//// Call from Asterisk ("dial" CLI command) to extension 200 (Twinkle) //// [Nov 19 01:37:20] DEBUG[21726] pbx.c: Launching 'Set' [Nov 19 01:37:20] DEBUG[21726] pbx.c: Launching 'Dial' [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Asked to create a SIP channel with formats: 0x40 (slin) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Setting NAT on RTP to On [Nov 19 01:37:20] DEBUG[21726] frame.c: Could not find preferred codec - Going for the best codec [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: *** Our native formats are 0x80004 (ulaw|h263) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: *** Joint capabilities are 0x0 (nothing) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: *** Our capabilities are 0x8000e (gsm|ulaw|alaw|h263) [Nov 19 01:37:20] DEBUG[21726] frame.c: Could not find preferred codec - Going for the best codec [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: *** Our preferred formats from the incoming channel are 0x40 (slin) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: This channel will not be able to handle video. [Nov 19 01:37:20] DEBUG[21726] rtp.c: Channel 'OSS/dsp' has no RTP, not doing anything [Nov 19 01:37:20] DEBUG[21726] channel.c: Not copying variable STACK-default-K_200-2. [Nov 19 01:37:20] DEBUG[21726] channel.c: Not copying variable STACK-default-K_200-1. [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Outgoing Call for 200 [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Updating call counter for outgoing call [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Our T38 capability (0), joint T38 capability (0) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: ** Our capability: 0x8000e (gsm|ulaw|alaw|h263) Video flag: False [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: ** Our prefcodec: 0x40 (slin) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: This call needs video offers, but there's no video support enabled! [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: -- Done with adding codecs to SDP [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Done building SDP. Settling with this capability: 0x8000e (gsm|ulaw|alaw|h263) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 0: INVITE sip:200@192.168.0.129 SIP/2.0 (36) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 1: Via: SIP/2.0/UDP 80.95.0.111:5080;branch=z9hG4bK604e158d;rport (62) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 2: From: "Asterisk PBX" ;tag=as19525703 (65) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 3: To: (27) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 4: Contact: (40) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 5: Call-ID: 47bb4741203a4e897bb94cfa6da36dd3@80.95.0.111 (53) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 6: CSeq: 102 INVITE (16) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 8: Max-Forwards: 70 (16) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 9: Date: Mon, 19 Nov 2007 00:37:20 GMT (35) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 11: Supported: replaces (19) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 12: Content-Type: application/sdp (29) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 13: Content-Length: 285 (19) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 14: (0) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: v=0 (3) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: o=root 21694 21694 IN IP4 80.95.0.111 (37) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: s=session (9) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: c=IN IP4 80.95.0.111 (20) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: t=0 0 (5) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: m=audio 10822 RTP/AVP 3 0 8 101 (31) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: a=rtpmap:3 GSM/8000 (19) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: a=fmtp:101 0-16 (15) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: a=silenceSupp:off - - - - (25) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: a=ptime:20 (10) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: a=sendrecv (10) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 0: INVITE sip:200@192.168.0.129 SIP/2.0 (36) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 1: Via: SIP/2.0/UDP 80.95.0.111:5080;branch=z9hG4bK604e158d;rport (62) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 2: From: "Asterisk PBX" ;tag=as19525703 (65) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 3: To: (27) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 4: Contact: (40) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 5: Call-ID: 47bb4741203a4e897bb94cfa6da36dd3@80.95.0.111 (53) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 6: CSeq: 102 INVITE (16) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 8: Max-Forwards: 70 (16) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 9: Date: Mon, 19 Nov 2007 00:37:20 GMT (35) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 11: Supported: replaces (19) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 12: Content-Type: application/sdp (29) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 13: Content-Length: 285 (19) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Header 14: (0) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: v=0 (3) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: o=root 21694 21694 IN IP4 80.95.0.111 (37) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: s=session (9) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: c=IN IP4 80.95.0.111 (20) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: t=0 0 (5) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: m=audio 10822 RTP/AVP 3 0 8 101 (31) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: a=rtpmap:3 GSM/8000 (19) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: a=fmtp:101 0-16 (15) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: a=silenceSupp:off - - - - (25) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: a=ptime:20 (10) [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: Line: a=sendrecv (10) [Nov 19 01:37:20] DEBUG[21726] sched.c: Attempted to delete nonexistent schedule entry 0! [Nov 19 01:37:20] DEBUG[21726] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #23 [Nov 19 01:37:20] DEBUG[21726] channel.c: Set channel SIP/200-081cfac8 to read format slin [Nov 19 01:37:20] DEBUG[21726] channel.c: Set channel OSS/dsp to write format slin [Nov 19 01:37:20] DEBUG[21726] channel.c: Set channel OSS/dsp to read format ulaw [Nov 19 01:37:20] DEBUG[21700] chan_sip.c: Header 0: SIP/2.0 100 Trying (18) [Nov 19 01:37:20] DEBUG[21700] chan_sip.c: Header 1: Via: SIP/2.0/UDP 80.95.0.111:5080;rport=5080;branch=z9hG4bK604e158d (67) [Nov 19 01:37:20] DEBUG[21700] chan_sip.c: Header 2: To: (27) [Nov 19 01:37:20] DEBUG[21700] chan_sip.c: Header 3: From: "Asterisk PBX" ;tag=as19525703 (65) [Nov 19 01:37:20] DEBUG[21700] chan_sip.c: Header 4: Call-ID: 47bb4741203a4e897bb94cfa6da36dd3@80.95.0.111 (53) [Nov 19 01:37:20] DEBUG[21700] chan_sip.c: Header 5: CSeq: 102 INVITE (16) [Nov 19 01:37:20] DEBUG[21700] chan_sip.c: Header 6: Server: Twinkle/1.1 (19) [Nov 19 01:37:20] DEBUG[21700] chan_sip.c: Header 7: Content-Length: 0 (17) [Nov 19 01:37:20] DEBUG[21700] chan_sip.c: *** SIP TIMER: Cancelling retransmission #23 - INVITE (got response) [Nov 19 01:37:20] DEBUG[21700] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '47bb4741203a4e897bb94cfa6da36dd3@80.95.0.111' Request 102: Found [Nov 19 01:37:20] DEBUG[21700] chan_sip.c: SIP response 100 to standard invite [Nov 19 01:37:20] DEBUG[21700] chan_sip.c: Header 0: SIP/2.0 180 Ringing (19) [Nov 19 01:37:20] DEBUG[21700] chan_sip.c: Header 1: Via: SIP/2.0/UDP 80.95.0.111:5080;rport=5080;branch=z9hG4bK604e158d (67) [Nov 19 01:37:20] DEBUG[21700] chan_sip.c: Header 2: To: ;tag=mqzbe (37) [Nov 19 01:37:20] DEBUG[21700] chan_sip.c: Header 3: From: "Asterisk PBX" ;tag=as19525703 (65) [Nov 19 01:37:20] DEBUG[21700] chan_sip.c: Header 4: Call-ID: 47bb4741203a4e897bb94cfa6da36dd3@80.95.0.111 (53) [Nov 19 01:37:20] DEBUG[21700] chan_sip.c: Header 5: CSeq: 102 INVITE (16) [Nov 19 01:37:20] DEBUG[21700] chan_sip.c: Header 6: Server: Twinkle/1.1 (19) [Nov 19 01:37:20] DEBUG[21700] chan_sip.c: Header 7: Content-Length: 0 (17) [Nov 19 01:37:20] DEBUG[21700] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '47bb4741203a4e897bb94cfa6da36dd3@80.95.0.111' Request 102: Found [Nov 19 01:37:20] DEBUG[21700] chan_sip.c: SIP response 180 to standard invite [Nov 19 01:37:20] DEBUG[21700] devicestate.c: Notification of state change to be queued on device/channel SIP/200-081cfac8 [Nov 19 01:37:20] DEBUG[21726] rtp.c: Channel 'OSS/dsp' has no RTP, not doing anything [Nov 19 01:37:20] DEBUG[21697] devicestate.c: No provider found, checking channel drivers for SIP - 200 [Nov 19 01:37:20] DEBUG[21697] chan_sip.c: Checking device state for peer 200 [Nov 19 01:37:20] DEBUG[21697] devicestate.c: Changing state for SIP/200 - state 1 (Not in use) [Nov 19 01:37:20] DEBUG[21727] app_queue.c: Device 'SIP/200' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Header 0: SIP/2.0 200 OK (14) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Header 1: Via: SIP/2.0/UDP 80.95.0.111:5080;rport=5080;branch=z9hG4bK604e158d (67) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Header 2: To: ;tag=mqzbe (37) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Header 3: From: "Asterisk PBX" ;tag=as19525703 (65) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Header 4: Call-ID: 47bb4741203a4e897bb94cfa6da36dd3@80.95.0.111 (53) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Header 5: CSeq: 102 INVITE (16) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Header 6: Contact: (32) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Header 7: Content-Type: application/sdp (29) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Header 8: Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,PRACK,REFER,NOTIFY,SUBSCRIBE,INFO,MESSAGE (78) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Header 9: Server: Twinkle/1.1 (19) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Header 10: Supported: replaces,norefersub (30) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Header 11: Content-Length: 191 (19) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Header 12: (0) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Line: v=0 (3) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Line: o=200 437072400 1452368222 IN IP4 192.168.0.129 (47) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Line: s=- (3) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Line: c=IN IP4 192.168.0.129 (22) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Line: t=0 0 (5) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Line: m=audio 8000 RTP/AVP 3 101 (26) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Line: a=rtpmap:3 GSM/8000 (19) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Acked pending invite 102 [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Stopping retransmission on '47bb4741203a4e897bb94cfa6da36dd3@80.95.0.111' of Request 102: Match Not Found [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: SIP response 200 to standard invite [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: T38 state changed to 0 on channel SIP/200-081cfac8 [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: We're settling with these formats: 0x2 (gsm) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: We have an owner, now see if we need to change this call [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Oooh, we need to change our audio formats since our peer supports only 0x2 (gsm) and not 0x80004 (ulaw|h263) [Nov 19 01:37:30] DEBUG[21700] frame.c: Could not find preferred codec - Going for the best codec [Nov 19 01:37:30] DEBUG[21700] channel.c: Set channel SIP/200-081cfac8 to read format slin [Nov 19 01:37:30] DEBUG[21700] channel.c: Set channel SIP/200-081cfac8 to write format ulaw [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Updating call counter for outgoing call [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: build_route: Contact hop: [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Strict routing enforced for session 47bb4741203a4e897bb94cfa6da36dd3@80.95.0.111 [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Header 0: ACK sip:200@192.168.0.129 SIP/2.0 (33) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Header 1: Via: SIP/2.0/UDP 80.95.0.111:5080;branch=z9hG4bK7803eb37;rport (62) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Header 2: From: "Asterisk PBX" ;tag=as19525703 (65) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Header 3: To: ;tag=mqzbe (37) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Header 4: Contact: (40) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Header 5: Call-ID: 47bb4741203a4e897bb94cfa6da36dd3@80.95.0.111 (53) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Header 6: CSeq: 102 ACK (13) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Header 8: Max-Forwards: 70 (16) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Header 9: Content-Length: 0 (17) [Nov 19 01:37:30] DEBUG[21700] chan_sip.c: Header 10: (0) [Nov 19 01:37:30] DEBUG[21726] devicestate.c: Notification of state change to be queued on device/channel SIP/200-081cfac8 [Nov 19 01:37:30] DEBUG[21726] rtp.c: Channel 'OSS/dsp' has no RTP, not doing anything [Nov 19 01:37:30] DEBUG[21697] devicestate.c: No provider found, checking channel drivers for SIP - 200 [Nov 19 01:37:30] DEBUG[21697] chan_sip.c: Checking device state for peer 200 [Nov 19 01:37:30] DEBUG[21697] devicestate.c: Changing state for SIP/200 - state 1 (Not in use) [Nov 19 01:37:30] DEBUG[21730] app_queue.c: Device 'SIP/200' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Nov 19 01:37:30] DEBUG[21726] channel.c: Set channel SIP/200-081cfac8 to write format alaw [Nov 19 01:37:30] DEBUG[21726] rtp.c: Ooh, format changed from unknown to gsm [Nov 19 01:37:30] DEBUG[21726] rtp.c: Created smoother: format: 2 ms: 20 len: 33 [Nov 19 01:37:30] DEBUG[21726] rtp.c: RTCP NAT: Got RTCP from other end. Now sending to address 85.58.131.104:52206 [Nov 19 01:37:30] DEBUG[21726] rtp.c: Got RTCP report of 40 bytes [Nov 19 01:37:30] DEBUG[21726] rtp.c: RTP NAT: Got audio from other end. Now sending to address 85.58.131.104:52207 [Nov 19 01:37:34] DEBUG[21726] rtp.c: RTCP NAT: Got RTCP from other end. Now sending to address 85.58.131.104:52206 [Nov 19 01:37:34] DEBUG[21726] rtp.c: Got RTCP report of 84 bytes //// Here the UAC 200 (Twinkle) sends an in-dialog OPTIONS to Asterisk "Contact" URI (sip:asterisk@80.95.0.111:5080) but Asterisk replies with 404 //// //// IMHO Asterisk replies a 404 because "asterisk" isnot a valid extension, but it should reply 200 OK since the dialog exists //// [Nov 19 01:37:35] DEBUG[21700] chan_sip.c: Header 0: OPTIONS sip:asterisk@80.95.0.111:5080 SIP/2.0 (45) [Nov 19 01:37:35] DEBUG[21700] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.129;rport;branch=z9hG4bKbespsvyq (59) [Nov 19 01:37:35] DEBUG[21700] chan_sip.c: Header 2: Max-Forwards: 70 (16) [Nov 19 01:37:35] DEBUG[21700] chan_sip.c: Header 3: To: "Asterisk PBX" ;tag=as19525703 (63) [Nov 19 01:37:35] DEBUG[21700] chan_sip.c: Header 4: From: ;tag=mqzbe (39) [Nov 19 01:37:35] DEBUG[21700] chan_sip.c: Header 5: Call-ID: 47bb4741203a4e897bb94cfa6da36dd3@80.95.0.111 (53) [Nov 19 01:37:35] DEBUG[21700] chan_sip.c: Header 6: CSeq: 441 OPTIONS (17) [Nov 19 01:37:35] DEBUG[21700] chan_sip.c: Header 7: Accept: application/sdp (23) [Nov 19 01:37:35] DEBUG[21700] chan_sip.c: Header 8: User-Agent: Twinkle/1.1 (23) [Nov 19 01:37:35] DEBUG[21700] chan_sip.c: Header 9: Content-Length: 0 (17) [Nov 19 01:37:35] DEBUG[21700] chan_sip.c: **** Received OPTIONS (3) - Command in SIP OPTIONS [Nov 19 01:37:35] DEBUG[21700] chan_sip.c: Header 0: SIP/2.0 404 Not Found (21) [Nov 19 01:37:35] DEBUG[21700] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.129;branch=z9hG4bKbespsvyq;received=85.58.131.104;rport=52202 (88) [Nov 19 01:37:35] DEBUG[21700] chan_sip.c: Header 2: From: ;tag=mqzbe (39) [Nov 19 01:37:35] DEBUG[21700] chan_sip.c: Header 3: To: "Asterisk PBX" ;tag=as19525703 (63) [Nov 19 01:37:35] DEBUG[21700] chan_sip.c: Header 4: Call-ID: 47bb4741203a4e897bb94cfa6da36dd3@80.95.0.111 (53) [Nov 19 01:37:35] DEBUG[21700] chan_sip.c: Header 5: CSeq: 441 OPTIONS (17) [Nov 19 01:37:35] DEBUG[21700] chan_sip.c: Header 6: User-Agent: Asterisk PBX (24) [Nov 19 01:37:35] DEBUG[21700] chan_sip.c: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Nov 19 01:37:35] DEBUG[21700] chan_sip.c: Header 8: Supported: replaces (19) [Nov 19 01:37:35] DEBUG[21700] chan_sip.c: Header 9: Accept: application/sdp (23) [Nov 19 01:37:35] DEBUG[21700] chan_sip.c: Header 10: Content-Length: 0 (17) [Nov 19 01:37:35] DEBUG[21700] chan_sip.c: Header 11: (0) [Nov 19 01:37:35] DEBUG[21700] chan_sip.c: SIP message could not be handled, bad request: 47bb4741203a4e897bb94cfa6da36dd3@80.95.0.111 [Nov 19 01:37:37] DEBUG[21726] channel.c: Set channel SIP/200-081cfac8 to write format ulaw [Nov 19 01:37:37] DEBUG[21726] devicestate.c: Notification of state change to be queued on device/channel OSS/dsp [Nov 19 01:37:37] DEBUG[21697] devicestate.c: No provider found, checking channel drivers for OSS - dsp [Nov 19 01:37:37] DEBUG[21697] devicestate.c: Changing state for OSS/dsp - state 4 (Invalid) [Nov 19 01:37:37] DEBUG[21731] app_queue.c: Device 'OSS/dsp' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Nov 19 01:37:41] DEBUG[21726] rtp.c: Got RTCP report of 84 bytes [Nov 19 01:37:44] DEBUG[21726] rtp.c: Got RTCP report of 84 bytes //// Asterisk hangups //// [Nov 19 01:37:50] DEBUG[21717] channel.c: Soft-Hanging up channel 'SIP/200-081cfac8' [Nov 19 01:37:50] DEBUG[21717] channel.c: Soft-Hanging up channel 'OSS/dsp' [Nov 19 01:37:50] DEBUG[21726] channel.c: Didn't get a frame from channel: SIP/200-081cfac8 [Nov 19 01:37:50] DEBUG[21726] channel.c: Bridge stops bridging channels OSS/dsp and SIP/200-081cfac8 [Nov 19 01:37:50] DEBUG[21726] channel.c: Hanging up channel 'SIP/200-081cfac8' [Nov 19 01:37:50] DEBUG[21726] chan_sip.c: Hangup call SIP/200-081cfac8, SIP callid 47bb4741203a4e897bb94cfa6da36dd3@80.95.0.111) [Nov 19 01:37:50] DEBUG[21726] chan_sip.c: Strict routing enforced for session 47bb4741203a4e897bb94cfa6da36dd3@80.95.0.111 [Nov 19 01:37:50] DEBUG[21726] chan_sip.c: Header 0: BYE sip:200@192.168.0.129 SIP/2.0 (33) [Nov 19 01:37:50] DEBUG[21726] chan_sip.c: Header 1: Via: SIP/2.0/UDP 80.95.0.111:5080;branch=z9hG4bK0c067ef9;rport (62) [Nov 19 01:37:50] DEBUG[21726] chan_sip.c: Header 2: From: "Asterisk PBX" ;tag=as19525703 (65) [Nov 19 01:37:50] DEBUG[21726] chan_sip.c: Header 3: To: ;tag=mqzbe (37) [Nov 19 01:37:50] DEBUG[21726] chan_sip.c: Header 4: Call-ID: 47bb4741203a4e897bb94cfa6da36dd3@80.95.0.111 (53) [Nov 19 01:37:50] DEBUG[21726] chan_sip.c: Header 5: CSeq: 103 BYE (13) [Nov 19 01:37:50] DEBUG[21726] chan_sip.c: Header 6: User-Agent: Asterisk PBX (24) [Nov 19 01:37:50] DEBUG[21726] chan_sip.c: Header 7: Max-Forwards: 70 (16) [Nov 19 01:37:50] DEBUG[21726] chan_sip.c: Header 8: Content-Length: 0 (17) [Nov 19 01:37:50] DEBUG[21726] chan_sip.c: Header 9: (0) [Nov 19 01:37:50] DEBUG[21726] sched.c: Attempted to delete nonexistent schedule entry 0! [Nov 19 01:37:50] DEBUG[21726] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #27 [Nov 19 01:37:50] DEBUG[21726] devicestate.c: Notification of state change to be queued on device/channel SIP/200-081cfac8 [Nov 19 01:37:50] DEBUG[21726] rtp.c: Channel 'OSS/dsp' has no RTP, not doing anything [Nov 19 01:37:50] DEBUG[21726] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Nov 19 01:37:50] DEBUG[21726] pbx.c: Spawn extension (default,K_200,2) exited non-zero on 'OSS/dsp' [Nov 19 01:37:50] DEBUG[21726] channel.c: Soft-Hanging up channel 'OSS/dsp' [Nov 19 01:37:50] DEBUG[21726] channel.c: Hanging up channel 'OSS/dsp' [Nov 19 01:37:50] DEBUG[21726] devicestate.c: Notification of state change to be queued on device/channel OSS/dsp [Nov 19 01:37:50] DEBUG[21697] devicestate.c: No provider found, checking channel drivers for SIP - 200 [Nov 19 01:37:50] DEBUG[21697] chan_sip.c: Checking device state for peer 200 [Nov 19 01:37:50] DEBUG[21697] devicestate.c: Changing state for SIP/200 - state 1 (Not in use) [Nov 19 01:37:50] DEBUG[21697] devicestate.c: No provider found, checking channel drivers for OSS - dsp [Nov 19 01:37:50] DEBUG[21697] devicestate.c: Changing state for OSS/dsp - state 4 (Invalid) [Nov 19 01:37:50] DEBUG[21732] app_queue.c: Device 'SIP/200' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Nov 19 01:37:50] DEBUG[21733] app_queue.c: Device 'OSS/dsp' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: Header 0: SIP/2.0 200 OK (14) [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: Header 1: Via: SIP/2.0/UDP 80.95.0.111:5080;rport=5080;branch=z9hG4bK0c067ef9 (67) [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: Header 2: To: ;tag=mqzbe (37) [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: Header 3: From: "Asterisk PBX" ;tag=as19525703 (65) [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: Header 4: Call-ID: 47bb4741203a4e897bb94cfa6da36dd3@80.95.0.111 (53) [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: Header 5: CSeq: 103 BYE (13) [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: Header 6: Server: Twinkle/1.1 (19) [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: Header 7: Content-Length: 0 (17) [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #27 [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: Stopping retransmission on '47bb4741203a4e897bb94cfa6da36dd3@80.95.0.111' of Request 103: Match Not Found [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: ---------- SIP HISTORY for '47bb4741203a4e897bb94cfa6da36dd3@80.95.0.111' [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: * SIP Call [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: 001. NewChan Channel SIP/200-081cfac8 - from 47bb4741203a4e897bb94cfa6da36dd [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: 002. TxReqRel INVITE / 102 INVITE - -UNKNOWN- [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: 003. Rx SIP/2.0 / 102 INVITE / 100 Trying [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: 004. Rx SIP/2.0 / 102 INVITE / 180 Ringing [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: 005. Rx SIP/2.0 / 102 INVITE / 200 OK [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: 006. TxReq ACK / 102 ACK - -UNKNOWN- [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: 007. Rx OPTIONS / 441 OPTIONS / sip:asterisk@80.95.0.111:5080 [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: 008. TxResp SIP/2.0 / 441 OPTIONS - 404 Not Found [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: 009. Hangup Cause Normal Clearing [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: 010. SchedDestroy 6400 ms [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: 011. TxReqRel BYE / 103 BYE - -UNKNOWN- [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: 012. RTCPaudio Quality:ssrc=2140569929;themssrc=2308755392;lp=0;rxjitter=0.006 [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: 013. Rx SIP/2.0 / 103 BYE / 200 OK [Nov 19 01:37:50] DEBUG[21700] chan_sip.c: ---------- END SIP HISTORY for '47bb4741203a4e897bb94cfa6da36dd3@80.95.0.111'