[Nov 6 22:17:15] VERBOSE[24920] logger.c: -- Remote UNIX connection [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 0: INVITE sip:00827863878@192.168.16.7 SIP/2.0 (43) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.16.69:34741;branch=z9hG4bK-d8754z-c5363d1285720e00-1---d8754z-;rport (93) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 2: Max-Forwards: 70 (16) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 3: Contact: (38) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 4: To: "00827863878" (47) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 5: From: "Shane Home";tag=7d33ba3a (54) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 6: Call-ID: Mjg0OTJlMjY2ODhmMzg0ZmJiYWNiMzY2MmZlNDU0MmM. (53) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 7: CSeq: 1 INVITE (14) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 8: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO (81) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 9: Content-Type: application/sdp (29) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 10: User-Agent: X-Lite release 1104o stamp 56125 (44) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 11: Content-Length: 317 (19) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 12: (0) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Line: v=0 (3) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Line: o=- 2 2 IN IP4 192.168.16.69 (28) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Line: s=CounterPath X-Lite 3.0 (24) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Line: c=IN IP4 192.168.16.69 (22) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Line: t=0 0 (5) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Line: m=audio 62602 RTP/AVP 107 0 8 101 (33) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Line: a=alt:1 2 : 0OGRHPg/ gqzym09C 192.168.69.6 62602 (48) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Line: a=alt:2 1 : IdapiZH5 fhdkwbYU 192.168.16.69 62602 (49) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Line: a=fmtp:101 0-15 (15) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Line: a=rtpmap:107 BV32/16000 (23) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Line: a=sendrecv (10) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: = No match Their Call ID: NDYzMWFkMzZkZjRkZDUzZTlkNzE1ZDIyNDJhMTRlZjg. Their Tag fe61806b Our tag: as6307592e [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Setting NAT on RTP to Off [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Allocating new SIP dialog for Mjg0OTJlMjY2ODhmMzg0ZmJiYWNiMzY2MmZlNDU0MmM. - INVITE (With RTP) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Setting NAT on RTP to On [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #-1 [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 0: ACK sip:00827863878@192.168.16.7 SIP/2.0 (40) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.16.69:34741;branch=z9hG4bK-d8754z-c5363d1285720e00-1---d8754z-;rport (93) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 2: To: "00827863878";tag=as511da78f (62) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 3: From: "Shane Home";tag=7d33ba3a (54) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 4: Call-ID: Mjg0OTJlMjY2ODhmMzg0ZmJiYWNiMzY2MmZlNDU0MmM. (53) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 5: CSeq: 1 ACK (11) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 6: Content-Length: 0 (17) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 7: (0) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: = Found Their Call ID: Mjg0OTJlMjY2ODhmMzg0ZmJiYWNiMzY2MmZlNDU0MmM. Their Tag 7d33ba3a Our tag: as511da78f [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #30 [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Stopping retransmission on 'Mjg0OTJlMjY2ODhmMzg0ZmJiYWNiMzY2MmZlNDU0MmM.' of Response 1: Match Found [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 0: INVITE sip:00827863878@192.168.16.7 SIP/2.0 (43) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.16.69:34741;branch=z9hG4bK-d8754z-183bdb620a1f9e11-1---d8754z-;rport (93) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 2: Max-Forwards: 70 (16) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 3: Contact: (38) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 4: To: "00827863878" (47) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 5: From: "Shane Home";tag=7d33ba3a (54) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 6: Call-ID: Mjg0OTJlMjY2ODhmMzg0ZmJiYWNiMzY2MmZlNDU0MmM. (53) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 7: CSeq: 2 INVITE (14) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 8: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO (81) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 9: Content-Type: application/sdp (29) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 10: Proxy-Authorization: Digest username="9169",realm="alexmay.co.za",nonce="57bbff65",uri="sip:00827863878@192.168.16.7",response="db2da1de6a3dd266680c40ef356f25ff",algorithm=MD5 (175) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 11: User-Agent: X-Lite release 1104o stamp 56125 (44) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 12: Content-Length: 317 (19) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 13: (0) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Line: v=0 (3) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Line: o=- 2 2 IN IP4 192.168.16.69 (28) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Line: s=CounterPath X-Lite 3.0 (24) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Line: c=IN IP4 192.168.16.69 (22) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Line: t=0 0 (5) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Line: m=audio 62602 RTP/AVP 107 0 8 101 (33) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Line: a=alt:1 2 : 0OGRHPg/ gqzym09C 192.168.69.6 62602 (48) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Line: a=alt:2 1 : IdapiZH5 fhdkwbYU 192.168.16.69 62602 (49) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Line: a=fmtp:101 0-15 (15) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Line: a=rtpmap:107 BV32/16000 (23) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Line: a=sendrecv (10) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: = Found Their Call ID: Mjg0OTJlMjY2ODhmMzg0ZmJiYWNiMzY2MmZlNDU0MmM. Their Tag 7d33ba3a Our tag: as511da78f [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Setting NAT on RTP to On [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Processing session-level SDP o=- 2 2 IN IP4 192.168.16.69... UNSUPPORTED. [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Processing session-level SDP s=CounterPath X-Lite 3.0... UNSUPPORTED. [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.16.69... OK. [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Processing media-level (audio) SDP a=alt:1 2 : 0OGRHPg/ gqzym09C 192.168.69.6 62602... UNSUPPORTED. [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Processing media-level (audio) SDP a=alt:2 1 : IdapiZH5 fhdkwbYU 192.168.16.69 62602... UNSUPPORTED. [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED. [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:107 BV32/16000... UNSUPPORTED. [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: T38 state changed to 0 on channel [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: We're settling with these formats: 0xc (ulaw|alaw) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Checking SIP call limits for device 9169 [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Updating call counter for incoming call [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: *** Joint capabilities are 0xc (ulaw|alaw) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: *** Our capabilities are 0xe (gsm|ulaw|alaw) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: This channel will not be able to handle video. [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: build_route: Contact hop: [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: SIP/9169-00000002: New call is still down.... Trying... [Nov 6 22:18:05] DEBUG[24929] devicestate.c: Notification of state change to be queued on device/channel SIP/9169 [Nov 6 22:18:05] DEBUG[24923] devicestate.c: No provider found, checking channel drivers for SIP - 9169 [Nov 6 22:18:05] DEBUG[24923] chan_sip.c: Checking device state for peer 9169 [Nov 6 22:18:05] DEBUG[24923] devicestate.c: Changing state for SIP/9169 - state 1 (Not in use) [Nov 6 22:18:05] DEBUG[24988] pbx.c: Launching 'Answer' [Nov 6 22:18:05] DEBUG[24927] app_queue.c: Device 'SIP/9169' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Nov 6 22:18:05] VERBOSE[24988] logger.c: -- Executing [00827863878@from-internal:1] Answer("SIP/9169-00000002", "") in new stack [Nov 6 22:18:05] DEBUG[24988] devicestate.c: Notification of state change to be queued on device/channel SIP/9169 [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: SIP answering channel: SIP/9169-00000002 [Nov 6 22:18:05] DEBUG[24923] devicestate.c: No provider found, checking channel drivers for SIP - 9169 [Nov 6 22:18:05] DEBUG[24988] rtp.c: Setting the marker bit due to a source update [Nov 6 22:18:05] DEBUG[24923] chan_sip.c: Checking device state for peer 9169 [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: Setting framing from config on incoming call [Nov 6 22:18:05] DEBUG[24923] devicestate.c: Changing state for SIP/9169 - state 1 (Not in use) [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: True [Nov 6 22:18:05] DEBUG[24927] app_queue.c: Device 'SIP/9169' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: -- Done with adding codecs to SDP [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #-1 [Nov 6 22:18:05] DEBUG[24988] pbx.c: Launching 'Dial' [Nov 6 22:18:05] VERBOSE[24988] logger.c: -- Executing [00827863878@from-internal:2] Dial("SIP/9169-00000002", "SIP/quintum-out/0827863878") in new stack [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw) [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: Setting NAT on RTP to Off [Nov 6 22:18:05] DEBUG[24988] frame.c: Could not find preferred codec - Going for the best codec [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: *** Our native formats are 0x80004 (ulaw|h263) [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: *** Joint capabilities are 0x0 (nothing) [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: *** Our capabilities are 0x8000e (gsm|ulaw|alaw|h263) [Nov 6 22:18:05] DEBUG[24988] frame.c: Could not find preferred codec - Going for the best codec [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: This channel will not be able to handle video. [Nov 6 22:18:05] DEBUG[24988] rtp.c: Seeded SDP of 'SIP/quintum-out-00000003' with that of 'SIP/9169-00000002' [Nov 6 22:18:05] DEBUG[24988] channel.c: Not copying variable DIALEDTIME. [Nov 6 22:18:05] DEBUG[24988] channel.c: Not copying variable ANSWEREDTIME. [Nov 6 22:18:05] DEBUG[24988] channel.c: Not copying variable DIALEDPEERNAME. [Nov 6 22:18:05] DEBUG[24988] channel.c: Not copying variable DIALEDPEERNUMBER. [Nov 6 22:18:05] DEBUG[24988] channel.c: Not copying variable DIALSTATUS. [Nov 6 22:18:05] DEBUG[24988] channel.c: Not copying variable SIPCALLID. [Nov 6 22:18:05] DEBUG[24988] channel.c: Not copying variable SIPUSERAGENT. [Nov 6 22:18:05] DEBUG[24988] channel.c: Not copying variable SIPDOMAIN. [Nov 6 22:18:05] DEBUG[24988] channel.c: Not copying variable SIPURI. [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: Outgoing Call for 0827863878 [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: Updating call counter for outgoing call [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: Our T38 capability (0), joint T38 capability (0) [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: ** Our capability: 0x8000e (gsm|ulaw|alaw|h263) Video flag: False [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: This call needs video offers, but there's no video support enabled! [Nov 6 22:18:05] VERBOSE[24988] logger.c: Audio is at 192.168.16.7 port 17556 [Nov 6 22:18:05] VERBOSE[24988] logger.c: Adding codec 0x4 (ulaw) to SDP [Nov 6 22:18:05] VERBOSE[24988] logger.c: Adding codec 0x2 (gsm) to SDP [Nov 6 22:18:05] VERBOSE[24988] logger.c: Adding codec 0x8 (alaw) to SDP [Nov 6 22:18:05] VERBOSE[24988] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: -- Done with adding codecs to SDP [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: Done building SDP. Settling with this capability: 0x8000e (gsm|ulaw|alaw|h263) [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: Header 0: INVITE sip:0827863878@192.168.16.8 SIP/2.0 (42) [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: Header 1: v: SIP/2.0/UDP 192.168.16.7:5060;branch=z9hG4bK1c3357a4;rport (61) [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: Header 2: f: "Shane James" ;tag=as26157ebf (55) [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: Header 3: t: (32) [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: Header 4: m: (26) [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: Header 5: i: 6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7 (48) [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: Header 6: CSeq: 102 INVITE (16) [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: Header 8: Max-Forwards: 70 (16) [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: Header 9: Date: Sat, 06 Nov 2010 20:18:05 GMT (35) [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO (72) [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: Header 11: k: replaces (11) [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: Header 12: c: application/sdp (18) [Nov 6 22:18:05] VERBOSE[24988] logger.c: Reliably Transmitting (no NAT) to 192.168.16.8:5060: INVITE sip:0827863878@192.168.16.8 SIP/2.0 v: SIP/2.0/UDP 192.168.16.7:5060;branch=z9hG4bK1c3357a4;rport f: "Shane James" ;tag=as26157ebf t: m: i: 6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Sat, 06 Nov 2010 20:18:05 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO k: replaces c: application/sdp l: 260 v=0 o=root 14665 14665 IN IP4 192.168.16.7 s=session c=IN IP4 192.168.16.7 t=0 0 m=audio 17556 RTP/AVP 0 3 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv --- [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #-1 [Nov 6 22:18:05] VERBOSE[24988] logger.c: -- Called quintum-out/0827863878 [Nov 6 22:18:05] VERBOSE[24929] logger.c: <--- SIP read from 192.168.16.8:5060 ---> SIP/2.0 100 Trying Call-ID: 6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7 Content-Length: 0 CSeq: 102 INVITE From: "Shane James";tag=as26157ebf To: ;tag=c0a81008-3b User-Agent: Quintum/1.0.0 SN/0030E1021145 SW/P108-09-04 Via: SIP/2.0/UDP 192.168.16.7:5060;branch=z9hG4bK1c3357a4;rport Quintum: 0b03313933 <-------------> [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 0: SIP/2.0 100 Trying (18) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 1: Call-ID: 6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7 (54) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 2: Content-Length: 0 (17) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 3: CSeq: 102 INVITE (16) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 4: From: "Shane James";tag=as26157ebf (57) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 5: To: ;tag=c0a81008-3b (49) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 6: User-Agent: Quintum/1.0.0 SN/0030E1021145 SW/P108-09-04 (55) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 7: Via: SIP/2.0/UDP 192.168.16.7:5060;branch=z9hG4bK1c3357a4;rport (63) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 8: Quintum: 0b03313933 (19) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 9: (0) [Nov 6 22:18:05] VERBOSE[24929] logger.c: --- (9 headers 0 lines) --- [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: = Found Their Call ID: 6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7 Their Tag Our tag: as26157ebf [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: *** SIP TIMER: Cancelling retransmission #34 - INVITE (got response) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7' Request 102: Found [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: SIP response 100 to standard invite [Nov 6 22:18:05] DEBUG[24988] rtp.c: Got RTCP report of 24 bytes [Nov 6 22:18:05] DEBUG[24988] rtp.c: RTCP NAT: Got RTCP from other end. Now sending to address 192.168.16.1:62603 [Nov 6 22:18:05] DEBUG[24988] rtp.c: Got RTCP report of 132 bytes [Nov 6 22:18:05] DEBUG[24988] rtp.c: RTP NAT: Got audio from other end. Now sending to address 192.168.16.1:62602 [Nov 6 22:18:05] DEBUG[24988] chan_sip.c: Oooh, format changed to 8 [Nov 6 22:18:05] DEBUG[24988] channel.c: Set channel SIP/quintum-out-00000003 to read format ulaw [Nov 6 22:18:05] DEBUG[24988] channel.c: Set channel SIP/quintum-out-00000003 to write format ulaw [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 0: ACK sip:00827863878@192.168.16.7 SIP/2.0 (40) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.16.69:34741;branch=z9hG4bK-d8754z-b6039b4a4669f222-1---d8754z-;rport (93) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 2: Max-Forwards: 70 (16) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 3: Contact: (38) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 4: To: "00827863878";tag=as4f1a072c (62) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 5: From: "Shane Home";tag=7d33ba3a (54) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 6: Call-ID: Mjg0OTJlMjY2ODhmMzg0ZmJiYWNiMzY2MmZlNDU0MmM. (53) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 7: CSeq: 2 ACK (11) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 8: Proxy-Authorization: Digest username="9169",realm="alexmay.co.za",nonce="57bbff65",uri="sip:00827863878@192.168.16.7",response="db2da1de6a3dd266680c40ef356f25ff",algorithm=MD5 (175) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 9: User-Agent: X-Lite release 1104o stamp 56125 (44) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 10: Content-Length: 0 (17) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Header 11: (0) [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: = No match Their Call ID: 6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7 Their Tag c0a81008-3b Our tag: as26157ebf [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: = Found Their Call ID: Mjg0OTJlMjY2ODhmMzg0ZmJiYWNiMzY2MmZlNDU0MmM. Their Tag 7d33ba3a Our tag: as4f1a072c [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #33 [Nov 6 22:18:05] DEBUG[24929] chan_sip.c: Stopping retransmission on 'Mjg0OTJlMjY2ODhmMzg0ZmJiYWNiMzY2MmZlNDU0MmM.' of Response 2: Match Found [Nov 6 22:18:06] NOTICE[24988] rtp.c: Comfort noise support incomplete in Asterisk (RFC 3389). Please turn off on client if possible. Client IP: 0.0.0.0 [Nov 6 22:18:06] DEBUG[24988] rtp.c: Got RTCP report of 44 bytes [Nov 6 22:18:08] DEBUG[24929] chan_sip.c: Header 0: (0) [Nov 6 22:18:08] DEBUG[24929] chan_sip.c: Line: (0) [Nov 6 22:18:08] DEBUG[24988] rtp.c: Got RTCP report of 44 bytes [Nov 6 22:18:08] DEBUG[24988] rtp.c: Got RTCP report of 152 bytes [Nov 6 22:18:09] DEBUG[24988] rtp.c: Got RTCP report of 44 bytes [Nov 6 22:18:09] VERBOSE[24929] logger.c: <--- SIP read from 192.168.16.8:5060 ---> SIP/2.0 180 Ringing Call-ID: 6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7 Contact: Content-Length: 224 Content-Type: application/sdp CSeq: 102 INVITE From: "Shane James";tag=as26157ebf To: ;tag=c0a81008-3b User-Agent: Quintum/1.0.0 SN/0030E1021145 SW/P108-09-04 Via: SIP/2.0/UDP 192.168.16.7:5060;branch=z9hG4bK1c3357a4;rport v=0 o=Quintum 45 14665 IN IP4 192.168.16.8 s=VoipCall c=IN IP4 192.168.16.8 t=0 0 m=audio 10324 RTP/AVP 8 101 c=IN IP4 192.168.16.8 a=rtpmap:8 PCMA/8000/1 a=ptime:20 a=rtpmap:101 telephone-event/8000/1 a=sendrecv <-------------> [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Header 0: SIP/2.0 180 Ringing (19) [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Header 1: Call-ID: 6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7 (54) [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Header 2: Contact: (38) [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Header 3: Content-Length: 224 (19) [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Header 4: Content-Type: application/sdp (29) [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Header 5: CSeq: 102 INVITE (16) [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Header 6: From: "Shane James";tag=as26157ebf (57) [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Header 7: To: ;tag=c0a81008-3b (49) [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Header 8: User-Agent: Quintum/1.0.0 SN/0030E1021145 SW/P108-09-04 (55) [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Header 9: Via: SIP/2.0/UDP 192.168.16.7:5060;branch=z9hG4bK1c3357a4;rport (63) [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Header 10: (0) [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Line: v=0 (3) [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Line: o=Quintum 45 14665 IN IP4 192.168.16.8 (38) [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Line: s=VoipCall (10) [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Line: c=IN IP4 192.168.16.8 (21) [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Line: t=0 0 (5) [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Line: m=audio 10324 RTP/AVP 8 101 (27) [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Line: c=IN IP4 192.168.16.8 (21) [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Line: a=rtpmap:8 PCMA/8000/1 (22) [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Line: a=ptime:20 (10) [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000/1 (35) [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Line: a=sendrecv (10) [Nov 6 22:18:09] VERBOSE[24929] logger.c: --- (10 headers 11 lines) --- [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: = Found Their Call ID: 6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7 Their Tag c0a81008-3b Our tag: as26157ebf [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7' Request 102: Found [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: SIP response 180 to standard invite [Nov 6 22:18:09] DEBUG[24929] devicestate.c: Notification of state change to be queued on device/channel SIP/quintum-out [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Processing session-level SDP o=Quintum 45 14665 IN IP4 192.168.16.8... UNSUPPORTED. [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Processing session-level SDP s=VoipCall... UNSUPPORTED. [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.16.8... OK. [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Nov 6 22:18:09] VERBOSE[24929] logger.c: Found RTP audio format 8 [Nov 6 22:18:09] VERBOSE[24929] logger.c: Found RTP audio format 101 [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Processing media-level (audio) SDP c=IN IP4 192.168.16.8... OK. [Nov 6 22:18:09] VERBOSE[24929] logger.c: Found audio description format PCMA for ID 8 [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000/1... OK. [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Nov 6 22:18:09] VERBOSE[24929] logger.c: Found audio description format telephone-event for ID 101 [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000/1... OK. [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: T38 state changed to 0 on channel SIP/quintum-out-00000003 [Nov 6 22:18:09] VERBOSE[24929] logger.c: Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) [Nov 6 22:18:09] VERBOSE[24929] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: Our T38 capability = (0), peer T38 capability (0), joint T38 capability (0) [Nov 6 22:18:09] VERBOSE[24929] logger.c: Peer audio RTP is at port 192.168.16.8:10324 [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: We're settling with these formats: 0x8 (alaw) [Nov 6 22:18:09] DEBUG[24929] chan_sip.c: We have an owner, now see if we need to change this call [Nov 6 22:18:09] DEBUG[24923] devicestate.c: No provider found, checking channel drivers for SIP - quintum-out [Nov 6 22:18:09] DEBUG[24923] chan_sip.c: Checking device state for peer quintum-out [Nov 6 22:18:09] DEBUG[24923] devicestate.c: Changing state for SIP/quintum-out - state 1 (Not in use) [Nov 6 22:18:09] DEBUG[24927] app_queue.c: Device 'SIP/quintum-out' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Nov 6 22:18:09] VERBOSE[24988] logger.c: -- SIP/quintum-out-00000003 is ringing [Nov 6 22:18:09] DEBUG[24988] channel.c: Driver for channel 'SIP/9169-00000002' does not support indication 3, emulating it [Nov 6 22:18:09] DEBUG[24988] channel.c: Set channel SIP/9169-00000002 to write format slin [Nov 6 22:18:09] DEBUG[24988] channel.c: Scheduling timer at 160 sample intervals [Nov 6 22:18:09] VERBOSE[24988] logger.c: -- SIP/quintum-out-00000003 is making progress passing it to SIP/9169-00000002 [Nov 6 22:18:09] DEBUG[24988] channel.c: Set channel SIP/9169-00000002 to write format ulaw [Nov 6 22:18:09] DEBUG[24988] channel.c: Scheduling timer at 0 sample intervals [Nov 6 22:18:09] DEBUG[24988] rtp.c: Ooh, format changed from unknown to ulaw [Nov 6 22:18:09] DEBUG[24988] rtp.c: Created smoother: format: 4 ms: 20 len: 160 [Nov 6 22:18:09] DEBUG[24988] rtp.c: Ooh, format changed from unknown to alaw [Nov 6 22:18:09] DEBUG[24988] rtp.c: Created smoother: format: 8 ms: 20 len: 160 [Nov 6 22:18:11] DEBUG[24988] rtp.c: Got RTCP report of 68 bytes [Nov 6 22:18:11] DEBUG[24988] rtp.c: Got RTCP report of 176 bytes [Nov 6 22:18:12] DEBUG[24988] rtp.c: Got RTCP report of 68 bytes [Nov 6 22:18:12] VERBOSE[24929] logger.c: <--- SIP read from 192.168.16.8:5060 ---> SIP/2.0 200 OK Call-ID: 6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7 Contact: Content-Length: 224 Content-Type: application/sdp CSeq: 102 INVITE From: "Shane James";tag=as26157ebf To: ;tag=c0a81008-3b User-Agent: Quintum/1.0.0 SN/0030E1021145 SW/P108-09-04 Via: SIP/2.0/UDP 192.168.16.7:5060;branch=z9hG4bK1c3357a4;rport v=0 o=Quintum 46 14665 IN IP4 192.168.16.8 s=VoipCall c=IN IP4 192.168.16.8 t=0 0 m=audio 10324 RTP/AVP 8 101 c=IN IP4 192.168.16.8 a=rtpmap:8 PCMA/8000/1 a=ptime:20 a=rtpmap:101 telephone-event/8000/1 a=sendrecv <-------------> [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Header 0: SIP/2.0 200 OK (14) [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Header 1: Call-ID: 6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7 (54) [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Header 2: Contact: (38) [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Header 3: Content-Length: 224 (19) [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Header 4: Content-Type: application/sdp (29) [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Header 5: CSeq: 102 INVITE (16) [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Header 6: From: "Shane James";tag=as26157ebf (57) [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Header 7: To: ;tag=c0a81008-3b (49) [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Header 8: User-Agent: Quintum/1.0.0 SN/0030E1021145 SW/P108-09-04 (55) [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Header 9: Via: SIP/2.0/UDP 192.168.16.7:5060;branch=z9hG4bK1c3357a4;rport (63) [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Header 10: (0) [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Line: v=0 (3) [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Line: o=Quintum 46 14665 IN IP4 192.168.16.8 (38) [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Line: s=VoipCall (10) [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Line: c=IN IP4 192.168.16.8 (21) [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Line: t=0 0 (5) [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Line: m=audio 10324 RTP/AVP 8 101 (27) [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Line: c=IN IP4 192.168.16.8 (21) [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Line: a=rtpmap:8 PCMA/8000/1 (22) [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Line: a=ptime:20 (10) [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000/1 (35) [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Line: a=sendrecv (10) [Nov 6 22:18:12] VERBOSE[24929] logger.c: --- (10 headers 11 lines) --- [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: = Found Their Call ID: 6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7 Their Tag c0a81008-3b Our tag: as26157ebf [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Acked pending invite 102 [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Stopping retransmission on '6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7' of Request 102: Match Found [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: SIP response 200 to standard invite [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Processing session-level SDP o=Quintum 46 14665 IN IP4 192.168.16.8... UNSUPPORTED. [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Processing session-level SDP s=VoipCall... UNSUPPORTED. [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.16.8... OK. [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Nov 6 22:18:12] VERBOSE[24929] logger.c: Found RTP audio format 8 [Nov 6 22:18:12] VERBOSE[24929] logger.c: Found RTP audio format 101 [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Processing media-level (audio) SDP c=IN IP4 192.168.16.8... OK. [Nov 6 22:18:12] VERBOSE[24929] logger.c: Found audio description format PCMA for ID 8 [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000/1... OK. [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Nov 6 22:18:12] VERBOSE[24929] logger.c: Found audio description format telephone-event for ID 101 [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000/1... OK. [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: T38 state changed to 0 on channel SIP/quintum-out-00000003 [Nov 6 22:18:12] VERBOSE[24929] logger.c: Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) [Nov 6 22:18:12] VERBOSE[24929] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Our T38 capability = (0), peer T38 capability (0), joint T38 capability (0) [Nov 6 22:18:12] VERBOSE[24929] logger.c: Peer audio RTP is at port 192.168.16.8:10324 [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: We're settling with these formats: 0x8 (alaw) [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: We have an owner, now see if we need to change this call [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Updating call counter for outgoing call [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: build_route: Contact hop: [Nov 6 22:18:12] VERBOSE[24929] logger.c: list_route: hop: [Nov 6 22:18:12] DEBUG[24929] chan_sip.c: Strict routing enforced for session 6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7 [Nov 6 22:18:12] VERBOSE[24929] logger.c: set_destination: Parsing for address/port to send to [Nov 6 22:18:12] VERBOSE[24929] logger.c: set_destination: set destination to 192.168.16.8, port 5060 [Nov 6 22:18:12] VERBOSE[24929] logger.c: Transmitting (no NAT) to 192.168.16.8:5060: ACK sip:0827863878@192.168.16.8 SIP/2.0 v: SIP/2.0/UDP 192.168.16.7:5060;branch=z9hG4bK5098cb29;rport f: "Shane James" ;tag=as26157ebf t: ;tag=c0a81008-3b m: i: 6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 l: 0 --- [Nov 6 22:18:12] DEBUG[24988] devicestate.c: Notification of state change to be queued on device/channel SIP/quintum-out [Nov 6 22:18:12] VERBOSE[24988] logger.c: -- SIP/quintum-out-00000003 answered SIP/9169-00000002 [Nov 6 22:18:12] DEBUG[24923] devicestate.c: No provider found, checking channel drivers for SIP - quintum-out [Nov 6 22:18:12] DEBUG[24923] chan_sip.c: Checking device state for peer quintum-out [Nov 6 22:18:12] DEBUG[24988] rtp.c: Changing ssrc from 465235190 to 1705442087 due to a source change [Nov 6 22:18:12] DEBUG[24923] devicestate.c: Changing state for SIP/quintum-out - state 1 (Not in use) [Nov 6 22:18:12] DEBUG[24988] rtp.c: Changing ssrc from 1070634602 to 677043798 due to a source change [Nov 6 22:18:12] DEBUG[24988] rtp.c: Cannot packet2packet bridge - raw formats are incompatible [Nov 6 22:18:12] DEBUG[24927] app_queue.c: Device 'SIP/quintum-out' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Nov 6 22:18:13] DEBUG[24988] rtp.c: Got RTCP report of 68 bytes [Nov 6 22:18:14] DEBUG[24988] rtp.c: Got RTCP report of 200 bytes [Nov 6 22:18:15] DEBUG[24988] rtp.c: Got RTCP report of 68 bytes [Nov 6 22:18:16] DEBUG[24988] rtp.c: Got RTCP report of 68 bytes [Nov 6 22:18:17] DEBUG[24988] rtp.c: Got RTCP report of 200 bytes [Nov 6 22:18:18] DEBUG[24988] rtp.c: Got RTCP report of 48 bytes [Nov 6 22:18:19] DEBUG[24988] rtp.c: Got RTCP report of 68 bytes [Nov 6 22:18:20] DEBUG[24988] rtp.c: Got RTCP report of 68 bytes [Nov 6 22:18:21] DEBUG[24988] rtp.c: Got RTCP report of 200 bytes [Nov 6 22:18:22] DEBUG[24988] rtp.c: Got RTCP report of 68 bytes [Nov 6 22:18:23] DEBUG[24988] rtp.c: Got RTCP report of 68 bytes [Nov 6 22:18:24] DEBUG[24988] rtp.c: Got RTCP report of 200 bytes [Nov 6 22:18:25] DEBUG[24988] rtp.c: Got RTCP report of 68 bytes [Nov 6 22:18:26] DEBUG[24988] rtp.c: Got RTCP report of 68 bytes [Nov 6 22:18:27] DEBUG[24988] rtp.c: Got RTCP report of 200 bytes [Nov 6 22:18:28] DEBUG[24988] rtp.c: Got RTCP report of 68 bytes [Nov 6 22:18:29] DEBUG[24988] rtp.c: Got RTCP report of 68 bytes [Nov 6 22:18:30] DEBUG[24988] rtp.c: Got RTCP report of 200 bytes [Nov 6 22:18:30] DEBUG[24988] rtp.c: Got RTCP report of 68 bytes [Nov 6 22:18:32] DEBUG[24988] rtp.c: Got RTCP report of 68 bytes [Nov 6 22:18:33] DEBUG[24988] rtp.c: Got RTCP report of 200 bytes [Nov 6 22:18:33] DEBUG[24988] rtp.c: Got RTCP report of 68 bytes [Nov 6 22:18:35] DEBUG[24988] rtp.c: Got RTCP report of 68 bytes [Nov 6 22:18:36] DEBUG[24988] rtp.c: Got RTCP report of 200 bytes [Nov 6 22:18:36] DEBUG[24988] rtp.c: Got RTCP report of 68 bytes [Nov 6 22:18:38] DEBUG[24929] chan_sip.c: Header 0: (0) [Nov 6 22:18:38] DEBUG[24929] chan_sip.c: Line: (0) [Nov 6 22:18:38] DEBUG[24988] rtp.c: Got RTCP report of 68 bytes [Nov 6 22:18:39] DEBUG[24988] rtp.c: Got RTCP report of 200 bytes [Nov 6 22:18:39] DEBUG[24988] rtp.c: Got RTCP report of 68 bytes [Nov 6 22:18:41] DEBUG[24988] rtp.c: Got RTCP report of 68 bytes [Nov 6 22:18:42] DEBUG[24988] rtp.c: Got RTCP report of 200 bytes [Nov 6 22:18:42] DEBUG[24988] rtp.c: Got RTCP report of 68 bytes [Nov 6 22:18:44] DEBUG[24988] rtp.c: Got RTCP report of 68 bytes [Nov 6 22:18:45] DEBUG[24988] rtp.c: Got RTCP report of 208 bytes [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: Header 0: BYE sip:00827863878@192.168.16.7 SIP/2.0 (40) [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.16.69:34741;branch=z9hG4bK-d8754z-952eb54b3947eb69-1---d8754z-;rport (93) [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: Header 2: Max-Forwards: 70 (16) [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: Header 3: Contact: (38) [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: Header 4: To: "00827863878";tag=as4f1a072c (62) [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: Header 5: From: "Shane Home";tag=7d33ba3a (54) [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: Header 6: Call-ID: Mjg0OTJlMjY2ODhmMzg0ZmJiYWNiMzY2MmZlNDU0MmM. (53) [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: Header 7: CSeq: 3 BYE (11) [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: Header 8: Proxy-Authorization: Digest username="9169",realm="alexmay.co.za",nonce="57bbff65",uri="sip:00827863878@192.168.16.7",response="1c066bdea5d77a5025f305af9760fdbf",algorithm=MD5 (175) [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: Header 9: User-Agent: X-Lite release 1104o stamp 56125 (44) [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: Header 10: Reason: SIP;description="User Hung Up" (38) [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: Header 11: Content-Length: 0 (17) [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: Header 12: (0) [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: = No match Their Call ID: 6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7 Their Tag c0a81008-3b Our tag: as26157ebf [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: = Found Their Call ID: Mjg0OTJlMjY2ODhmMzg0ZmJiYWNiMzY2MmZlNDU0MmM. Their Tag 7d33ba3a Our tag: as4f1a072c [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: Setting SIP_ALREADYGONE on dialog Mjg0OTJlMjY2ODhmMzg0ZmJiYWNiMzY2MmZlNDU0MmM. [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: Received bye, issuing owner hangup [Nov 6 22:18:45] DEBUG[24988] channel.c: Didn't get a frame from channel: SIP/9169-00000002 [Nov 6 22:18:45] DEBUG[24988] rtp.c: Setting the marker bit due to a source update [Nov 6 22:18:45] DEBUG[24988] channel.c: Bridge stops bridging channels SIP/9169-00000002 and SIP/quintum-out-00000003 [Nov 6 22:18:45] VERBOSE[24988] logger.c: > cdr_odbc: Query Successful! [Nov 6 22:18:45] DEBUG[24988] channel.c: Hanging up channel 'SIP/quintum-out-00000003' [Nov 6 22:18:45] DEBUG[24988] chan_sip.c: Hangup call SIP/quintum-out-00000003, SIP callid 6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7) [Nov 6 22:18:45] VERBOSE[24988] logger.c: Scheduling destruction of SIP dialog '6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7' in 32000 ms (Method: INVITE) [Nov 6 22:18:45] DEBUG[24988] chan_sip.c: Strict routing enforced for session 6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7 [Nov 6 22:18:45] VERBOSE[24988] logger.c: set_destination: Parsing for address/port to send to [Nov 6 22:18:45] VERBOSE[24988] logger.c: set_destination: set destination to 192.168.16.8, port 5060 [Nov 6 22:18:45] VERBOSE[24988] logger.c: Reliably Transmitting (no NAT) to 192.168.16.8:5060: BYE sip:0827863878@192.168.16.8 SIP/2.0 v: SIP/2.0/UDP 192.168.16.7:5060;branch=z9hG4bK0a4b166f;rport f: "Shane James" ;tag=as26157ebf t: ;tag=c0a81008-3b i: 6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7 CSeq: 103 BYE User-Agent: Asterisk PBX Max-Forwards: 70 X-Asterisk-HangupCause: Normal Clearing X-Asterisk-HangupCauseCode: 16 l: 0 --- [Nov 6 22:18:45] DEBUG[24988] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #-1 [Nov 6 22:18:45] DEBUG[24988] devicestate.c: Notification of state change to be queued on device/channel SIP/quintum-out [Nov 6 22:18:45] DEBUG[24988] rtp.c: Channel '' has no RTP, not doing anything [Nov 6 22:18:45] DEBUG[24988] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Nov 6 22:18:45] DEBUG[24988] pbx.c: Spawn extension (from-internal,00827863878,2) exited non-zero on 'SIP/9169-00000002' [Nov 6 22:18:45] VERBOSE[24988] logger.c: == Spawn extension (from-internal, 00827863878, 2) exited non-zero on 'SIP/9169-00000002' [Nov 6 22:18:45] DEBUG[24988] channel.c: Soft-Hanging up channel 'SIP/9169-00000002' [Nov 6 22:18:45] DEBUG[24988] channel.c: Hanging up channel 'SIP/9169-00000002' [Nov 6 22:18:45] DEBUG[24988] chan_sip.c: Hangup call SIP/9169-00000002, SIP callid Mjg0OTJlMjY2ODhmMzg0ZmJiYWNiMzY2MmZlNDU0MmM.) [Nov 6 22:18:45] DEBUG[24988] devicestate.c: Notification of state change to be queued on device/channel SIP/9169 [Nov 6 22:18:45] DEBUG[24923] devicestate.c: No provider found, checking channel drivers for SIP - quintum-out [Nov 6 22:18:45] DEBUG[24923] chan_sip.c: Checking device state for peer quintum-out [Nov 6 22:18:45] DEBUG[24923] devicestate.c: Changing state for SIP/quintum-out - state 1 (Not in use) [Nov 6 22:18:45] DEBUG[24927] app_queue.c: Device 'SIP/quintum-out' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Nov 6 22:18:45] DEBUG[24923] devicestate.c: No provider found, checking channel drivers for SIP - 9169 [Nov 6 22:18:45] DEBUG[24923] chan_sip.c: Checking device state for peer 9169 [Nov 6 22:18:45] DEBUG[24923] devicestate.c: Changing state for SIP/9169 - state 1 (Not in use) [Nov 6 22:18:45] DEBUG[24927] app_queue.c: Device 'SIP/9169' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Nov 6 22:18:45] VERBOSE[24929] logger.c: <--- SIP read from 192.168.16.8:5060 ---> SIP/2.0 200 OK Call-ID: 6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7 Content-Length: 0 CSeq: 103 BYE From: "Shane James";tag=as26157ebf To: ;tag=c0a81008-3b Via: SIP/2.0/UDP 192.168.16.7:5060;branch=z9hG4bK0a4b166f;rport <-------------> [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: Header 0: SIP/2.0 200 OK (14) [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: Header 1: Call-ID: 6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7 (54) [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: Header 2: Content-Length: 0 (17) [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: Header 3: CSeq: 103 BYE (13) [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: Header 4: From: "Shane James";tag=as26157ebf (57) [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: Header 5: To: ;tag=c0a81008-3b (49) [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: Header 6: Via: SIP/2.0/UDP 192.168.16.7:5060;branch=z9hG4bK0a4b166f;rport (63) [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: Header 7: (0) [Nov 6 22:18:45] VERBOSE[24929] logger.c: --- (7 headers 0 lines) --- [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: = Found Their Call ID: 6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7 Their Tag c0a81008-3b Our tag: as26157ebf [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #39 [Nov 6 22:18:45] DEBUG[24929] chan_sip.c: Stopping retransmission on '6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7' of Request 103: Match Found [Nov 6 22:18:45] VERBOSE[24929] logger.c: Really destroying SIP dialog '6416ae1a6574033f7cc5ee381eb1cdeb@192.168.16.7' Method: INVITE [Nov 6 22:18:45] VERBOSE[24929] logger.c: Really destroying SIP dialog 'Mjg0OTJlMjY2ODhmMzg0ZmJiYWNiMzY2MmZlNDU0MmM.' Method: BYE [Nov 6 22:18:52] VERBOSE[24985] logger.c: -- Remote UNIX connection disconnected [Nov 6 22:18:58] VERBOSE[24929] logger.c: <--- SIP read from 192.168.16.8:5060 ---> REGISTER sip:192.168.16.7 SIP/2.0 Authorization: Digest realm="alexmay.co.za", nonce="6af1bcb5",algorithm=MD5, username="6969", uri="sip:192.168.16.7", response="31d33d2d3aef55bafa2baeb40d183ce2" Call-ID: call-F115AE9D-D1CB-2D10-0E11-0@192.168.16.8 Contact: Content-Length: 0 CSeq: 154 REGISTER Expires: 300 From: ;tag=c0a81008-31 Max-Forwards: 70 To: User-Agent: Quintum/1.0.0 SN/0030E1021145 SW/P108-09-04 Via: SIP/2.0/UDP 192.168.16.8;branch=z9hG4bK-tenor-c0a8-1008-0103 <-------------> [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 0: REGISTER sip:192.168.16.7 SIP/2.0 (33) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 1: Authorization: Digest realm="alexmay.co.za", nonce="6af1bcb5",algorithm=MD5, username="6969", uri="sip:192.168.16.7", response="31d33d2d3aef55bafa2baeb40d183ce2" (161) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 2: Call-ID: call-F115AE9D-D1CB-2D10-0E11-0@192.168.16.8 (52) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 3: Contact: (27) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 4: Content-Length: 0 (17) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 5: CSeq: 154 REGISTER (18) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 6: Expires: 300 (12) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 7: From: ;tag=c0a81008-31 (45) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 8: Max-Forwards: 70 (16) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 9: To: (27) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 10: User-Agent: Quintum/1.0.0 SN/0030E1021145 SW/P108-09-04 (55) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 11: Via: SIP/2.0/UDP 192.168.16.8;branch=z9hG4bK-tenor-c0a8-1008-0103 (65) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 12: (0) [Nov 6 22:18:58] VERBOSE[24929] logger.c: --- (12 headers 0 lines) --- [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: = No match Their Call ID: NDYzMWFkMzZkZjRkZDUzZTlkNzE1ZDIyNDJhMTRlZjg. Their Tag fe61806b Our tag: as6307592e [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Allocating new SIP dialog for call-F115AE9D-D1CB-2D10-0E11-0@192.168.16.8 - REGISTER (No RTP) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Nov 6 22:18:58] VERBOSE[24929] logger.c: Using latest REGISTER request as basis request [Nov 6 22:18:58] VERBOSE[24929] logger.c: Sending to 192.168.16.8 : 5060 (no NAT) [Nov 6 22:18:58] VERBOSE[24929] logger.c: <--- Transmitting (NAT) to 192.168.16.8:5060 ---> SIP/2.0 100 Trying v: SIP/2.0/UDP 192.168.16.8;branch=z9hG4bK-tenor-c0a8-1008-0103;received=192.168.16.8 f: ;tag=c0a81008-31 t: i: call-F115AE9D-D1CB-2D10-0E11-0@192.168.16.8 CSeq: 154 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO k: replaces l: 0 <------------> [Nov 6 22:18:58] VERBOSE[24929] logger.c: <--- Transmitting (NAT) to 192.168.16.8:5060 ---> SIP/2.0 401 Unauthorized v: SIP/2.0/UDP 192.168.16.8;branch=z9hG4bK-tenor-c0a8-1008-0103;received=192.168.16.8 f: ;tag=c0a81008-31 t: ;tag=as3230da67 i: call-F115AE9D-D1CB-2D10-0E11-0@192.168.16.8 CSeq: 154 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO k: replaces WWW-Authenticate: Digest algorithm=MD5, realm="alexmay.co.za", nonce="069eb502" l: 0 <------------> [Nov 6 22:18:58] VERBOSE[24929] logger.c: Scheduling destruction of SIP dialog 'call-F115AE9D-D1CB-2D10-0E11-0@192.168.16.8' in 32000 ms (Method: REGISTER) [Nov 6 22:18:58] VERBOSE[24929] logger.c: <--- SIP read from 192.168.16.8:5060 ---> REGISTER sip:192.168.16.7 SIP/2.0 Authorization: Digest realm="alexmay.co.za", nonce="069eb502",algorithm=MD5, username="6969", uri="sip:192.168.16.7", response="100f25f53da98580f48bdf2e5674acc3" Call-ID: call-F115AE9D-D1CB-2D10-0E11-0@192.168.16.8 Contact: Content-Length: 0 CSeq: 155 REGISTER Expires: 300 From: ;tag=c0a81008-31 Max-Forwards: 70 To: User-Agent: Quintum/1.0.0 SN/0030E1021145 SW/P108-09-04 Via: SIP/2.0/UDP 192.168.16.8;branch=z9hG4bK-tenor-c0a8-1008-0105 <-------------> [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 0: REGISTER sip:192.168.16.7 SIP/2.0 (33) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 1: Authorization: Digest realm="alexmay.co.za", nonce="069eb502",algorithm=MD5, username="6969", uri="sip:192.168.16.7", response="100f25f53da98580f48bdf2e5674acc3" (161) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 2: Call-ID: call-F115AE9D-D1CB-2D10-0E11-0@192.168.16.8 (52) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 3: Contact: (27) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 4: Content-Length: 0 (17) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 5: CSeq: 155 REGISTER (18) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 6: Expires: 300 (12) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 7: From: ;tag=c0a81008-31 (45) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 8: Max-Forwards: 70 (16) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 9: To: (27) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 10: User-Agent: Quintum/1.0.0 SN/0030E1021145 SW/P108-09-04 (55) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 11: Via: SIP/2.0/UDP 192.168.16.8;branch=z9hG4bK-tenor-c0a8-1008-0105 (65) [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: Header 12: (0) [Nov 6 22:18:58] VERBOSE[24929] logger.c: --- (12 headers 0 lines) --- [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: = Found Their Call ID: call-F115AE9D-D1CB-2D10-0E11-0@192.168.16.8 Their Tag c0a81008-31 Our tag: as3230da67 [Nov 6 22:18:58] DEBUG[24929] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Nov 6 22:18:58] VERBOSE[24929] logger.c: Using latest REGISTER request as basis request [Nov 6 22:18:58] VERBOSE[24929] logger.c: Sending to 192.168.16.8 : 5060 (NAT) [Nov 6 22:18:58] VERBOSE[24929] logger.c: <--- Transmitting (NAT) to 192.168.16.8:5060 ---> SIP/2.0 100 Trying v: SIP/2.0/UDP 192.168.16.8;branch=z9hG4bK-tenor-c0a8-1008-0105;received=192.168.16.8 f: ;tag=c0a81008-31 t: i: call-F115AE9D-D1CB-2D10-0E11-0@192.168.16.8 CSeq: 155 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO k: replaces l: 0 <------------> [Nov 6 22:18:58] VERBOSE[24929] logger.c: <--- Transmitting (NAT) to 192.168.16.8:5060 ---> SIP/2.0 200 OK v: SIP/2.0/UDP 192.168.16.8;branch=z9hG4bK-tenor-c0a8-1008-0105;received=192.168.16.8 f: ;tag=c0a81008-31 t: ;tag=as3230da67 i: call-F115AE9D-D1CB-2D10-0E11-0@192.168.16.8 CSeq: 155 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO k: replaces Expires: 300 m: ;expires=300 Date: Sat, 06 Nov 2010 20:18:58 GMT l: 0 <------------> [Nov 6 22:18:58] DEBUG[24929] devicestate.c: Notification of state change to be queued on device/channel SIP/6969 [Nov 6 22:18:58] VERBOSE[24929] logger.c: Scheduling destruction of SIP dialog 'call-F115AE9D-D1CB-2D10-0E11-0@192.168.16.8' in 32000 ms (Method: REGISTER) [Nov 6 22:18:58] DEBUG[24923] devicestate.c: No provider found, checking channel drivers for SIP - 6969 [Nov 6 22:18:58] DEBUG[24923] chan_sip.c: Checking device state for peer 6969 [Nov 6 22:18:58] DEBUG[24923] devicestate.c: Changing state for SIP/6969 - state 1 (Not in use) [Nov 6 22:18:58] DEBUG[24927] app_queue.c: Device 'SIP/6969' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Nov 6 22:19:08] DEBUG[24929] chan_sip.c: Header 0: (0) [Nov 6 22:19:08] DEBUG[24929] chan_sip.c: Line: (0) [Nov 6 22:19:30] DEBUG[24929] chan_sip.c: Auto destroying SIP dialog 'call-F115AE9D-D1CB-2D10-0E11-0@192.168.16.8' [Nov 6 22:19:30] DEBUG[24929] chan_sip.c: Destroying SIP dialog call-F115AE9D-D1CB-2D10-0E11-0@192.168.16.8 [Nov 6 22:19:30] VERBOSE[24929] logger.c: Really destroying SIP dialog 'call-F115AE9D-D1CB-2D10-0E11-0@192.168.16.8' Method: REGISTER [Nov 6 22:19:38] DEBUG[24929] chan_sip.c: Header 0: (0) [Nov 6 22:19:38] DEBUG[24929] chan_sip.c: Line: (0) [Nov 6 22:20:08] DEBUG[24929] chan_sip.c: Header 0: (0) [Nov 6 22:20:08] DEBUG[24929] chan_sip.c: Line: (0) [Nov 6 22:20:14] DEBUG[24929] chan_sip.c: Header 0: SUBSCRIBE sip:asterisk@192.168.16.7 SIP/2.0 (43) [Nov 6 22:20:14] DEBUG[24929] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.16.69:34741;branch=z9hG4bK-d8754z-bf22fd61fe2b4678-1---d8754z-;rport (93) [Nov 6 22:20:14] DEBUG[24929] chan_sip.c: Header 2: Max-Forwards: 70 (16) [Nov 6 22:20:14] DEBUG[24929] chan_sip.c: Header 3: Contact: (38) [Nov 6 22:20:14] DEBUG[24929] chan_sip.c: Header 4: To: "Shane Home";tag=as6307592e (54) [Nov 6 22:20:14] DEBUG[24929] chan_sip.c: Header 5: From: "Shane Home";tag=fe61806b (54) [Nov 6 22:20:14] DEBUG[24929] chan_sip.c: Header 6: Call-ID: NDYzMWFkMzZkZjRkZDUzZTlkNzE1ZDIyNDJhMTRlZjg. (53) [Nov 6 22:20:14] DEBUG[24929] chan_sip.c: Header 7: CSeq: 4 SUBSCRIBE (17) [Nov 6 22:20:14] DEBUG[24929] chan_sip.c: Header 8: Expires: 300 (12) [Nov 6 22:20:14] DEBUG[24929] chan_sip.c: Header 9: User-Agent: X-Lite release 1104o stamp 56125 (44) [Nov 6 22:20:14] DEBUG[24929] chan_sip.c: Header 10: Authorization: Digest username="9169",realm="alexmay.co.za",nonce="7ea80f92",uri="sip:asterisk@192.168.16.7",response="971865926af8a282e868d43ac55361e9",algorithm=MD5 (166) [Nov 6 22:20:14] DEBUG[24929] chan_sip.c: Header 11: Event: message-summary (22) [Nov 6 22:20:14] DEBUG[24929] chan_sip.c: Header 12: Content-Length: 0 (17) [Nov 6 22:20:14] DEBUG[24929] chan_sip.c: Header 13: (0) [Nov 6 22:20:14] DEBUG[24929] chan_sip.c: = Found Their Call ID: NDYzMWFkMzZkZjRkZDUzZTlkNzE1ZDIyNDJhMTRlZjg. Their Tag fe61806b Our tag: as6307592e [Nov 6 22:20:14] DEBUG[24929] chan_sip.c: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE [Nov 6 22:20:14] NOTICE[24929] chan_sip.c: Correct auth, but based on stale nonce received from '"Shane Home";tag=fe61806b' [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Header 0: SUBSCRIBE sip:asterisk@192.168.16.7 SIP/2.0 (43) [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.16.69:34741;branch=z9hG4bK-d8754z-8b57f33eee345617-1---d8754z-;rport (93) [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Header 2: Max-Forwards: 70 (16) [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Header 3: Contact: (38) [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Header 4: To: "Shane Home";tag=as6307592e (54) [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Header 5: From: "Shane Home";tag=fe61806b (54) [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Header 6: Call-ID: NDYzMWFkMzZkZjRkZDUzZTlkNzE1ZDIyNDJhMTRlZjg. (53) [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Header 7: CSeq: 5 SUBSCRIBE (17) [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Header 8: Expires: 300 (12) [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Header 9: User-Agent: X-Lite release 1104o stamp 56125 (44) [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Header 10: Authorization: Digest username="9169",realm="alexmay.co.za",nonce="3a5910f8",uri="sip:asterisk@192.168.16.7",response="3bbc75aa6cc78b2838f86488259396c5",algorithm=MD5 (166) [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Header 11: Event: message-summary (22) [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Header 12: Content-Length: 0 (17) [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Header 13: (0) [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: = Found Their Call ID: NDYzMWFkMzZkZjRkZDUzZTlkNzE1ZDIyNDJhMTRlZjg. Their Tag fe61806b Our tag: as6307592e [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Adding subscription for mailbox notification - peer 9169 Mailbox 9169@default [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #-1 [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Header 0: SIP/2.0 200 OK (14) [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.16.7:5060;branch=z9hG4bK0dbb99d1;rport=5060 (68) [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Header 2: Contact: (38) [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Header 3: To: ;tag=fe61806b (46) [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Header 4: From: "asterisk";tag=as6307592e (58) [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Header 5: Call-ID: NDYzMWFkMzZkZjRkZDUzZTlkNzE1ZDIyNDJhMTRlZjg. (53) [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Header 6: CSeq: 103 NOTIFY (16) [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Header 7: User-Agent: X-Lite release 1104o stamp 56125 (44) [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Header 8: Content-Length: 0 (17) [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Header 9: (0) [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: = Found Their Call ID: NDYzMWFkMzZkZjRkZDUzZTlkNzE1ZDIyNDJhMTRlZjg. Their Tag fe61806b Our tag: as6307592e [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #45 [Nov 6 22:20:15] DEBUG[24929] chan_sip.c: Stopping retransmission on 'NDYzMWFkMzZkZjRkZDUzZTlkNzE1ZDIyNDJhMTRlZjg.' of Request 103: Match Found [Nov 6 22:20:38] DEBUG[24929] chan_sip.c: Header 0: (0) [Nov 6 22:20:38] DEBUG[24929] chan_sip.c: Line: (0)