Hi Juha,

I've posted some additional fixes today. However, early_announce works like a 
charm at my place. Could you please recheck it? If it is now only related to 
the ivr plug-in, could you please provide me with a simple ivr script that 
fails?

Thx
-Raphael.

On 02.03.2013, at 06:36, Juha Heinanen wrote:

> 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

_______________________________________________
Semsdev mailing list
[email protected]
http://lists.iptel.org/mailman/listinfo/semsdev

Reply via email to