when i started to test my ivr apps on latest master, i noticed that after sems answered the call and tried to play an announcement, i could not hear anything and after sems never completed the call. when i send bye from the ua, sems debug does not show that it received it. sems also stopped receiving other calls. looks like it is hanged.
debug of the ivr announcement call is below. i went and tried the same call using sems master from 20130214 and it worked fine. something seems to gone wrong with latest commit. the issue is not related to ivr, since i get the same problem with sems early_announce.so. -- juha Mar 2 07:17:56 sip /usr/sbin/sip-proxy[14699]: INFO: Routing initial INVITE <sip:[email protected]> to Application Server at <sip:127.0.0.1:5090> Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [run, udp_trsp.cpp:322] DEBUG: vv M [|] u recvd msg via UDP vv#012--++--#012INVITE sip:[email protected] SIP/2.0#015#012Record-Route: <sip:127.0.0.1:5070;r2=on;lr>#015#012Record-Route: <sip:192.98.102.10;transport=tcp;r2=on;lr>#015#012Via: SIP/2.0/UDP 127.0.0.1:5070;branch=z9hG4bK7e0b.0065ff8fa725889eb31c3a7001b492d3.0;i=6#015#012Via: SIP/2.0/TCP 192.98.102.10:5050;branch=z9hG4bK46f579d32209940c;rport=37942#015#012Contact: <sip:[email protected]:5050;alias=192.98.102.10~37942~2;transport=tcp>#015#012Max-Forwards: 16#015#012To: <sip:[email protected]>#015#012From: "" <sip:[email protected]>;tag=33155a92cfc983b5#015#012Call-ID: 698206100734e169#015#012CSeq: 44687 INVITE#015#012User-Agent: baresip v0.4.3 (i586/linux)#015#012Allow: INVITE,ACK,BYE,CANCEL,REFER,NOTIFY,SUBSCRIBE,INFO#015#012Content-Type: application/sdp#015#012Content-Length: 515#015#012P-App-Name: announcement#015#012P-App-Param: UserId=jh;Language=en#015#012#015#012v=0#015#012o=- 42009506 302564435 IN IP4 192.168.1.31#015#012s=-#015#012c=IN IP4 192.168.1.31#015#012t=0 0#015#012a=tool:baresip 0.4.3#015#012m=audio 18844 RTP/AVP 96 97 98 99 100 101 8 0 102#015#012b=AS:125#015#012a=rtpmap:96 SILK/24000#015#012a=rtpmap:97 SILK/16000#015#012a=rtpmap:98 speex/16000#015#012a=fmtp:98 mode="7";vbr=off;cng=on#015#012a=rtpmap:99 SILK/12000#015#012a=rtpmap:100 SILK/8000#015#012a=rtpmap:101 speex/8000#015#012a=fmtp:101 mode="7";vbr=off;cng=on#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:102 telephone-event/8000#015#012a=fmtp:102 0-15#015#012a=sendrecv#015#012a=label:1#015#012a=ptime:20#015#012--++-- Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [parse_sip_uri, parse_uri.cpp:332] DEBUG: Converted URI port () to int (5060) Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [parse_via_params, parse_via.cpp:525] DEBUG: parsed branch: z9hG4bK7e0b.0065ff8fa725889eb31c3a7001b492d3.0 Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [parse_via_params, parse_via.cpp:548] DEBUG: has_rport: 0 Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [match_request, trans_table.cpp:68] DEBUG: Matching INVITE request Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [sip_msg2am_request, SipCtrlInterface.cpp:412] DEBUG: single contact = '<sip:[email protected]:5050;alias=192.98.102.10~37942~2;transport=tcp>' Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [parse_sip_uri, parse_uri.cpp:332] DEBUG: Converted URI port (5050) to int (5050) Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [parse, AmMimeBody.cpp:566] DEBUG: saving single-part body Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [sip_msg2am_request, SipCtrlInterface.cpp:498] DEBUG: MIME body successfully parsed Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [handle_sip_request, SipCtrlInterface.cpp:632] DEBUG: Received new request from <127.0.0.1:5070> on intf #0 Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [handle_sip_request, SipCtrlInterface.cpp:636] DEBUG: req.method = <INVITE> Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [handle_sip_request, SipCtrlInterface.cpp:639] DEBUG: req.r_uri = <sip:[email protected]> Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [handle_sip_request, SipCtrlInterface.cpp:640] DEBUG: req.from_uri = <sip:[email protected]:5050;alias=192.98.102.10~37942~2;transport=tcp> Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [handle_sip_request, SipCtrlInterface.cpp:641] DEBUG: req.from = <"" <sip:[email protected]>> Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [handle_sip_request, SipCtrlInterface.cpp:642] DEBUG: req.to = <<sip:[email protected]>> Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [handle_sip_request, SipCtrlInterface.cpp:643] DEBUG: req.callid = <698206100734e169> Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [handle_sip_request, SipCtrlInterface.cpp:644] DEBUG: req.from_tag = <33155a92cfc983b5> Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [handle_sip_request, SipCtrlInterface.cpp:645] DEBUG: req.to_tag = <> Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [handle_sip_request, SipCtrlInterface.cpp:646] DEBUG: cseq = <44687> Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [handle_sip_request, SipCtrlInterface.cpp:647] DEBUG: req.route = <<sip:127.0.0.1:5070;r2=on;lr>, <sip:192.98.102.10;transport=tcp;r2=on;lr>> Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [handle_sip_request, SipCtrlInterface.cpp:648] DEBUG: hdrs = <Max-Forwards: 16#015#012User-Agent: baresip v0.4.3 (i586/linux)#015#012Allow: INVITE,ACK,BYE,CANCEL,REFER,NOTIFY,SUBSCRIBE,INFO#015#012P-App-Name: announcement#015#012P-App-Param: UserId=jh;Language=en#015#012> Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [handle_sip_request, SipCtrlInterface.cpp:649] DEBUG: body-ct = <application/sdp> Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [handleSipMsg, AmSipDispatcher.cpp:94] DEBUG: method: `INVITE' [6]. Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [AmSession, AmSession.cpp:91] DEBUG: dlg = (nil) Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [IvrSipDialog_new, IvrSipDialog.cpp:38] DEBUG: IvrSipDialog_new Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [IvrSipRequest_newRef, IvrSipRequest.cpp:90] DEBUG: IvrSipRequest_newRef Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [IvrDialogBase_new, IvrDialogBase.cpp:67] DEBUG: IvrDialogBase_new Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [setLocalTag, AmSession.cpp:231] DEBUG: AmSession::setLocalTag() - session id set to 3140F2E6-51318B840006EC6C-B5397B70 Mar 2 07:17:56 sip sems[16177]: [#b5397b70] [handle_sip_request, SipCtrlInterface.cpp:655] DEBUG: ^^ M [698206100734e169|] Ru SIP request INVITE handled ^^ Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [_start, AmThread.cpp:65] DEBUG: Thread 3036232560 is starting. Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [run, AmSession.cpp:269] DEBUG: startup session Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [run, AmSession.cpp:273] DEBUG: running session event loop Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [processingCycle, AmSession.cpp:378] DEBUG: vv S [|3140F2E6-51318B840006EC6C-B5397B70] Disconnected, running, 0 UACTransPending, 0 usages vv Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [process, Ivr.cpp:764] DEBUG: IvrDialog::process Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [process, AmSession.cpp:727] DEBUG: AmSession processing event Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [onRxRequest, AmBasicSipDialog.cpp:297] DEBUG: AmBasicSipDialog::onRxRequest(req = INVITE) Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [setStatus, AmBasicSipDialog.cpp:80] DEBUG: setting SIP dialog status: Disconnected->Trying Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [onRxSdp, AmOfferAnswer.cpp:211] DEBUG: entering onRxSdp(), oa_state=None Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [parse_sdp_line_ex, AmSdp.cpp:486] DEBUG: parsing SDP message... Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [parse_sdp_connection, AmSdp.cpp:707] DEBUG: SDP: got session level connection: IP4 192.168.1.31 Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [parse_sdp_media, AmSdp.cpp:850] DEBUG: SDP: got media: port 18844, payloads: 96 97 98 99 100 101 8 0 102 Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [attr_check, AmSdp.cpp:1367] DEBUG: unknown attribute: label Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [setState, AmOfferAnswer.cpp:69] DEBUG: setting SIP dialog O/A status: None->OfferRecved Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [onRxSdp, AmOfferAnswer.cpp:254] DEBUG: oa_state: None -> OfferRecved Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [IvrSipRequest_new, IvrSipRequest.cpp:61] DEBUG: IvrSipRequest_new Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [callPyEventHandler, Ivr.cpp:650] DEBUG: method onSipRequest is not implemented, trying default one Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [IvrSipRequest_dealloc, IvrSipRequest.cpp:97] DEBUG: IvrSipRequest_dealloc Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [onSipRequest, AmSession.cpp:777] DEBUG: onSipRequest: method = INVITE Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [ivr_log, Ivr.cpp:80] DEBUG: Ivr-Python: Entering announcement onInvite ... Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [reply, AmBasicSipDialog.cpp:487] DEBUG: reply: transaction found! Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [getSdpAnswer, AmSession.cpp:979] DEBUG: AmSession::getSdpAnswer(...) ... Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [advertisedIP, AmSession.cpp:1245] DEBUG: No media interface for signaling interface: Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [advertisedIP, AmSession.cpp:1246] DEBUG: Using default media interface instead. Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [RTPStream, AmSession.h:624] DEBUG: creating RTP stream instance for session [0xa370f70] Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [setLocalIP, AmRtpStream.cpp:101] DEBUG: ip = 192.98.102.10 Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [setLocalPort, AmRtpStream.cpp:204] DEBUG: added stream [0xa4021b0] to RTP receiver (192.98.102.10:40000/40001) Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [setState, AmOfferAnswer.cpp:69] DEBUG: setting SIP dialog O/A status: OfferRecved->Completed Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [setStatus, AmBasicSipDialog.cpp:80] DEBUG: setting SIP dialog status: Trying->Connected Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [send_reply, trans_layer.cpp:266] DEBUG: reply_len = 1079 Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [is_opt_set, transport.cpp:63] DEBUG: trsp_socket::socket_options = 0x0 Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [is_opt_set, transport.cpp:63] DEBUG: trsp_socket::socket_options = 0x0 Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [send_reply, trans_layer.cpp:439] DEBUG: Sending to 127.0.0.1:5070 <SIP/2.0 200 OK#015#012Record-Route: <sip:127.0.0.1:5070;...> Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [send, udp_trsp.cpp:245] DEBUG: send msg#012--++--#012SIP/2.0 200 OK#015#012Record-Route: <sip:127.0.0.1:5070;r2=on;lr>#015#012Record-Route: <sip:192.98.102.10;transport=tcp;r2=on;lr>#015#012Via: SIP/2.0/UDP 127.0.0.1:5070;branch=z9hG4bK7e0b.0065ff8fa725889eb31c3a7001b492d3.0;i=6#015#012Via: SIP/2.0/TCP 192.98.102.10:5050;branch=z9hG4bK46f579d32209940c;rport=37942#015#012To: <sip:[email protected]>;tag=3140F2E6-51318B840006EC6C-B5397B70#015#012From: "" <sip:[email protected]>;tag=33155a92cfc983b5#015#012Call-ID: 698206100734e169#015#012CSeq: 44687 INVITE#015#012Server: Sip Express Media Server (1.6.0 (x86/linux))#015#012Contact: <sip:127.0.0.1:5090>#015#012Content-Type: application/sdp#015#012Content-Length: 489#015#012#015#012v=0#015#012o=sems 1832368327 1888996188 IN IP4 192.98.102.10#015#012s=sems#015#012c=IN IP4 192.98.102.10#015#012t=0 0#015#012m=audio 40000 RTP/AVP 96 97 99 100 98 101 8 0 102#015#012a=rtpmap:96 SILK/24000#015#012a=rt pmap:97 SILK/16000#015#012a=rtpmap:99 SILK/12000#015#012a=rtpmap:100 SILK/8000#015#012a=rtpmap:98 speex/16000#015#012a=fmtp:98 mode="7";vbr=off;cng=on#015#012a=rtpmap:101 speex/8000#015#012a=fmtp:101 mode="7";vbr=off;cng=on#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:102 telephone-event/8000#015#012a=fmtp:102 0-15#015#012a=sendrecv#015#012a=direction:both#015#012--++-- Mar 2 07:17:56 sip /usr/sbin/sip-proxy[14699]: INFO: Routing in-dialog ACK <sip:127.0.0.1:5090> from <sip:[email protected]> Mar 2 07:17:56 sip sems[16177]: [#b5195b70] [run, udp_trsp.cpp:322] DEBUG: vv M [|] u recvd msg via UDP vv#012--++--#012ACK sip:127.0.0.1:5090 SIP/2.0#015#012Via: SIP/2.0/UDP 127.0.0.1:5070;branch=z9hG4bK7e0b.9284d0385f8a9cdffb3e49278deb1cd8.0;i=6#015#012Via: SIP/2.0/TCP 192.98.102.10:5050;branch=z9hG4bK4242e6ce4becbfca;rport=37942#015#012Max-Forwards: 16#015#012To: <sip:[email protected]>;tag=3140F2E6-51318B840006EC6C-B5397B70#015#012From: "" <sip:[email protected]>;tag=33155a92cfc983b5#015#012Call-ID: 698206100734e169#015#012CSeq: 44687 ACK#015#012User-Agent: baresip v0.4.3 (i586/linux)#015#012Content-Length: 0#015#012#015#012--++-- Mar 2 07:17:56 sip sems[16177]: [#b5195b70] [parse_sip_uri, parse_uri.cpp:332] DEBUG: Converted URI port (5090) to int (5090) Mar 2 07:17:56 sip sems[16177]: [#b5195b70] [parse_via_params, parse_via.cpp:525] DEBUG: parsed branch: z9hG4bK7e0b.9284d0385f8a9cdffb3e49278deb1cd8.0 Mar 2 07:17:56 sip sems[16177]: [#b5195b70] [parse_via_params, parse_via.cpp:548] DEBUG: has_rport: 0 Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [update_uas_reply, trans_layer.cpp:1688] DEBUG: update_uas_reply(t=0xa370648) Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [reset_timer, sip_trans.cpp:215] DEBUG: New timer of type G at time=1631 (repeated=0) Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [reset_timer, sip_trans.cpp:215] DEBUG: New timer of type H at time=3206 (repeated=0) Mar 2 07:17:56 sip sems[16177]: [#b5195b70] [match_request, trans_table.cpp:68] DEBUG: Matching ACK request Mar 2 07:17:56 sip sems[16177]: [#b5195b70] [match_request, trans_table.cpp:87] DEBUG: do_3261_match = 1 Mar 2 07:17:56 sip sems[16177]: [#b5195b70] [received_msg, trans_layer.cpp:1290] DEBUG: ACK matched INVITE transaction 0xa370648 Mar 2 07:17:56 sip sems[16177]: [#b5195b70] [update_uas_request, trans_layer.cpp:1745] DEBUG: update_uas_request(t=0xa370648) Mar 2 07:17:56 sip sems[16177]: [#b5195b70] [received_msg, trans_layer.cpp:1293] DEBUG: update_uas_request(bucket,t=0xa370648,msg) = 9 Mar 2 07:17:56 sip sems[16177]: [#b5195b70] [received_msg, trans_layer.cpp:1310] DEBUG: Passing ACK to the UA. Mar 2 07:17:56 sip sems[16177]: [#b5195b70] [handle_sip_request, SipCtrlInterface.cpp:632] DEBUG: Received new request from <127.0.0.1:5070> on intf #0 Mar 2 07:17:56 sip sems[16177]: [#b5195b70] [handle_sip_request, SipCtrlInterface.cpp:636] DEBUG: req.method = <ACK> Mar 2 07:17:56 sip sems[16177]: [#b5195b70] [handle_sip_request, SipCtrlInterface.cpp:639] DEBUG: req.r_uri = <sip:127.0.0.1:5090> Mar 2 07:17:56 sip sems[16177]: [#b5195b70] [handle_sip_request, SipCtrlInterface.cpp:640] DEBUG: req.from_uri = <sip:[email protected]> Mar 2 07:17:56 sip sems[16177]: [#b5195b70] [handle_sip_request, SipCtrlInterface.cpp:641] DEBUG: req.from = <"" <sip:[email protected]>> Mar 2 07:17:56 sip sems[16177]: [#b5195b70] [handle_sip_request, SipCtrlInterface.cpp:642] DEBUG: req.to = <<sip:[email protected]>;tag=3140F2E6-51318B840006EC6C-B5397B70> Mar 2 07:17:56 sip sems[16177]: [#b5195b70] [handle_sip_request, SipCtrlInterface.cpp:643] DEBUG: req.callid = <698206100734e169> Mar 2 07:17:56 sip sems[16177]: [#b5195b70] [handle_sip_request, SipCtrlInterface.cpp:644] DEBUG: req.from_tag = <33155a92cfc983b5> Mar 2 07:17:56 sip sems[16177]: [#b5195b70] [handle_sip_request, SipCtrlInterface.cpp:645] DEBUG: req.to_tag = <3140F2E6-51318B840006EC6C-B5397B70> Mar 2 07:17:56 sip sems[16177]: [#b5195b70] [handle_sip_request, SipCtrlInterface.cpp:646] DEBUG: cseq = <44687> Mar 2 07:17:56 sip sems[16177]: [#b5195b70] [handle_sip_request, SipCtrlInterface.cpp:647] DEBUG: req.route = <> Mar 2 07:17:56 sip sems[16177]: [#b5195b70] [handle_sip_request, SipCtrlInterface.cpp:648] DEBUG: hdrs = <Max-Forwards: 16#015#012User-Agent: baresip v0.4.3 (i586/linux)#015#012> Mar 2 07:17:56 sip sems[16177]: [#b5195b70] [handle_sip_request, SipCtrlInterface.cpp:649] DEBUG: body-ct = <> Mar 2 07:17:56 sip sems[16177]: [#b5195b70] [handle_sip_request, SipCtrlInterface.cpp:655] DEBUG: ^^ M [698206100734e169|3140F2E6-51318B840006EC6C-B5397B70] Ru SIP request ACK handled ^^ Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [onSdpCompleted, AmSession.cpp:1043] DEBUG: AmSession::onSdpCompleted(...) ... Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [init, AmRtpAudio.cpp:321] DEBUG: AmRtpAudio::init(...) Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [setPassiveMode, AmRtpStream.cpp:517] DEBUG: The other UA is NATed: switched to passive mode. Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [setRAddr, AmRtpStream.cpp:446] DEBUG: RTP remote address set to 192.168.1.31:(18844/0) Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [init, AmRtpStream.cpp:676] DEBUG: default payload selected = 96 Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [init, AmRtpStream.cpp:682] DEBUG: remote party supports telephone events (pt=102) Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [setCurrentPayload, AmRtpAudio.cpp:48] DEBUG: fmt.codec_id = 33 Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [setCurrentPayload, AmRtpAudio.cpp:51] DEBUG: fmt.rate = 24000 Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [setCurrentPayload, AmRtpAudio.cpp:53] DEBUG: fmt.advertized_rate = 24000 Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [setInbandDetector, AmDtmfDetector.cpp:212] DEBUG: Setting spandsp DTMF detector Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [IvrAudioFile_new, IvrAudio.cpp:17] DEBUG: ---------- IvrAudioFile_alloc ----------- Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [ivr_log, Ivr.cpp:80] DEBUG: Ivr-Python: Found audio file of length 62924 Mar 2 07:17:56 sip sems[16177]: [#b4691b70] [_start, AmThread.cpp:65] DEBUG: Thread 3026787184 is starting. Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [wav_read_header, wav_hdr.c:126] DEBUG: trying to read WAV file Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [wav_read_header, wav_hdr.c:129] DEBUG: tag = <RIFF> Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [wav_read_header, wav_hdr.c:137] DEBUG: file size = <62916> Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [wav_read_header, wav_hdr.c:140] DEBUG: tag = <WAVE> Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [wav_read_header, wav_hdr.c:147] DEBUG: tag = <fmt > Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [wav_read_header, wav_hdr.c:155] DEBUG: chunk_size = <16> Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [wav_read_header, wav_hdr.c:159] DEBUG: fmt = <01> Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [wav_read_header, wav_hdr.c:163] DEBUG: channels = <1> Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [wav_read_header, wav_hdr.c:167] DEBUG: rate = <8000> Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [wav_read_header, wav_hdr.c:174] DEBUG: bits/sample = <16> Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [wav_read_header, wav_hdr.c:195] DEBUG: tag = <data> Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [wav_read_header, wav_hdr.c:199] DEBUG: chunk size = <62880> Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [setBufferSize, AmBufferedAudio.cpp:62] DEBUG: set output buffer size to 0 low thresh 0, fill thresh 0 Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [onSipRequest, AmB2BSession.cpp:355] DEBUG: relaying B2B SIP request INVITE sip:[email protected] Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [relayEvent, AmB2BSession.cpp:518] DEBUG: AmB2BSession::relayEvent: to other_id='' Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [process, Ivr.cpp:764] DEBUG: IvrDialog::process Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [process, AmSession.cpp:727] DEBUG: AmSession processing event Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [onRxRequest, AmBasicSipDialog.cpp:297] DEBUG: AmBasicSipDialog::onRxRequest(req = ACK) Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [onRequestIn, AmOfferAnswer.cpp:155] DEBUG: 200 ACK received: resetting OA state Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [IvrSipRequest_new, IvrSipRequest.cpp:61] DEBUG: IvrSipRequest_new Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [callPyEventHandler, Ivr.cpp:650] DEBUG: method onSipRequest is not implemented, trying default one Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [IvrSipRequest_dealloc, IvrSipRequest.cpp:97] DEBUG: IvrSipRequest_dealloc Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [onSipRequest, AmSession.cpp:777] DEBUG: onSipRequest: method = ACK Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [onSipRequest, AmB2BSession.cpp:355] DEBUG: relaying B2B SIP request ACK sip:127.0.0.1:5090 Mar 2 07:17:56 sip sems[16177]: [#b569ab70] [process, AmMediaProcessor.cpp:308] DEBUG: Session inserted to the scheduler Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [relayEvent, AmB2BSession.cpp:518] DEBUG: AmB2BSession::relayEvent: to other_id='' Mar 2 07:17:56 sip sems[16177]: [#b4f93b70] [processingCycle, AmSession.cpp:397] DEBUG: ^^ S [698206100734e169|3140F2E6-51318B840006EC6C-B5397B70] Connected, running, 0 UACTransPending, 0 usages ^^ Mar 2 07:17:56 sip sems[16177]: [#b569ab70] [resampleOutput, AmAudio.cpp:447] DEBUG: using internal resampler for output Mar 2 07:18:46 sip /usr/sbin/sip-proxy[14691]: INFO: Routing in-dialog BYE <sip:127.0.0.1:5090> from <sip:[email protected]> Mar 2 07:19:08 sip /usr/sbin/sip-proxy[14695]: INFO: INVITE <sip:[email protected]> by <sip:[email protected]> has no Proxy-Authorization header Mar 2 07:19:08 sip /usr/sbin/sip-proxy[14695]: INFO: INVITE <sip:[email protected]> by <[email protected]> as <sip:[email protected]> from <192.98.102.10> is authorized Mar 2 07:19:08 sip /usr/sbin/sip-proxy[14695]: INFO: Routing initial INVITE <sip:[email protected]> to Application Server at <sip:127.0.0.1:5090> Mar 2 07:19:45 sip postfix/pickup[14469]: C94E363C041: uid=1000 from=<jh> Mar 2 07:19:45 sip postfix/cleanup[16293]: C94E363C041: message-id=<[email protected]> Mar 2 07:19:45 sip postfix/qmgr[14468]: C94E363C041: from=<[email protected]>, size=5900, nrcpt=2 (queue active) Mar 2 07:19:46 sip postfix/smtp[16295]: connect to box.tutpro.com[192.26.111.29]:8008: Network is unreachable Mar 2 07:19:46 sip postfix/smtp[16295]: C94E363C041: to=<[email protected]>, relay=none, delay=0.44, delays=0.06/0.28/0.1/0, dsn=4.4.1, status=deferred (connect to box.tutpro.com[192.26.111.29]:8008: Network is unreachable) Mar 2 07:19:46 sip postfix/smtp[16295]: C94E363C041: to=<[email protected]>, relay=none, delay=0.44, delays=0.06/0.28/0.1/0, dsn=4.4.1, status=deferred (connect to box.tutpro.com[192.26.111.29]:8008: Network is unreachable) Mar 2 07:22:10 sip pdns[1323]: gmysql Connection succesful root@rautu:/home/jh# service sems stop Stopping sems Waiting for sessions to end ... Mar 2 07:25:09 sip postfix/qmgr[14468]: C94E363C041: from=<[email protected]>, size=5900, nrcpt=2 (queue active) Mar 2 07:25:09 sip postfix/smtp[16544]: connect to box.tutpro.com[192.26.111.29]:8008: Network is unreachable Mar 2 07:25:09 sip postfix/smtp[16544]: C94E363C041: to=<[email protected]>, relay=none, delay=324, delays=324/0.06/0.17/0, dsn=4.4.1, status=deferred (connect to box.tutpro.com[192.26.111.29]:8008: Network is unreachable) Mar 2 07:25:09 sip postfix/smtp[16544]: C94E363C041: to=<[email protected]>, relay=none, delay=324, delays=324/0.06/0.17/0, dsn=4.4.1, status=deferred (connect to box.tutpro.com[192.26.111.29]:8008: Network is unreachable) root@rautu:/home/jh# Mar 2 07:26:45 sip /usr/sbin/sip-proxy[14696]: INFO: REGISTER <sip:[email protected]> by <[email protected]> from <192.98.102.10> has stale nonce Mar 2 07:26:45 sip /usr/sbin/sip-proxy[14696]: INFO: REGISTER <sip:[email protected]> by <[email protected]> from <192.98.102.10> is authorized _______________________________________________ Semsdev mailing list [email protected] http://lists.iptel.org/mailman/listinfo/semsdev
