==================== extension 2 calls extension 1 ============================= [Mar 5 17:56:33] VERBOSE[3212] logger.c: <--- SIP read from 11.111.11.3:2059 ---> INVITE sip:1@app.fooobar.at;user=phone SIP/2.0 Via: SIP/2.0/UDP 11.111.11.3:2059;branch=z9hG4bK-jkrfg6lfv7z2;rport From: "" ;tag=l2i4j4pt65 To: Call-ID: 3c26aa35c0df-2k7sco3qp09e@snom320-00041324009C CSeq: 1 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: keys="3" User-Agent: snom320/6.5.18 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Session-Expires: 3600;refresher=uas Min-SE: 90 Content-Type: application/sdp Content-Length: 339 v=0 o=root 1173074340 1173074340 IN IP4 11.111.11.3 s=call c=IN IP4 11.111.11.3 t=0 0 m=audio 57832 RTP/AVP 0 8 9 3 18 4 101 a=rtpmap:0 pcmu/8000 a=rtpmap:8 pcma/8000 a=rtpmap:9 g722/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv <-------------> [Mar 5 17:56:33] VERBOSE[3212] logger.c: --- (18 headers 16 lines) --- [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: Setting NAT on RTP to On [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: Setting NAT on UDPTL to On [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: Allocating new SIP dialog for 3c26aa35c0df-2k7sco3qp09e@snom320-00041324009C - INVITE (With RTP) [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: Begin: parsing SIP "Supported: timer, 100rel, replaces, callerid" [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: Found SIP option: -timer- [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: Matched SIP option: timer [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: Found SIP option: -100rel- [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: Matched SIP option: 100rel [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: Found SIP option: -replaces- [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: Matched SIP option: replaces [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: Found SIP option: -callerid- [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: Found no match for SIP option: callerid (Please file bug report!) [Mar 5 17:56:33] VERBOSE[3212] logger.c: Sending to 11.111.11.3 : 2059 (NAT) [Mar 5 17:56:33] VERBOSE[3212] logger.c: Using INVITE request as basis request - 3c26aa35c0df-2k7sco3qp09e@snom320-00041324009C [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: Setting NAT on RTP to On [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: Setting NAT on UDPTL to On [Mar 5 17:56:33] VERBOSE[3212] logger.c: <--- Reliably Transmitting (NAT) to 11.111.11.3:2059 ---> SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 11.111.11.3:2059;branch=z9hG4bK-jkrfg6lfv7z2;received=11.111.11.3;rport=2059 From: "" ;tag=l2i4j4pt65 To: ;tag=as4cda90ed Call-ID: 3c26aa35c0df-2k7sco3qp09e@snom320-00041324009C CSeq: 1 INVITE User-Agent: InnoSIP-app Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Proxy-Authenticate: Digest algorithm=MD5, realm="app.fooobar.at", nonce="68471684" Content-Length: 0 <------------> [Mar 5 17:56:33] VERBOSE[3212] logger.c: Scheduling destruction of SIP dialog '3c26aa35c0df-2k7sco3qp09e@snom320-00041324009C' in 32000 ms (Method: INVITE) [Mar 5 17:56:33] VERBOSE[3212] logger.c: Found user '2' [Mar 5 17:56:33] VERBOSE[3212] logger.c: <--- SIP read from 11.111.11.3:2059 ---> ACK sip:1@app.fooobar.at;user=phone SIP/2.0 Via: SIP/2.0/UDP 11.111.11.3:2059;branch=z9hG4bK-jkrfg6lfv7z2;rport From: "" ;tag=l2i4j4pt65 To: ;tag=as4cda90ed Call-ID: 3c26aa35c0df-2k7sco3qp09e@snom320-00041324009C CSeq: 1 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 <-------------> [Mar 5 17:56:33] VERBOSE[3212] logger.c: --- (9 headers 0 lines) --- [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: Stopping retransmission on '3c26aa35c0df-2k7sco3qp09e@snom320-00041324009C' of Response 1: Match Found [Mar 5 17:56:33] VERBOSE[3212] logger.c: <--- SIP read from 11.111.11.3:2059 ---> INVITE sip:1@app.fooobar.at;user=phone SIP/2.0 Via: SIP/2.0/UDP 11.111.11.3:2059;branch=z9hG4bK-banm0nve0xko;rport From: "" ;tag=l2i4j4pt65 To: Call-ID: 3c26aa35c0df-2k7sco3qp09e@snom320-00041324009C CSeq: 2 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: keys="3" User-Agent: snom320/6.5.18 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Session-Expires: 3600;refresher=uas Min-SE: 90 Proxy-Authorization: Digest username="2",realm="app.fooobar.at",nonce="68471684",uri="sip:1@app.fooobar.at;user=phone",response="3fa0fd9a37d4a9c165851227b2778f68",algorithm=MD5 Content-Type: application/sdp Content-Length: 339 v=0 o=root 1173074340 1173074340 IN IP4 11.111.11.3 s=call c=IN IP4 11.111.11.3 t=0 0 m=audio 57832 RTP/AVP 0 8 9 3 18 4 101 a=rtpmap:0 pcmu/8000 a=rtpmap:8 pcma/8000 a=rtpmap:9 g722/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv <-------------> [Mar 5 17:56:33] VERBOSE[3212] logger.c: --- (19 headers 16 lines) --- [Mar 5 17:56:33] VERBOSE[3212] logger.c: Sending to 11.111.11.3 : 2059 (NAT) [Mar 5 17:56:33] VERBOSE[3212] logger.c: Using INVITE request as basis request - 3c26aa35c0df-2k7sco3qp09e@snom320-00041324009C [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: Setting NAT on RTP to On [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: Setting NAT on UDPTL to On [Mar 5 17:56:33] VERBOSE[3212] logger.c: Found user '2' [Mar 5 17:56:33] VERBOSE[3212] logger.c: Found RTP audio format 0 [Mar 5 17:56:33] VERBOSE[3212] logger.c: Found RTP audio format 8 [Mar 5 17:56:33] VERBOSE[3212] logger.c: Found RTP audio format 9 [Mar 5 17:56:33] VERBOSE[3212] logger.c: Found RTP audio format 3 [Mar 5 17:56:33] VERBOSE[3212] logger.c: Found RTP audio format 18 [Mar 5 17:56:33] VERBOSE[3212] logger.c: Found RTP audio format 4 [Mar 5 17:56:33] VERBOSE[3212] logger.c: Found RTP audio format 101 [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: Peer doesn't provide T.38 UDPTL [Mar 5 17:56:33] VERBOSE[3212] logger.c: Peer audio RTP is at port 11.111.11.3:57832 [Mar 5 17:56:33] VERBOSE[3212] logger.c: Found audio description format pcmu for ID 0 [Mar 5 17:56:33] VERBOSE[3212] logger.c: Found audio description format pcma for ID 8 [Mar 5 17:56:33] VERBOSE[3212] logger.c: Found audio description format g722 for ID 9 [Mar 5 17:56:33] VERBOSE[3212] logger.c: Found audio description format gsm for ID 3 [Mar 5 17:56:33] VERBOSE[3212] logger.c: Found audio description format g729 for ID 18 [Mar 5 17:56:33] VERBOSE[3212] logger.c: Found audio description format g723 for ID 4 [Mar 5 17:56:33] VERBOSE[3212] logger.c: Found audio description format telephone-event for ID 101 [Mar 5 17:56:33] VERBOSE[3212] logger.c: Got unsupported a:fmtp in SDP offer [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: T38 state changed to 0 on channel [Mar 5 17:56:33] VERBOSE[3212] logger.c: Capabilities: us - 0x40e (gsm|ulaw|alaw|ilbc), peer - audio=0x110f (g723|gsm|ulaw|alaw|g729|g722)/video=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) [Mar 5 17:56:33] VERBOSE[3212] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Mar 5 17:56:33] VERBOSE[3212] logger.c: Peer audio RTP is at port 11.111.11.3:57832 [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: We're settling with these formats: 0xe (gsm|ulaw|alaw) [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: Checking SIP call limits for device 2 [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: Updating call counter for incoming call [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: Call from peer '2' is 1 out of 2 [Mar 5 17:56:33] DEBUG[3212] devicestate.c: Notification of state change to be queued on device/channel SIP/2 [Mar 5 17:56:33] DEBUG[3203] chan_sip.c: Checking device state for peer 2 [Mar 5 17:56:33] VERBOSE[3212] logger.c: Looking for 1 in fromSipPbx (domain app.fooobar.at) [Mar 5 17:56:33] DEBUG[3203] devicestate.c: Changing state for SIP/2 - state 2 (In use) [Mar 5 17:56:33] DEBUG[3203] chan_sip.c: Checking device state for peer 2 [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Mar 5 17:56:33] DEBUG[3227] app_queue.c: Device 'SIP/2' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: *** Joint capabilities are 0xe (gsm|ulaw|alaw) [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: *** Our capabilities are 0x40e (gsm|ulaw|alaw|ilbc) [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: This channel will not be able to handle video. [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: build_route: Contact hop: ;flow-id=1 [Mar 5 17:56:33] VERBOSE[3212] logger.c: list_route: hop: [Mar 5 17:56:33] DEBUG[3212] chan_sip.c: SIP/2-0a17d398: New call is still down.... Trying... [Mar 5 17:56:33] VERBOSE[3212] logger.c: <--- Transmitting (NAT) to 11.111.11.3:2059 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 11.111.11.3:2059;branch=z9hG4bK-banm0nve0xko;received=11.111.11.3;rport=2059 From: "" ;tag=l2i4j4pt65 To: Call-ID: 3c26aa35c0df-2k7sco3qp09e@snom320-00041324009C CSeq: 2 INVITE User-Agent: InnoSIP-app Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Mar 5 17:56:33] DEBUG[3212] devicestate.c: Notification of state change to be queued on device/channel SIP/2 [Mar 5 17:56:33] DEBUG[3203] chan_sip.c: Checking device state for peer 2 [Mar 5 17:56:33] DEBUG[3203] devicestate.c: Changing state for SIP/2 - state 2 (In use) [Mar 5 17:56:33] DEBUG[4145] pbx.c: Launching 'DumpChan' [Mar 5 17:56:33] DEBUG[3203] chan_sip.c: Checking device state for peer 2 [Mar 5 17:56:33] DEBUG[3227] app_queue.c: Device 'SIP/2' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Mar 5 17:56:33] VERBOSE[4145] logger.c: -- Executing [1@fromSipPbx:1] DumpChan("SIP/2-0a17d398", "") in new stack [Mar 5 17:56:33] VERBOSE[4145] logger.c: ... dialplan processing ... [Mar 5 17:56:33] DEBUG[4145] pbx.c: Launching 'Dial' [Mar 5 17:56:33] VERBOSE[4145] logger.c: -- Executing [s@macro-toPbxMakro:58] Dial("SIP/2-0a17d398", "SIP/1|300|im(blaa)") in new stack [Mar 5 17:56:33] DEBUG[4145] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw) [Mar 5 17:56:33] DEBUG[4145] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Mar 5 17:56:33] DEBUG[4145] chan_sip.c: Our T38 capability (3856) [Mar 5 17:56:33] DEBUG[4145] chan_sip.c: Setting NAT on RTP to On [Mar 5 17:56:33] DEBUG[4145] chan_sip.c: Setting NAT on UDPTL to On [Mar 5 17:56:33] DEBUG[4145] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Mar 5 17:56:33] DEBUG[4145] chan_sip.c: *** Joint capabilities are 0x0 (nothing) [Mar 5 17:56:33] DEBUG[4145] chan_sip.c: *** Our capabilities are 0x40e (gsm|ulaw|alaw|ilbc) [Mar 5 17:56:33] DEBUG[4145] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Mar 5 17:56:33] DEBUG[4145] chan_sip.c: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Mar 5 17:56:33] DEBUG[4145] chan_sip.c: This channel will not be able to handle video. [Mar 5 17:56:33] DEBUG[4145] channel.c: Not copying variable DIALEDTIME. ... [Mar 5 17:56:33] DEBUG[4145] channel.c: Not copying variable SIPURI. [Mar 5 17:56:33] DEBUG[4145] chan_sip.c: Outgoing Call for 1 [Mar 5 17:56:33] DEBUG[4145] chan_sip.c: Updating call counter for outgoing call [Mar 5 17:56:33] DEBUG[4145] chan_sip.c: Call to peer '1' is 1 out of 2 [Mar 5 17:56:33] DEBUG[4145] devicestate.c: Notification of state change to be queued on device/channel SIP/1 [Mar 5 17:56:33] DEBUG[4145] chan_sip.c: Our T38 capability (3856), joint T38 capability (3856) [Mar 5 17:56:33] DEBUG[3203] chan_sip.c: Checking device state for peer 1 [Mar 5 17:56:33] DEBUG[3203] devicestate.c: Changing state for SIP/1 - state 6 (Ringing) [Mar 5 17:56:33] DEBUG[4145] chan_sip.c: ** Our capability: 0x40e (gsm|ulaw|alaw|ilbc) Video flag: False [Mar 5 17:56:33] DEBUG[3203] chan_sip.c: Checking device state for peer 1 [Mar 5 17:56:33] DEBUG[4145] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [Mar 5 17:56:33] DEBUG[3227] app_queue.c: Device 'SIP/1' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Mar 5 17:56:33] VERBOSE[4145] logger.c: Audio is at 22.22.222.184 port 11372 [Mar 5 17:56:33] VERBOSE[4145] logger.c: Adding codec 0x4 (ulaw) to SDP [Mar 5 17:56:33] VERBOSE[4145] logger.c: Adding codec 0x8 (alaw) to SDP [Mar 5 17:56:33] VERBOSE[4145] logger.c: Adding codec 0x400 (ilbc) to SDP [Mar 5 17:56:33] VERBOSE[4145] logger.c: Adding codec 0x2 (gsm) to SDP [Mar 5 17:56:33] VERBOSE[4145] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Mar 5 17:56:33] DEBUG[4145] chan_sip.c: -- Done with adding codecs to SDP [Mar 5 17:56:33] DEBUG[4145] chan_sip.c: Done building SDP. Settling with this capability: 0x40e (gsm|ulaw|alaw|ilbc) [Mar 5 17:56:33] VERBOSE[4145] logger.c: Reliably Transmitting (NAT) to 11.111.11.3:27252: INVITE sip:1@11.111.11.3:27252;rinstance=72d3c45619ba8136 SIP/2.0 Via: SIP/2.0/UDP 22.22.222.184:5160;branch=z9hG4bK367554b4;rport From: "2 ()" ;tag=as274f340f To: Contact: Call-ID: 303483274359eba217d9f3736e46898c@22.22.222.184 CSeq: 102 INVITE User-Agent: InnoSIP-app Max-Forwards: 70 Date: Thu, 05 Mar 2009 16:56:33 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 334 v=0 o=root 19618 19618 IN IP4 22.22.222.184 s=session c=IN IP4 22.22.222.184 t=0 0 m=audio 11372 RTP/AVP 0 8 97 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=30 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Mar 5 17:56:33] VERBOSE[4145] logger.c: -- Called 1 [Mar 5 17:56:33] DEBUG[4145] channel.c: Prodding channel 'SIP/2-0a17d398' [Mar 5 17:56:33] DEBUG[4145] chan_sip.c: Setting framing from config on incoming call [Mar 5 17:56:33] DEBUG[4145] chan_sip.c: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True [Mar 5 17:56:33] DEBUG[4145] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Mar 5 17:56:33] VERBOSE[4145] logger.c: Audio is at 22.22.222.184 port 10048 [Mar 5 17:56:33] VERBOSE[4145] logger.c: Adding codec 0x4 (ulaw) to SDP [Mar 5 17:56:33] VERBOSE[4145] logger.c: Adding codec 0x8 (alaw) to SDP [Mar 5 17:56:33] VERBOSE[4145] logger.c: Adding codec 0x2 (gsm) to SDP [Mar 5 17:56:33] VERBOSE[4145] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Mar 5 17:56:33] DEBUG[4145] chan_sip.c: -- Done with adding codecs to SDP [Mar 5 17:56:33] DEBUG[4145] chan_sip.c: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) [Mar 5 17:56:33] VERBOSE[4145] logger.c: <--- Transmitting (NAT) to 11.111.11.3:2059 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 11.111.11.3:2059;branch=z9hG4bK-banm0nve0xko;received=11.111.11.3;rport=2059 From: "" ;tag=l2i4j4pt65 To: ;tag=as216ec317 Call-ID: 3c26aa35c0df-2k7sco3qp09e@snom320-00041324009C CSeq: 2 INVITE User-Agent: InnoSIP-app Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 289 v=0 o=root 19618 19618 IN IP4 22.22.222.184 s=session c=IN IP4 22.22.222.184 t=0 0 m=audio 10048 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Mar 5 17:56:33] DEBUG[4145] channel.c: Set channel SIP/2-0a17d398 to write format slin [Mar 5 17:56:33] VERBOSE[4145] logger.c: -- Started music on hold, class 'blaa', on channel 'SIP/2-0a17d398' [Mar 5 17:56:34] DEBUG[4145] rtp.c: Got RTCP report of 52 bytes [Mar 5 17:56:34] VERBOSE[3212] logger.c: <--- SIP read from 11.111.11.3:27252 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 22.22.222.184:5160;branch=z9hG4bK367554b4;rport=5160 Contact: To: ;tag=fe2b522a From: "2 ()";tag=as274f340f Call-ID: 303483274359eba217d9f3736e46898c@22.22.222.184 CSeq: 102 INVITE User-Agent: eyeBeam release 1102q stamp 51814 Content-Length: 0 <-------------> [Mar 5 17:56:34] VERBOSE[3212] logger.c: --- (9 headers 0 lines) --- [Mar 5 17:56:34] DEBUG[3212] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '303483274359eba217d9f3736e46898c@22.22.222.184' Request 102: Found [Mar 5 17:56:34] DEBUG[3212] devicestate.c: Notification of state change to be queued on device/channel SIP/1 [Mar 5 17:56:34] DEBUG[3203] chan_sip.c: Checking device state for peer 1 [Mar 5 17:56:34] VERBOSE[4145] logger.c: -- SIP/1-0a2756e8 is ringing [Mar 5 17:56:34] DEBUG[3203] devicestate.c: Changing state for SIP/1 - state 6 (Ringing) [Mar 5 17:56:34] DEBUG[3203] chan_sip.c: Checking device state for peer 1 [Mar 5 17:56:34] DEBUG[3227] app_queue.c: Device 'SIP/1' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Mar 5 17:56:34] DEBUG[4145] rtp.c: Ooh, format changed from unknown to ulaw [Mar 5 17:56:34] DEBUG[4145] rtp.c: Created smoother: format: 4 ms: 20 len: 160 [Mar 5 17:56:34] VERBOSE[3212] logger.c: <--- SIP read from 11.111.11.3:27252 ---> <-------------> [Mar 5 17:56:34] DEBUG[4145] rtp.c: RTCP NAT: Got RTCP from other end. Now sending to address 11.111.11.3:38915 [Mar 5 17:56:34] DEBUG[4145] rtp.c: Got RTCP report of 132 bytes [Mar 5 17:56:34] DEBUG[4145] rtp.c: RTP NAT: Got audio from other end. Now sending to address 11.111.11.3:38914 [Mar 5 17:56:34] VERBOSE[3212] logger.c: <--- SIP read from 11.111.11.3:27252 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 22.22.222.184:5160;branch=z9hG4bK367554b4;rport=5160 Contact: To: ;tag=fe2b522a From: "2 ()";tag=as274f340f Call-ID: 303483274359eba217d9f3736e46898c@22.22.222.184 CSeq: 102 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp User-Agent: eyeBeam release 1102q stamp 51814 Content-Length: 184 v=0 o=- 7 2 IN IP4 11.111.11.3 s=CounterPath eyeBeam 1.5 c=IN IP4 11.111.11.3 t=0 0 m=audio 38914 RTP/AVP 0 8 101 a=fmtp:101 0-15 a=rtpmap:101 telephone-event/8000 a=sendrecv <-------------> [Mar 5 17:56:34] VERBOSE[3212] logger.c: --- (11 headers 9 lines) --- [Mar 5 17:56:34] DEBUG[3212] chan_sip.c: Acked pending invite 102 [Mar 5 17:56:34] DEBUG[3212] chan_sip.c: Stopping retransmission on '303483274359eba217d9f3736e46898c@22.22.222.184' of Request 102: Match Found [Mar 5 17:56:34] VERBOSE[3212] logger.c: Found RTP audio format 0 [Mar 5 17:56:34] VERBOSE[3212] logger.c: Found RTP audio format 8 [Mar 5 17:56:34] VERBOSE[3212] logger.c: Found RTP audio format 101 [Mar 5 17:56:34] DEBUG[3212] chan_sip.c: Peer doesn't provide T.38 UDPTL [Mar 5 17:56:34] VERBOSE[3212] logger.c: Peer audio RTP is at port 11.111.11.3:38914 [Mar 5 17:56:34] VERBOSE[3212] logger.c: Got unsupported a:fmtp in SDP offer [Mar 5 17:56:34] VERBOSE[3212] logger.c: Found audio description format telephone-event for ID 101 [Mar 5 17:56:34] DEBUG[3212] chan_sip.c: T38 state changed to 0 on channel SIP/1-0a2756e8 [Mar 5 17:56:34] VERBOSE[3212] logger.c: Capabilities: us - 0x40e (gsm|ulaw|alaw|ilbc), peer - audio=0xc (ulaw|alaw)/video=0x0 (nothing), combined - 0xc (ulaw|alaw) [Mar 5 17:56:34] VERBOSE[3212] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Mar 5 17:56:34] VERBOSE[3212] logger.c: Peer audio RTP is at port 11.111.11.3:38914 [Mar 5 17:56:34] DEBUG[3212] chan_sip.c: We're settling with these formats: 0xc (ulaw|alaw) [Mar 5 17:56:34] DEBUG[3212] chan_sip.c: Updating call counter for outgoing call [Mar 5 17:56:34] DEBUG[3212] devicestate.c: Notification of state change to be queued on device/channel SIP/1 [Mar 5 17:56:34] DEBUG[3212] chan_sip.c: build_route: Contact hop: [Mar 5 17:56:34] DEBUG[3203] chan_sip.c: Checking device state for peer 1 [Mar 5 17:56:34] VERBOSE[3212] logger.c: list_route: hop: [Mar 5 17:56:34] DEBUG[3203] devicestate.c: Changing state for SIP/1 - state 2 (In use) [Mar 5 17:56:34] DEBUG[3212] chan_sip.c: Strict routing enforced for session 303483274359eba217d9f3736e46898c@22.22.222.184 [Mar 5 17:56:34] DEBUG[3203] chan_sip.c: Checking device state for peer 1 [Mar 5 17:56:34] VERBOSE[3212] logger.c: set_destination: Parsing for address/port to send to [Mar 5 17:56:34] DEBUG[3227] app_queue.c: Device 'SIP/1' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Mar 5 17:56:34] VERBOSE[3212] logger.c: set_destination: set destination to 11.111.11.3, port 27252 [Mar 5 17:56:34] VERBOSE[3212] logger.c: Transmitting (NAT) to 11.111.11.3:27252: ACK sip:1@11.111.11.3:27252;rinstance=72d3c45619ba8136 SIP/2.0 Via: SIP/2.0/UDP 22.22.222.184:5160;branch=z9hG4bK7aa9eeba;rport From: "2 ()" ;tag=as274f340f To: ;tag=fe2b522a Contact: Call-ID: 303483274359eba217d9f3736e46898c@22.22.222.184 CSeq: 102 ACK User-Agent: InnoSIP-app Max-Forwards: 70 Content-Length: 0 --- [Mar 5 17:56:34] DEBUG[4145] devicestate.c: Notification of state change to be queued on device/channel SIP/1 [Mar 5 17:56:34] VERBOSE[4145] logger.c: -- SIP/1-0a2756e8 answered SIP/2-0a17d398 [Mar 5 17:56:34] DEBUG[3203] chan_sip.c: Checking device state for peer 1 [Mar 5 17:56:34] DEBUG[3203] devicestate.c: Changing state for SIP/1 - state 2 (In use) [Mar 5 17:56:34] DEBUG[4145] channel.c: Set channel SIP/2-0a17d398 to write format ulaw [Mar 5 17:56:34] DEBUG[3203] chan_sip.c: Checking device state for peer 1 [Mar 5 17:56:34] VERBOSE[4145] logger.c: -- Stopped music on hold on SIP/2-0a17d398 [Mar 5 17:56:34] DEBUG[3227] app_queue.c: Device 'SIP/1' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Mar 5 17:56:34] DEBUG[4145] devicestate.c: Notification of state change to be queued on device/channel SIP/2 [Mar 5 17:56:34] DEBUG[4145] chan_sip.c: SIP answering channel: SIP/2-0a17d398 [Mar 5 17:56:34] DEBUG[3203] chan_sip.c: Checking device state for peer 2 [Mar 5 17:56:34] DEBUG[3203] devicestate.c: Changing state for SIP/2 - state 2 (In use) [Mar 5 17:56:34] DEBUG[4145] chan_sip.c: Setting framing from config on incoming call [Mar 5 17:56:34] DEBUG[3203] chan_sip.c: Checking device state for peer 2 [Mar 5 17:56:34] DEBUG[4145] chan_sip.c: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True [Mar 5 17:56:34] DEBUG[3227] app_queue.c: Device 'SIP/2' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Mar 5 17:56:34] DEBUG[4145] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Mar 5 17:56:34] VERBOSE[4145] logger.c: Audio is at 22.22.222.184 port 10048 [Mar 5 17:56:34] VERBOSE[4145] logger.c: Adding codec 0x4 (ulaw) to SDP [Mar 5 17:56:34] VERBOSE[4145] logger.c: Adding codec 0x8 (alaw) to SDP [Mar 5 17:56:34] VERBOSE[4145] logger.c: Adding codec 0x2 (gsm) to SDP [Mar 5 17:56:34] VERBOSE[4145] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Mar 5 17:56:34] DEBUG[4145] chan_sip.c: -- Done with adding codecs to SDP [Mar 5 17:56:34] DEBUG[4145] chan_sip.c: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) [Mar 5 17:56:34] VERBOSE[4145] logger.c: <--- Reliably Transmitting (NAT) to 11.111.11.3:2059 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 11.111.11.3:2059;branch=z9hG4bK-banm0nve0xko;received=11.111.11.3;rport=2059 From: "" ;tag=l2i4j4pt65 To: ;tag=as216ec317 Call-ID: 3c26aa35c0df-2k7sco3qp09e@snom320-00041324009C CSeq: 2 INVITE User-Agent: InnoSIP-app Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 289 v=0 o=root 19618 19619 IN IP4 22.22.222.184 s=session c=IN IP4 22.22.222.184 t=0 0 m=audio 10048 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Mar 5 17:56:34] VERBOSE[4145] logger.c: -- Packet2Packet bridging SIP/2-0a17d398 and SIP/1-0a2756e8 [Mar 5 17:56:34] VERBOSE[3212] logger.c: <--- SIP read from 11.111.11.3:2059 ---> ACK sip:1@22.22.222.184:5160 SIP/2.0 Via: SIP/2.0/UDP 11.111.11.3:2059;branch=z9hG4bK-4uayzt2r8ihd;rport From: "" ;tag=l2i4j4pt65 To: ;tag=as216ec317 Call-ID: 3c26aa35c0df-2k7sco3qp09e@snom320-00041324009C CSeq: 2 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 <-------------> [Mar 5 17:56:34] VERBOSE[3212] logger.c: --- (9 headers 0 lines) --- [Mar 5 17:56:34] DEBUG[3212] chan_sip.c: Stopping retransmission on '3c26aa35c0df-2k7sco3qp09e@snom320-00041324009C' of Response 2: Match Found [Mar 5 17:56:34] DEBUG[4145] rtp.c: Got RTCP report of 52 bytes [Mar 5 17:56:37] DEBUG[4145] rtp.c: Got RTCP report of 176 bytes [Mar 5 17:56:39] DEBUG[4145] rtp.c: Got RTCP report of 52 bytes [Mar 5 17:56:40] VERBOSE[3212] logger.c: <--- SIP read from 11.111.11.3:2059 ---> ==================== extension 1 puts extension 2 on hold ============================= <-------------> [Mar 5 17:56:41] DEBUG[4145] rtp.c: Got RTCP report of 200 bytes [Mar 5 17:56:41] VERBOSE[3212] logger.c: <--- SIP read from 11.111.11.3:27252 ---> INVITE sip:2@22.22.222.184:5160 SIP/2.0 Via: SIP/2.0/UDP 10.10.0.51:27252;branch=z9hG4bK-d8754z-c4727b3637040d08-1---d8754z-;rport Max-Forwards: 70 Contact: To: "2 ()";tag=as274f340f From: ;tag=fe2b522a Call-ID: 303483274359eba217d9f3736e46898c@22.22.222.184 CSeq: 2 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp User-Agent: eyeBeam release 1102q stamp 51814 Content-Length: 180 v=0 o=- 7 3 IN IP4 11.111.11.3 s=CounterPath eyeBeam 1.5 c=IN IP4 0.0.0.0 t=0 0 m=audio 38914 RTP/AVP 0 8 101 a=fmtp:101 0-15 a=rtpmap:101 telephone-event/8000 a=sendonly <-------------> [Mar 5 17:56:41] VERBOSE[3212] logger.c: --- (12 headers 9 lines) --- [Mar 5 17:56:41] VERBOSE[3212] logger.c: Sending to 11.111.11.3 : 27252 (NAT) [Mar 5 17:56:41] VERBOSE[3212] logger.c: Found RTP audio format 0 [Mar 5 17:56:41] VERBOSE[3212] logger.c: Found RTP audio format 8 [Mar 5 17:56:41] VERBOSE[3212] logger.c: Found RTP audio format 101 [Mar 5 17:56:41] DEBUG[3212] chan_sip.c: Peer doesn't provide T.38 UDPTL [Mar 5 17:56:41] VERBOSE[3212] logger.c: Peer audio RTP is at port 0.0.0.0:38914 [Mar 5 17:56:41] VERBOSE[3212] logger.c: Got unsupported a:fmtp in SDP offer [Mar 5 17:56:41] VERBOSE[3212] logger.c: Found audio description format telephone-event for ID 101 [Mar 5 17:56:41] DEBUG[3212] chan_sip.c: T38 state changed to 0 on channel SIP/1-0a2756e8 [Mar 5 17:56:41] VERBOSE[3212] logger.c: Capabilities: us - 0x40e (gsm|ulaw|alaw|ilbc), peer - audio=0xc (ulaw|alaw)/video=0x0 (nothing), combined - 0xc (ulaw|alaw) [Mar 5 17:56:41] VERBOSE[3212] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Mar 5 17:56:41] VERBOSE[3212] logger.c: Peer audio RTP is at port 0.0.0.0:38914 [Mar 5 17:56:41] DEBUG[3212] chan_sip.c: We're settling with these formats: 0xc (ulaw|alaw) [Mar 5 17:56:41] DEBUG[3212] chan_sip.c: Got a SIP re-invite for call 303483274359eba217d9f3736e46898c@22.22.222.184 [Mar 5 17:56:41] DEBUG[3212] chan_sip.c: SIP/1-0a2756e8: This call is UP.... [Mar 5 17:56:41] VERBOSE[3212] logger.c: <--- Transmitting (NAT) to 11.111.11.3:27252 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.10.0.51:27252;branch=z9hG4bK-d8754z-c4727b3637040d08-1---d8754z-;received=11.111.11.3;rport=27252 From: ;tag=fe2b522a To: "2 ()";tag=as274f340f Call-ID: 303483274359eba217d9f3736e46898c@22.22.222.184 CSeq: 2 INVITE User-Agent: InnoSIP-app Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Mar 5 17:56:41] DEBUG[3212] chan_sip.c: Setting framing from config on incoming call [Mar 5 17:56:41] DEBUG[3212] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: True [Mar 5 17:56:41] DEBUG[3212] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [Mar 5 17:56:41] VERBOSE[3212] logger.c: Audio is at 22.22.222.184 port 11372 [Mar 5 17:56:41] VERBOSE[3212] logger.c: Adding codec 0x4 (ulaw) to SDP [Mar 5 17:56:41] VERBOSE[3212] logger.c: Adding codec 0x8 (alaw) to SDP [Mar 5 17:56:41] VERBOSE[3212] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Mar 5 17:56:41] DEBUG[3212] chan_sip.c: -- Done with adding codecs to SDP [Mar 5 17:56:41] DEBUG[3212] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Mar 5 17:56:41] VERBOSE[3212] logger.c: <--- Reliably Transmitting (NAT) to 11.111.11.3:27252 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.10.0.51:27252;branch=z9hG4bK-d8754z-c4727b3637040d08-1---d8754z-;received=11.111.11.3;rport=27252 From: ;tag=fe2b522a To: "2 ()";tag=as274f340f Call-ID: 303483274359eba217d9f3736e46898c@22.22.222.184 CSeq: 2 INVITE User-Agent: InnoSIP-app Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 266 v=0 o=root 19618 19619 IN IP4 22.22.222.184 s=session c=IN IP4 22.22.222.184 t=0 0 m=audio 11372 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=recvonly <------------> [Mar 5 17:56:41] DEBUG[4145] channel.c: Set channel SIP/2-0a17d398 to write format slin [Mar 5 17:56:41] VERBOSE[4145] logger.c: -- Started music on hold, class 'blaa', on channel 'SIP/2-0a17d398' [Mar 5 17:56:41] DEBUG[4145] rtp.c: RTP NAT: Got audio from other end. Now sending to address 11.111.11.3:38914 [Mar 5 17:56:41] DEBUG[4145] rtp.c: Ooh, format changed from unknown to ulaw [Mar 5 17:56:41] DEBUG[4145] rtp.c: Created smoother: format: 4 ms: 20 len: 160 [Mar 5 17:56:41] DEBUG[4145] rtp.c: Created smoother: format: 4 ms: 20 len: 160 [Mar 5 17:56:41] DEBUG[4145] rtp.c: Difference is 59120, ms is 7410 [Mar 5 17:56:41] VERBOSE[3212] logger.c: <--- SIP read from 11.111.11.3:27252 ---> ACK sip:2@22.22.222.184:5160 SIP/2.0 Via: SIP/2.0/UDP 10.10.0.51:27252;branch=z9hG4bK-d8754z-9074f0736238296f-1---d8754z-;rport Max-Forwards: 70 Contact: To: "2 ()";tag=as274f340f From: ;tag=fe2b522a Call-ID: 303483274359eba217d9f3736e46898c@22.22.222.184 CSeq: 2 ACK User-Agent: eyeBeam release 1102q stamp 51814 Content-Length: 0 ==================== extension 1 calls extension 3 ============================= <-------------> [Mar 5 17:56:41] VERBOSE[3212] logger.c: --- (10 headers 0 lines) --- [Mar 5 17:56:41] DEBUG[3212] chan_sip.c: Stopping retransmission on '303483274359eba217d9f3736e46898c@22.22.222.184' of Response 2: Match Found [Mar 5 17:56:43] VERBOSE[3212] logger.c: <--- SIP read from 11.111.11.3:27252 ---> INVITE sip:3@app.fooobar.at SIP/2.0 Via: SIP/2.0/UDP 10.10.0.51:27252;branch=z9hG4bK-d8754z-5631761b7821ec0b-1---d8754z-;rport Max-Forwards: 70 Contact: To: "3" From: "";tag=fb2b594c Call-ID: OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ. CSeq: 1 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp User-Agent: eyeBeam release 1102q stamp 51814 Content-Length: 232 v=0 o=- 1 2 IN IP4 11.111.11.3 s=CounterPath eyeBeam 1.5 c=IN IP4 11.111.11.3 t=0 0 m=audio 64188 RTP/AVP 0 8 18 101 a=fmtp:18 annexb=yes a=fmtp:101 0-15 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 a=sendrecv <-------------> [Mar 5 17:56:43] VERBOSE[3212] logger.c: --- (12 headers 11 lines) --- [Mar 5 17:56:43] DEBUG[3212] chan_sip.c: Setting NAT on RTP to On [Mar 5 17:56:43] DEBUG[3212] chan_sip.c: Setting NAT on UDPTL to On [Mar 5 17:56:43] DEBUG[3212] chan_sip.c: Allocating new SIP dialog for OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ. - INVITE (With RTP) [Mar 5 17:56:43] VERBOSE[3212] logger.c: Sending to 11.111.11.3 : 27252 (NAT) [Mar 5 17:56:43] VERBOSE[3212] logger.c: Using INVITE request as basis request - OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ. [Mar 5 17:56:43] DEBUG[3212] chan_sip.c: Setting NAT on RTP to On [Mar 5 17:56:43] DEBUG[3212] chan_sip.c: Setting NAT on UDPTL to On [Mar 5 17:56:43] VERBOSE[3212] logger.c: <--- Reliably Transmitting (NAT) to 11.111.11.3:27252 ---> SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 10.10.0.51:27252;branch=z9hG4bK-d8754z-5631761b7821ec0b-1---d8754z-;received=11.111.11.3;rport=27252 From: "";tag=fb2b594c To: "3";tag=as54aa160c Call-ID: OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ. CSeq: 1 INVITE User-Agent: InnoSIP-app Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Proxy-Authenticate: Digest algorithm=MD5, realm="app.fooobar.at", nonce="18c3525c" Content-Length: 0 <------------> [Mar 5 17:56:43] VERBOSE[3212] logger.c: Scheduling destruction of SIP dialog 'OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ.' in 32000 ms (Method: INVITE) [Mar 5 17:56:43] VERBOSE[3212] logger.c: Found user '1' [Mar 5 17:56:43] VERBOSE[3212] logger.c: <--- SIP read from 11.111.11.3:27252 ---> ACK sip:3@app.fooobar.at SIP/2.0 Via: SIP/2.0/UDP 10.10.0.51:27252;branch=z9hG4bK-d8754z-5631761b7821ec0b-1---d8754z-;rport To: "3";tag=as54aa160c From: "";tag=fb2b594c Call-ID: OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ. CSeq: 1 ACK Content-Length: 0 <-------------> [Mar 5 17:56:43] VERBOSE[3212] logger.c: --- (7 headers 0 lines) --- [Mar 5 17:56:43] DEBUG[3212] chan_sip.c: Stopping retransmission on 'OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ.' of Response 1: Match Found [Mar 5 17:56:43] VERBOSE[3212] logger.c: <--- SIP read from 11.111.11.3:27252 ---> INVITE sip:3@app.fooobar.at SIP/2.0 Via: SIP/2.0/UDP 10.10.0.51:27252;branch=z9hG4bK-d8754z-4b305c6d610b7b46-1---d8754z-;rport Max-Forwards: 70 Contact: To: "3" From: "";tag=fb2b594c Call-ID: OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ. CSeq: 2 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp Proxy-Authorization: Digest username="1",realm="app.fooobar.at",nonce="18c3525c",uri="sip:3@app.fooobar.at",response="bbce8338a5115131c6bf0bf2fbd2eafb",algorithm=MD5 User-Agent: eyeBeam release 1102q stamp 51814 Content-Length: 232 v=0 o=- 1 2 IN IP4 11.111.11.3 s=CounterPath eyeBeam 1.5 c=IN IP4 11.111.11.3 t=0 0 m=audio 64188 RTP/AVP 0 8 18 101 a=fmtp:18 annexb=yes a=fmtp:101 0-15 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 a=sendrecv <-------------> [Mar 5 17:56:43] VERBOSE[3212] logger.c: --- (13 headers 11 lines) --- [Mar 5 17:56:43] VERBOSE[3212] logger.c: Sending to 11.111.11.3 : 27252 (NAT) [Mar 5 17:56:43] VERBOSE[3212] logger.c: Using INVITE request as basis request - OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ. [Mar 5 17:56:43] DEBUG[3212] chan_sip.c: Setting NAT on RTP to On [Mar 5 17:56:43] DEBUG[3212] chan_sip.c: Setting NAT on UDPTL to On [Mar 5 17:56:43] VERBOSE[3212] logger.c: Found user '1' [Mar 5 17:56:43] VERBOSE[3212] logger.c: Found RTP audio format 0 [Mar 5 17:56:43] VERBOSE[3212] logger.c: Found RTP audio format 8 [Mar 5 17:56:43] VERBOSE[3212] logger.c: Found RTP audio format 18 [Mar 5 17:56:43] VERBOSE[3212] logger.c: Found RTP audio format 101 [Mar 5 17:56:43] DEBUG[3212] chan_sip.c: Peer doesn't provide T.38 UDPTL [Mar 5 17:56:43] VERBOSE[3212] logger.c: Peer audio RTP is at port 11.111.11.3:64188 [Mar 5 17:56:43] VERBOSE[3212] logger.c: Got unsupported a:fmtp in SDP offer [Mar 5 17:56:43] VERBOSE[3212] logger.c: Got unsupported a:fmtp in SDP offer [Mar 5 17:56:43] VERBOSE[3212] logger.c: Found audio description format G729 for ID 18 [Mar 5 17:56:43] VERBOSE[3212] logger.c: Found audio description format telephone-event for ID 101 [Mar 5 17:56:43] DEBUG[3212] chan_sip.c: T38 state changed to 0 on channel [Mar 5 17:56:43] VERBOSE[3212] logger.c: Capabilities: us - 0x40e (gsm|ulaw|alaw|ilbc), peer - audio=0x10c (ulaw|alaw|g729)/video=0x0 (nothing), combined - 0xc (ulaw|alaw) [Mar 5 17:56:43] VERBOSE[3212] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Mar 5 17:56:43] VERBOSE[3212] logger.c: Peer audio RTP is at port 11.111.11.3:64188 [Mar 5 17:56:43] DEBUG[3212] chan_sip.c: We're settling with these formats: 0xc (ulaw|alaw) [Mar 5 17:56:43] DEBUG[3212] chan_sip.c: Checking SIP call limits for device 1 [Mar 5 17:56:43] DEBUG[3212] chan_sip.c: Updating call counter for incoming call [Mar 5 17:56:43] DEBUG[3212] chan_sip.c: Call from peer '1' is 2 out of 2 [Mar 5 17:56:43] DEBUG[3212] devicestate.c: Notification of state change to be queued on device/channel SIP/1 [Mar 5 17:56:43] VERBOSE[3212] logger.c: Looking for 3 in fromSipPbx (domain app.fooobar.at) [Mar 5 17:56:43] DEBUG[3212] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Mar 5 17:56:43] DEBUG[3212] chan_sip.c: *** Joint capabilities are 0xc (ulaw|alaw) [Mar 5 17:56:43] DEBUG[3212] chan_sip.c: *** Our capabilities are 0x40e (gsm|ulaw|alaw|ilbc) [Mar 5 17:56:43] DEBUG[3212] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Mar 5 17:56:43] DEBUG[3212] chan_sip.c: This channel will not be able to handle video. [Mar 5 17:56:43] DEBUG[3212] chan_sip.c: build_route: Contact hop: [Mar 5 17:56:43] VERBOSE[3212] logger.c: list_route: hop: [Mar 5 17:56:43] DEBUG[3212] chan_sip.c: SIP/1-0a26b3d0: New call is still down.... Trying... [Mar 5 17:56:43] VERBOSE[3212] logger.c: <--- Transmitting (NAT) to 11.111.11.3:27252 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.10.0.51:27252;branch=z9hG4bK-d8754z-4b305c6d610b7b46-1---d8754z-;received=11.111.11.3;rport=27252 From: "";tag=fb2b594c To: "3" Call-ID: OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ. CSeq: 2 INVITE User-Agent: InnoSIP-app Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Mar 5 17:56:43] DEBUG[3212] devicestate.c: Notification of state change to be queued on device/channel SIP/1 [Mar 5 17:56:43] DEBUG[3203] chan_sip.c: Checking device state for peer 1 [Mar 5 17:56:43] DEBUG[4146] pbx.c: Launching 'DumpChan' [Mar 5 17:56:43] DEBUG[3203] devicestate.c: Changing state for SIP/1 - state 3 (Busy) [Mar 5 17:56:43] VERBOSE[4146] logger.c: -- Executing [3@fromSipPbx:1] DumpChan("SIP/1-0a26b3d0", "") in new stack [Mar 5 17:56:43] DEBUG[3203] chan_sip.c: Checking device state for peer 1 [Mar 5 17:56:43] DEBUG[3203] chan_sip.c: Checking device state for peer 1 [Mar 5 17:56:43] DEBUG[3203] devicestate.c: Changing state for SIP/1 - state 3 (Busy) [Mar 5 17:56:43] VERBOSE[4146] logger.c: ... dialplan processing ... [Mar 5 17:56:43] DEBUG[4146] pbx.c: Launching 'Dial' [Mar 5 17:56:43] VERBOSE[4146] logger.c: -- Executing [s@macro-toPbxMakro:58] Dial("SIP/1-0a26b3d0", "SIP/3|300|i") in new stack [Mar 5 17:56:43] DEBUG[4146] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw) [Mar 5 17:56:43] DEBUG[4146] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Mar 5 17:56:43] DEBUG[4146] chan_sip.c: Our T38 capability (3856) [Mar 5 17:56:43] DEBUG[4146] chan_sip.c: Setting NAT on RTP to On [Mar 5 17:56:43] DEBUG[4146] chan_sip.c: Setting NAT on UDPTL to On [Mar 5 17:56:43] DEBUG[4146] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Mar 5 17:56:43] DEBUG[4146] chan_sip.c: *** Joint capabilities are 0x0 (nothing) [Mar 5 17:56:43] DEBUG[4146] chan_sip.c: *** Our capabilities are 0x40e (gsm|ulaw|alaw|ilbc) [Mar 5 17:56:43] DEBUG[4146] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Mar 5 17:56:43] DEBUG[4146] chan_sip.c: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Mar 5 17:56:43] DEBUG[4146] chan_sip.c: This channel will not be able to handle video. [Mar 5 17:56:43] DEBUG[4146] channel.c: Not copying variable DIALEDTIME. ... [Mar 5 17:56:43] DEBUG[4146] channel.c: Not copying variable SIPURI. [Mar 5 17:56:43] DEBUG[4146] chan_sip.c: Outgoing Call for 3 [Mar 5 17:56:43] DEBUG[4146] chan_sip.c: Updating call counter for outgoing call [Mar 5 17:56:43] DEBUG[4146] chan_sip.c: Call to peer '3' is 1 out of 2 [Mar 5 17:56:43] DEBUG[4146] devicestate.c: Notification of state change to be queued on device/channel SIP/3 [Mar 5 17:56:43] DEBUG[4146] chan_sip.c: Our T38 capability (3856), joint T38 capability (3856) [Mar 5 17:56:43] DEBUG[3203] chan_sip.c: Checking device state for peer 3 [Mar 5 17:56:43] DEBUG[3203] devicestate.c: Changing state for SIP/3 - state 6 (Ringing) [Mar 5 17:56:43] DEBUG[4146] chan_sip.c: ** Our capability: 0x40e (gsm|ulaw|alaw|ilbc) Video flag: False [Mar 5 17:56:43] DEBUG[3227] app_queue.c: Device 'SIP/3' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Mar 5 17:56:43] DEBUG[4146] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [Mar 5 17:56:43] DEBUG[3203] chan_sip.c: Checking device state for peer 3 [Mar 5 17:56:43] VERBOSE[4146] logger.c: Audio is at 22.22.222.184 port 16620 [Mar 5 17:56:43] VERBOSE[4146] logger.c: Adding codec 0x4 (ulaw) to SDP [Mar 5 17:56:43] VERBOSE[4146] logger.c: Adding codec 0x8 (alaw) to SDP [Mar 5 17:56:43] VERBOSE[4146] logger.c: Adding codec 0x400 (ilbc) to SDP [Mar 5 17:56:43] VERBOSE[4146] logger.c: Adding codec 0x2 (gsm) to SDP [Mar 5 17:56:43] VERBOSE[4146] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Mar 5 17:56:43] DEBUG[4146] chan_sip.c: -- Done with adding codecs to SDP [Mar 5 17:56:43] DEBUG[4146] chan_sip.c: Done building SDP. Settling with this capability: 0x40e (gsm|ulaw|alaw|ilbc) [Mar 5 17:56:43] VERBOSE[4146] logger.c: Reliably Transmitting (NAT) to 11.111.11.3:5200: INVITE sip:3@11.111.11.3:5200;line=n774g73r SIP/2.0 Via: SIP/2.0/UDP 22.22.222.184:5160;branch=z9hG4bK73a56440;rport From: "1 (Klaus Darilion)" ;tag=as742ffae1 To: Contact: Call-ID: 5fb7fedf1663031363b01ea9402b7418@22.22.222.184 CSeq: 102 INVITE User-Agent: InnoSIP-app Max-Forwards: 70 Date: Thu, 05 Mar 2009 16:56:43 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 334 v=0 o=root 19618 19618 IN IP4 22.22.222.184 s=session c=IN IP4 22.22.222.184 t=0 0 m=audio 16620 RTP/AVP 0 8 97 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=30 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Mar 5 17:56:43] VERBOSE[4146] logger.c: -- Called 3 [Mar 5 17:56:43] VERBOSE[3212] logger.c: <--- SIP read from 11.111.11.3:5200 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 22.22.222.184:5160;branch=z9hG4bK73a56440;rport=5160 From: "1 (Klaus Darilion)" ;tag=as742ffae1 To: ;tag=fvtg3kg6jk Call-ID: 5fb7fedf1663031363b01ea9402b7418@22.22.222.184 CSeq: 102 INVITE Contact: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Content-Length: 0 <-------------> [Mar 5 17:56:43] VERBOSE[3212] logger.c: --- (10 headers 0 lines) --- [Mar 5 17:56:43] DEBUG[3212] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '5fb7fedf1663031363b01ea9402b7418@22.22.222.184' Request 102: Found [Mar 5 17:56:43] DEBUG[3212] devicestate.c: Notification of state change to be queued on device/channel SIP/3 [Mar 5 17:56:43] DEBUG[3203] chan_sip.c: Checking device state for peer 3 [Mar 5 17:56:43] VERBOSE[4146] logger.c: -- SIP/3-0a176a78 is ringing [Mar 5 17:56:43] DEBUG[3203] devicestate.c: Changing state for SIP/3 - state 6 (Ringing) [Mar 5 17:56:43] VERBOSE[4146] logger.c: <--- Transmitting (NAT) to 11.111.11.3:27252 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.10.0.51:27252;branch=z9hG4bK-d8754z-4b305c6d610b7b46-1---d8754z-;received=11.111.11.3;rport=27252 From: "";tag=fb2b594c To: "3";tag=as539a8593 Call-ID: OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ. CSeq: 2 INVITE User-Agent: InnoSIP-app Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Mar 5 17:56:43] DEBUG[3227] app_queue.c: Device 'SIP/3' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Mar 5 17:56:43] DEBUG[3203] chan_sip.c: Checking device state for peer 3 [Mar 5 17:56:44] VERBOSE[3212] logger.c: <--- SIP read from 11.111.11.3:5200 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 22.22.222.184:5160;branch=z9hG4bK73a56440;rport=5160 From: "1 (Klaus Darilion)" ;tag=as742ffae1 To: ;tag=fvtg3kg6jk Call-ID: 5fb7fedf1663031363b01ea9402b7418@22.22.222.184 CSeq: 102 INVITE Contact: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Content-Length: 0 <-------------> [Mar 5 17:56:44] VERBOSE[3212] logger.c: --- (10 headers 0 lines) --- [Mar 5 17:56:44] DEBUG[3212] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '5fb7fedf1663031363b01ea9402b7418@22.22.222.184' Request 102: Found [Mar 5 17:56:44] VERBOSE[4146] logger.c: -- SIP/3-0a176a78 is ringing [Mar 5 17:56:44] DEBUG[4145] rtp.c: Got RTCP report of 52 bytes [Mar 5 17:56:44] DEBUG[4145] rtp.c: Got RTCP report of 200 bytes [Mar 5 17:56:45] VERBOSE[3212] logger.c: <--- SIP read from 11.111.11.3:5200 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 22.22.222.184:5160;branch=z9hG4bK73a56440;rport=5160 From: "1 (Klaus Darilion)" ;tag=as742ffae1 To: ;tag=fvtg3kg6jk Call-ID: 5fb7fedf1663031363b01ea9402b7418@22.22.222.184 CSeq: 102 INVITE Contact: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Content-Length: 0 <-------------> [Mar 5 17:56:45] VERBOSE[3212] logger.c: --- (10 headers 0 lines) --- [Mar 5 17:56:45] DEBUG[3212] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '5fb7fedf1663031363b01ea9402b7418@22.22.222.184' Request 102: Found [Mar 5 17:56:45] VERBOSE[4146] logger.c: -- SIP/3-0a176a78 is ringing [Mar 5 17:56:45] VERBOSE[3212] logger.c: <--- SIP read from 11.111.11.3:5200 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 22.22.222.184:5160;branch=z9hG4bK73a56440;rport=5160 From: "1 (Klaus Darilion)" ;tag=as742ffae1 To: ;tag=fvtg3kg6jk Call-ID: 5fb7fedf1663031363b01ea9402b7418@22.22.222.184 CSeq: 102 INVITE Contact: User-Agent: snom200-3.56z Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces Content-Type: application/sdp Content-Length: 218 v=0 o=root 1477789674 1477789674 IN IP4 11.111.11.3 s=call c=IN IP4 11.111.11.3 t=0 0 m=audio 10096 RTP/AVP 0 101 a=rtpmap:0 pcmu/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv <-------------> [Mar 5 17:56:45] VERBOSE[3212] logger.c: --- (13 headers 11 lines) --- [Mar 5 17:56:45] DEBUG[3212] chan_sip.c: Acked pending invite 102 [Mar 5 17:56:45] DEBUG[3212] chan_sip.c: Stopping retransmission on '5fb7fedf1663031363b01ea9402b7418@22.22.222.184' of Request 102: Match Found [Mar 5 17:56:45] VERBOSE[3212] logger.c: Found RTP audio format 0 [Mar 5 17:56:45] VERBOSE[3212] logger.c: Found RTP audio format 101 [Mar 5 17:56:45] DEBUG[3212] chan_sip.c: Peer doesn't provide T.38 UDPTL [Mar 5 17:56:45] VERBOSE[3212] logger.c: Peer audio RTP is at port 11.111.11.3:10096 [Mar 5 17:56:45] VERBOSE[3212] logger.c: Found audio description format pcmu for ID 0 [Mar 5 17:56:45] VERBOSE[3212] logger.c: Found audio description format telephone-event for ID 101 [Mar 5 17:56:45] VERBOSE[3212] logger.c: Got unsupported a:fmtp in SDP offer [Mar 5 17:56:45] DEBUG[3212] chan_sip.c: T38 state changed to 0 on channel SIP/3-0a176a78 [Mar 5 17:56:45] VERBOSE[3212] logger.c: Capabilities: us - 0x40e (gsm|ulaw|alaw|ilbc), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) [Mar 5 17:56:45] VERBOSE[3212] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Mar 5 17:56:45] VERBOSE[3212] logger.c: Peer audio RTP is at port 11.111.11.3:10096 [Mar 5 17:56:45] DEBUG[3212] chan_sip.c: We're settling with these formats: 0x4 (ulaw) [Mar 5 17:56:45] DEBUG[3212] chan_sip.c: Updating call counter for outgoing call [Mar 5 17:56:45] DEBUG[3212] devicestate.c: Notification of state change to be queued on device/channel SIP/3 [Mar 5 17:56:45] DEBUG[3212] chan_sip.c: build_route: Contact hop: [Mar 5 17:56:45] DEBUG[3203] chan_sip.c: Checking device state for peer 3 [Mar 5 17:56:45] VERBOSE[3212] logger.c: list_route: hop: [Mar 5 17:56:45] DEBUG[3203] devicestate.c: Changing state for SIP/3 - state 2 (In use) [Mar 5 17:56:45] DEBUG[3212] chan_sip.c: Strict routing enforced for session 5fb7fedf1663031363b01ea9402b7418@22.22.222.184 [Mar 5 17:56:45] DEBUG[3203] chan_sip.c: Checking device state for peer 3 [Mar 5 17:56:45] VERBOSE[3212] logger.c: set_destination: Parsing for address/port to send to [Mar 5 17:56:45] DEBUG[3227] app_queue.c: Device 'SIP/3' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Mar 5 17:56:45] VERBOSE[3212] logger.c: set_destination: set destination to 11.111.11.3, port 5200 [Mar 5 17:56:45] VERBOSE[3212] logger.c: Transmitting (NAT) to 11.111.11.3:5200: ACK sip:3@11.111.11.3:5200;line=n774g73r SIP/2.0 Via: SIP/2.0/UDP 22.22.222.184:5160;branch=z9hG4bK5154a188;rport From: "1 (Klaus Darilion)" ;tag=as742ffae1 To: ;tag=fvtg3kg6jk Contact: Call-ID: 5fb7fedf1663031363b01ea9402b7418@22.22.222.184 CSeq: 102 ACK User-Agent: InnoSIP-app Max-Forwards: 70 Content-Length: 0 --- [Mar 5 17:56:45] DEBUG[4146] devicestate.c: Notification of state change to be queued on device/channel SIP/3 [Mar 5 17:56:45] DEBUG[3203] chan_sip.c: Checking device state for peer 3 [Mar 5 17:56:45] VERBOSE[4146] logger.c: -- SIP/3-0a176a78 answered SIP/1-0a26b3d0 [Mar 5 17:56:45] DEBUG[3203] devicestate.c: Changing state for SIP/3 - state 2 (In use) [Mar 5 17:56:45] DEBUG[3203] chan_sip.c: Checking device state for peer 3 [Mar 5 17:56:45] DEBUG[4146] devicestate.c: Notification of state change to be queued on device/channel SIP/1 [Mar 5 17:56:45] DEBUG[3227] app_queue.c: Device 'SIP/3' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Mar 5 17:56:45] DEBUG[4146] chan_sip.c: SIP answering channel: SIP/1-0a26b3d0 [Mar 5 17:56:45] DEBUG[3203] chan_sip.c: Checking device state for peer 1 [Mar 5 17:56:45] DEBUG[3203] devicestate.c: Changing state for SIP/1 - state 3 (Busy) [Mar 5 17:56:45] DEBUG[4146] chan_sip.c: Setting framing from config on incoming call [Mar 5 17:56:45] DEBUG[3203] chan_sip.c: Checking device state for peer 1 [Mar 5 17:56:45] DEBUG[4146] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: True [Mar 5 17:56:45] DEBUG[3227] app_queue.c: Device 'SIP/1' changed to state '3' (Busy) but we don't care because they're not a member of any queue. [Mar 5 17:56:45] DEBUG[4146] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Mar 5 17:56:45] VERBOSE[4146] logger.c: Audio is at 22.22.222.184 port 14416 [Mar 5 17:56:45] VERBOSE[4146] logger.c: Adding codec 0x4 (ulaw) to SDP [Mar 5 17:56:45] VERBOSE[4146] logger.c: Adding codec 0x8 (alaw) to SDP [Mar 5 17:56:45] VERBOSE[4146] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Mar 5 17:56:45] DEBUG[4146] chan_sip.c: -- Done with adding codecs to SDP [Mar 5 17:56:45] DEBUG[4146] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Mar 5 17:56:45] VERBOSE[4146] logger.c: <--- Reliably Transmitting (NAT) to 11.111.11.3:27252 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.10.0.51:27252;branch=z9hG4bK-d8754z-4b305c6d610b7b46-1---d8754z-;received=11.111.11.3;rport=27252 From: "";tag=fb2b594c To: "3";tag=as539a8593 Call-ID: OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ. CSeq: 2 INVITE User-Agent: InnoSIP-app Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 266 v=0 o=root 19618 19618 IN IP4 22.22.222.184 s=session c=IN IP4 22.22.222.184 t=0 0 m=audio 14416 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Mar 5 17:56:45] VERBOSE[4146] logger.c: -- Packet2Packet bridging SIP/1-0a26b3d0 and SIP/3-0a176a78 [Mar 5 17:56:45] DEBUG[4146] rtp.c: Got RTCP report of 132 bytes [Mar 5 17:56:45] VERBOSE[3212] logger.c: <--- SIP read from 11.111.11.3:27252 ---> ACK sip:3@22.22.222.184:5160 SIP/2.0 Via: SIP/2.0/UDP 10.10.0.51:27252;branch=z9hG4bK-d8754z-2c4a3e6f9f36656e-1---d8754z-;rport Max-Forwards: 70 Contact: To: "3";tag=as539a8593 From: "";tag=fb2b594c Call-ID: OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ. CSeq: 2 ACK Proxy-Authorization: Digest username="1",realm="app.fooobar.at",nonce="18c3525c",uri="sip:3@app.fooobar.at",response="bbce8338a5115131c6bf0bf2fbd2eafb",algorithm=MD5 User-Agent: eyeBeam release 1102q stamp 51814 Content-Length: 0 <-------------> [Mar 5 17:56:45] VERBOSE[3212] logger.c: --- (11 headers 0 lines) --- [Mar 5 17:56:45] DEBUG[3212] chan_sip.c: Stopping retransmission on 'OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ.' of Response 2: Match Found [Mar 5 17:56:48] DEBUG[4145] rtp.c: Got RTCP report of 180 bytes [Mar 5 17:56:49] DEBUG[4146] rtp.c: Got RTCP report of 176 bytes [Mar 5 17:56:49] DEBUG[4145] rtp.c: Got RTCP report of 52 bytes ==================== extension 1 puts extension 3 on hold ============================= [Mar 5 17:56:49] VERBOSE[3212] logger.c: <--- SIP read from 11.111.11.3:27252 ---> INVITE sip:3@22.22.222.184:5160 SIP/2.0 Via: SIP/2.0/UDP 10.10.0.51:27252;branch=z9hG4bK-d8754z-0e657000e956761f-1---d8754z-;rport Max-Forwards: 70 Contact: To: "3";tag=as539a8593 From: "";tag=fb2b594c Call-ID: OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ. CSeq: 3 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp Proxy-Authorization: Digest username="1",realm="app.fooobar.at",nonce="18c3525c",uri="sip:3@22.22.222.184:5160",response="cdcc57472a1b9b7f0cc6aa9e2ec811a6",algorithm=MD5 User-Agent: eyeBeam release 1102q stamp 51814 Content-Length: 180 v=0 o=- 1 3 IN IP4 11.111.11.3 s=CounterPath eyeBeam 1.5 c=IN IP4 0.0.0.0 t=0 0 m=audio 64188 RTP/AVP 0 8 101 a=fmtp:101 0-15 a=rtpmap:101 telephone-event/8000 a=sendonly <-------------> [Mar 5 17:56:49] VERBOSE[3212] logger.c: --- (13 headers 9 lines) --- [Mar 5 17:56:49] VERBOSE[3212] logger.c: Sending to 11.111.11.3 : 27252 (NAT) [Mar 5 17:56:49] VERBOSE[3212] logger.c: Found RTP audio format 0 [Mar 5 17:56:49] VERBOSE[3212] logger.c: Found RTP audio format 8 [Mar 5 17:56:49] VERBOSE[3212] logger.c: Found RTP audio format 101 [Mar 5 17:56:49] DEBUG[3212] chan_sip.c: Peer doesn't provide T.38 UDPTL [Mar 5 17:56:49] VERBOSE[3212] logger.c: Peer audio RTP is at port 0.0.0.0:64188 [Mar 5 17:56:49] VERBOSE[3212] logger.c: Got unsupported a:fmtp in SDP offer [Mar 5 17:56:49] VERBOSE[3212] logger.c: Found audio description format telephone-event for ID 101 [Mar 5 17:56:49] DEBUG[3212] chan_sip.c: T38 state changed to 0 on channel SIP/1-0a26b3d0 [Mar 5 17:56:49] VERBOSE[3212] logger.c: Capabilities: us - 0x40e (gsm|ulaw|alaw|ilbc), peer - audio=0xc (ulaw|alaw)/video=0x0 (nothing), combined - 0xc (ulaw|alaw) [Mar 5 17:56:49] VERBOSE[3212] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Mar 5 17:56:49] VERBOSE[3212] logger.c: Peer audio RTP is at port 0.0.0.0:64188 [Mar 5 17:56:49] DEBUG[3212] chan_sip.c: We're settling with these formats: 0xc (ulaw|alaw) [Mar 5 17:56:49] DEBUG[3212] chan_sip.c: Got a SIP re-invite for call OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ. [Mar 5 17:56:49] DEBUG[3212] chan_sip.c: SIP/1-0a26b3d0: This call is UP.... [Mar 5 17:56:49] VERBOSE[3212] logger.c: <--- Transmitting (NAT) to 11.111.11.3:27252 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.10.0.51:27252;branch=z9hG4bK-d8754z-0e657000e956761f-1---d8754z-;received=11.111.11.3;rport=27252 From: "";tag=fb2b594c To: "3";tag=as539a8593 Call-ID: OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ. CSeq: 3 INVITE User-Agent: InnoSIP-app Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Mar 5 17:56:49] DEBUG[3212] chan_sip.c: Setting framing from config on incoming call [Mar 5 17:56:49] DEBUG[3212] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: True [Mar 5 17:56:49] DEBUG[3212] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Mar 5 17:56:49] VERBOSE[3212] logger.c: Audio is at 22.22.222.184 port 14416 [Mar 5 17:56:49] VERBOSE[3212] logger.c: Adding codec 0x4 (ulaw) to SDP [Mar 5 17:56:49] VERBOSE[3212] logger.c: Adding codec 0x8 (alaw) to SDP [Mar 5 17:56:49] VERBOSE[3212] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Mar 5 17:56:49] DEBUG[3212] chan_sip.c: -- Done with adding codecs to SDP [Mar 5 17:56:49] DEBUG[3212] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Mar 5 17:56:49] VERBOSE[3212] logger.c: <--- Reliably Transmitting (NAT) to 11.111.11.3:27252 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.10.0.51:27252;branch=z9hG4bK-d8754z-0e657000e956761f-1---d8754z-;received=11.111.11.3;rport=27252 From: "";tag=fb2b594c To: "3";tag=as539a8593 Call-ID: OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ. CSeq: 3 INVITE User-Agent: InnoSIP-app Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 266 v=0 o=root 19618 19619 IN IP4 22.22.222.184 s=session c=IN IP4 22.22.222.184 t=0 0 m=audio 14416 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=recvonly <------------> [Mar 5 17:56:49] DEBUG[4146] channel.c: Set channel SIP/3-0a176a78 to write format slin [Mar 5 17:56:49] VERBOSE[4146] logger.c: -- Started music on hold, class 'blaa', on channel 'SIP/3-0a176a78' [Mar 5 17:56:49] DEBUG[4146] rtp.c: RTP NAT: Got audio from other end. Now sending to address 11.111.11.3:64188 [Mar 5 17:56:49] DEBUG[4146] rtp.c: Ooh, format changed from unknown to ulaw [Mar 5 17:56:49] DEBUG[4146] rtp.c: Created smoother: format: 4 ms: 20 len: 160 [Mar 5 17:56:49] DEBUG[4146] rtp.c: Ooh, format changed from unknown to ulaw [Mar 5 17:56:49] DEBUG[4146] rtp.c: Created smoother: format: 4 ms: 20 len: 160 [Mar 5 17:56:49] VERBOSE[3212] logger.c: <--- SIP read from 11.111.11.3:27252 ---> ACK sip:3@22.22.222.184:5160 SIP/2.0 Via: SIP/2.0/UDP 10.10.0.51:27252;branch=z9hG4bK-d8754z-c40b4a0b6210b819-1---d8754z-;rport Max-Forwards: 70 Contact: To: "3";tag=as539a8593 From: "";tag=fb2b594c Call-ID: OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ. CSeq: 3 ACK Proxy-Authorization: Digest username="1",realm="app.fooobar.at",nonce="18c3525c",uri="sip:3@22.22.222.184:5160",response="cdcc57472a1b9b7f0cc6aa9e2ec811a6",algorithm=MD5 User-Agent: eyeBeam release 1102q stamp 51814 Content-Length: 0 <-------------> [Mar 5 17:56:49] VERBOSE[3212] logger.c: --- (11 headers 0 lines) --- [Mar 5 17:56:49] DEBUG[3212] chan_sip.c: Stopping retransmission on 'OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ.' of Response 3: Match Found [Mar 5 17:56:49] DEBUG[3204] res_musiconhold.c: Read 1434 bytes of audio while expecting 1600 [Mar 5 17:56:50] NOTICE[3204] res_musiconhold.c: Request to schedule in the past?!?! [Mar 5 17:56:50] NOTICE[3204] res_musiconhold.c: Request to schedule in the past?!?! [Mar 5 17:56:50] DEBUG[4145] rtp.c: Difference is 5752, ms is 739 [Mar 5 17:56:50] DEBUG[4146] rtp.c: Difference is 5760, ms is 740 [Mar 5 17:56:51] DEBUG[4145] rtp.c: Got RTCP report of 180 bytes ==================== extension 1 refers extension 3 to extension 2 ============================= [Mar 5 17:56:52] VERBOSE[3212] logger.c: <--- SIP read from 11.111.11.3:27252 ---> REFER sip:3@22.22.222.184:5160 SIP/2.0 Via: SIP/2.0/UDP 10.10.0.51:27252;branch=z9hG4bK-d8754z-bc78e812795fd65d-1---d8754z-;rport Max-Forwards: 70 Contact: To: "3";tag=as539a8593 From: "";tag=fb2b594c Call-ID: OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ. CSeq: 4 REFER Proxy-Authorization: Digest username="1",realm="app.fooobar.at",nonce="18c3525c",uri="sip:3@22.22.222.184:5160",response="6fc7ce23ba3000cd3d32b959df67e269",algorithm=MD5 User-Agent: eyeBeam release 1102q stamp 51814 Refer-To: "2 ()" Referred-By: "" Content-Length: 0 <-------------> [Mar 5 17:56:52] VERBOSE[3212] logger.c: --- (13 headers 0 lines) --- [Mar 5 17:56:52] VERBOSE[3212] logger.c: Call OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ. got a SIP call transfer from caller: (REFER)! [Mar 5 17:56:52] DEBUG[3212] chan_sip.c: Attended transfer: Will use Replace-Call-ID : 303483274359eba217d9f3736e46898c@22.22.222.184 F-tag: fe2b522a T-tag: as274f340f [Mar 5 17:56:52] VERBOSE[3212] logger.c: SIP transfer to extension 2@handlePbxTransfer by 1@app.fooobar.at [Mar 5 17:56:52] DEBUG[3212] chan_sip.c: SIP attended transfer: Transferer channel SIP/1-0a26b3d0, transferee channel SIP/3-0a176a78 [Mar 5 17:56:52] VERBOSE[3212] logger.c: <--- Transmitting (NAT) to 11.111.11.3:27252 ---> SIP/2.0 202 Accepted Via: SIP/2.0/UDP 10.10.0.51:27252;branch=z9hG4bK-d8754z-bc78e812795fd65d-1---d8754z-;received=11.111.11.3;rport=27252 From: "";tag=fb2b594c To: "3";tag=as539a8593 Call-ID: OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ. CSeq: 4 REFER User-Agent: InnoSIP-app Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Mar 5 17:56:52] DEBUG[3212] chan_sip.c: Strict routing enforced for session OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ. [Mar 5 17:56:52] VERBOSE[3212] logger.c: set_destination: Parsing for address/port to send to [Mar 5 17:56:52] VERBOSE[3212] logger.c: set_destination: set destination to 11.111.11.3, port 27252 [Mar 5 17:56:52] VERBOSE[3212] logger.c: Reliably Transmitting (NAT) to 11.111.11.3:27252: NOTIFY sip:1@11.111.11.3:27252 SIP/2.0 Via: SIP/2.0/UDP 22.22.222.184:5160;branch=z9hG4bK25fd7cd8;rport From: "3";tag=as539a8593 To: "";tag=fb2b594c Contact: Call-ID: OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ. CSeq: 102 NOTIFY User-Agent: InnoSIP-app Max-Forwards: 70 Event: refer;id=4 Subscription-state: terminated;reason=noresource Content-Type: message/sipfrag;version=2.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 49 SIP/2.0 481 Call leg/transaction does not exist --- [Mar 5 17:56:52] DEBUG[3212] chan_sip.c: SIP message could not be handled, bad request: OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ. [Mar 5 17:56:52] DEBUG[4146] channel.c: Set channel SIP/3-0a176a78 to write format ulaw [Mar 5 17:56:52] VERBOSE[4146] logger.c: -- Stopped music on hold on SIP/3-0a176a78 [Mar 5 17:56:52] NOTICE[4145] rtp.c: Unknown RTP codec 126 received from '11.111.11.3' [Mar 5 17:56:52] VERBOSE[3212] logger.c: <--- SIP read from 11.111.11.3:27252 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 22.22.222.184:5160;branch=z9hG4bK25fd7cd8;rport=5160 Contact: To: "";tag=fb2b594c From: "3";tag=as539a8593 Call-ID: OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ. CSeq: 102 NOTIFY User-Agent: eyeBeam release 1102q stamp 51814 Content-Length: 0 <-------------> [Mar 5 17:56:52] VERBOSE[3212] logger.c: --- (9 headers 0 lines) --- [Mar 5 17:56:52] DEBUG[3212] chan_sip.c: Stopping retransmission on 'OTNhY2Y1OTc4ZTMyOWI2ZDQ2NDY3MDg0NzNmMjhlZjQ.' of Request 102: Match Found [Mar 5 17:56:52] VERBOSE[3212] logger.c: SIP Response message for INCOMING dialog NOTIFY arrived [Mar 5 17:56:52] DEBUG[3212] chan_sip.c: Got 200 OK on NOTIFY for transfer