[Jun 10 14:57:40] NOTICE[3363] chan_sip.c: We don't have subscription for peer: 401 [Jun 10 14:57:40] VERBOSE[3363] logger.c: <--- SIP read from 192.168.161.250:5060 ---> SUBSCRIBE sip:401@pbx.example.net SIP/2.0 Via: SIP/2.0/UDP 192.168.161.250:5060;branch=z9hG4bK-746znpm8utnt;rport From: ;tag=8t0kkke1ud To: ;tag=as264a6ae5 Call-ID: 3c26b193d3f5-8mm74rdut151 CSeq: 4 SUBSCRIBE Max-Forwards: 70 Contact: ;flow-id=1 Event: message-summary Accept: application/simple-message-summary User-Agent: snom360/7.1.33 Authorization: Digest username="401",realm="siprealm",nonce="03f2b4ad",uri="sip:401@pbx.example.net",response="4312aee356b6027a230ae751ba55857d",algorithm=MD5 Expires: 0 Content-Length: 0 <-------------> [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 0: SUBSCRIBE sip:401@pbx.example.net SIP/2.0 (41) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.250:5060;branch=z9hG4bK-746znpm8utnt;rport (71) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 2: From: ;tag=8t0kkke1ud (46) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 3: To: ;tag=as264a6ae5 (44) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 4: Call-ID: 3c26b193d3f5-8mm74rdut151 (34) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 5: CSeq: 4 SUBSCRIBE (17) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 6: Max-Forwards: 70 (16) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 7: Contact: ;flow-id=1 (49) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 8: Event: message-summary (22) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 9: Accept: application/simple-message-summary (42) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 10: User-Agent: snom360/7.1.33 (26) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 11: Authorization: Digest username="401",realm="siprealm",nonce="03f2b4ad",uri="sip:401@pbx.example.net",response="4312aee356b6027a230ae751ba55857d",algorithm=MD5 (158) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 12: Expires: 0 (10) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 13: Content-Length: 0 (17) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 14: (0) [Jun 10 14:57:40] VERBOSE[3363] logger.c: --- (14 headers 0 lines) --- [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: = No match Their Call ID: 3c26b1e9e60e-hmjv96ktqzhp Their Tag ea12o5y2gj Our tag: as6cbe01aa [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: = No match Their Call ID: 3c26b193771a-rw1x9mnlj9x9 Their Tag 3jfu9k8e4g Our tag: as631c9486 [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: = Found Their Call ID: 3c26b193d3f5-8mm74rdut151 Their Tag 8t0kkke1ud Our tag: as264a6ae5 [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Got a re-subscribe on existing subscription 3c26b193d3f5-8mm74rdut151 [Jun 10 14:57:40] VERBOSE[3363] logger.c: Found peer '401' [Jun 10 14:57:40] VERBOSE[3363] logger.c: Looking for 401 in subscriptions (domain pbx.example.net) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Adding subscription for mailbox notification - peer 401 Mailbox 401@voice-00 [Jun 10 14:57:40] VERBOSE[3363] logger.c: <--- Transmitting (no NAT) to 192.168.161.250:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.161.250:5060;branch=z9hG4bK-746znpm8utnt;received=192.168.161.250;rport=5060 From: ;tag=8t0kkke1ud To: ;tag=as264a6ae5 Call-ID: 3c26b193d3f5-8mm74rdut151 CSeq: 4 SUBSCRIBE User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Expires: 0 Content-Length: 0 <------------> [Jun 10 14:57:40] VERBOSE[3363] logger.c: Really destroying SIP dialog '3c26b193d3f5-8mm74rdut151' Method: SUBSCRIBE [Jun 10 14:57:40] VERBOSE[3363] logger.c: <--- SIP read from 192.168.161.250:5060 ---> REGISTER sip:pbx.example.net SIP/2.0 Via: SIP/2.0/UDP 192.168.161.250:5060;branch=z9hG4bK-n6s6znnroavm;rport From: "Toestel 401" ;tag=3jfu9k8e4g To: "Toestel 401" Call-ID: 3c26b193771a-rw1x9mnlj9x9 CSeq: 359 REGISTER Max-Forwards: 70 Contact: ;flow-id=1;q=1.0;+sip.instance="" User-Agent: snom360/7.1.33 Supported: gruu Allow-Events: dialog X-Real-IP: 192.168.161.250 Authorization: Digest username="401",realm="siprealm",nonce="42264dac",uri="sip:pbx.example.net",response="461b8542d3074fee2eea6b958b0c43d1",algorithm=MD5 Expires: 0 Content-Length: 0 <-------------> [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 0: REGISTER sip:pbx.example.net SIP/2.0 (36) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.250:5060;branch=z9hG4bK-n6s6znnroavm;rport (71) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 2: From: "Toestel 401" ;tag=3jfu9k8e4g (60) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 3: To: "Toestel 401" (43) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 4: Call-ID: 3c26b193771a-rw1x9mnlj9x9 (34) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 5: CSeq: 359 REGISTER (18) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 6: Max-Forwards: 70 (16) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 7: Contact: ;flow-id=1;q=1.0;+sip.instance="" (119) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 8: User-Agent: snom360/7.1.33 (26) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 9: Supported: gruu (15) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 10: Allow-Events: dialog (20) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 11: X-Real-IP: 192.168.161.250 (26) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 12: Authorization: Digest username="401",realm="siprealm",nonce="42264dac",uri="sip:pbx.example.net",response="461b8542d3074fee2eea6b958b0c43d1",algorithm=MD5 (154) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 13: Expires: 0 (10) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 14: Content-Length: 0 (17) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 15: (0) [Jun 10 14:57:40] VERBOSE[3363] logger.c: --- (15 headers 0 lines) --- [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: = No match Their Call ID: 3c26b1e9e60e-hmjv96ktqzhp Their Tag ea12o5y2gj Our tag: as6cbe01aa [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: = Found Their Call ID: 3c26b193771a-rw1x9mnlj9x9 Their Tag 3jfu9k8e4g Our tag: as631c9486 [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Jun 10 14:57:40] VERBOSE[3363] logger.c: Using latest REGISTER request as basis request [Jun 10 14:57:40] VERBOSE[3363] logger.c: Sending to 192.168.161.250 : 5060 (NAT) [Jun 10 14:57:40] VERBOSE[3363] logger.c: <--- Transmitting (no NAT) to 192.168.161.250:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.161.250:5060;branch=z9hG4bK-n6s6znnroavm;received=192.168.161.250;rport=5060 From: "Toestel 401" ;tag=3jfu9k8e4g To: "Toestel 401" Call-ID: 3c26b193771a-rw1x9mnlj9x9 CSeq: 359 REGISTER User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Jun 10 14:57:40] VERBOSE[3363] logger.c: -- Unregistered SIP '401' [Jun 10 14:57:40] VERBOSE[3363] logger.c: <--- Transmitting (no NAT) to 192.168.161.250:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.161.250:5060;branch=z9hG4bK-n6s6znnroavm;received=192.168.161.250;rport=5060 From: "Toestel 401" ;tag=3jfu9k8e4g To: "Toestel 401" ;tag=as631c9486 Call-ID: 3c26b193771a-rw1x9mnlj9x9 CSeq: 359 REGISTER User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Expires: 0 Date: Tue, 10 Jun 2008 12:57:40 GMT Content-Length: 0 <------------> [Jun 10 14:57:40] DEBUG[3363] devicestate.c: Notification of state change to be queued on device/channel SIP/401 [Jun 10 14:57:40] VERBOSE[3363] logger.c: Scheduling destruction of SIP dialog '3c26b193771a-rw1x9mnlj9x9' in 32000 ms (Method: REGISTER) [Jun 10 14:57:40] NOTICE[3363] chan_sip.c: We don't have subscription for peer: 401 [Jun 10 14:57:40] DEBUG[3342] devicestate.c: No provider found, checking channel drivers for SIP - 401 [Jun 10 14:57:40] DEBUG[3342] chan_sip.c: Checking device state for peer 401 [Jun 10 14:57:40] DEBUG[3342] devicestate.c: Changing state for SIP/401 - state 5 (Unavailable) [Jun 10 14:57:40] DEBUG[3342] devicestate.c: No provider found, checking channel drivers for SIP - 401 [Jun 10 14:57:40] DEBUG[3342] chan_sip.c: Checking device state for peer 401 [Jun 10 14:57:40] DEBUG[3365] app_queue.c: Device 'SIP/401' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Jun 10 14:57:40] VERBOSE[3363] logger.c: <--- SIP read from 192.168.161.250:5060 ---> REGISTER sip:pbx.example.net SIP/2.0 Via: SIP/2.0/UDP 192.168.161.250:5060;branch=z9hG4bK-dcmd7d1dw9mj;rport From: "Toestel 401" ;tag=ea12o5y2gj To: "Toestel 401" Call-ID: 3c26b1e9e60e-hmjv96ktqzhp CSeq: 360 REGISTER Max-Forwards: 70 Contact: ;flow-id=1;q=1.0;+sip.instance="" User-Agent: snom360/7.1.33 Supported: gruu Allow-Events: dialog X-Real-IP: 192.168.161.250 Authorization: Digest username="401",realm="siprealm",nonce="13143243",uri="sip:pbx.example.net",response="884b3a37dbbeed23bfb4c64772113650",algorithm=MD5 Expires: 600 Content-Length: 0 <-------------> [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 0: REGISTER sip:pbx.example.net SIP/2.0 (36) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.250:5060;branch=z9hG4bK-dcmd7d1dw9mj;rport (71) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 2: From: "Toestel 401" ;tag=ea12o5y2gj (60) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 3: To: "Toestel 401" (43) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 4: Call-ID: 3c26b1e9e60e-hmjv96ktqzhp (34) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 5: CSeq: 360 REGISTER (18) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 6: Max-Forwards: 70 (16) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 7: Contact: ;flow-id=1;q=1.0;+sip.instance="" (119) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 8: User-Agent: snom360/7.1.33 (26) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 9: Supported: gruu (15) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 10: Allow-Events: dialog (20) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 11: X-Real-IP: 192.168.161.250 (26) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 12: Authorization: Digest username="401",realm="siprealm",nonce="13143243",uri="sip:pbx.example.net",response="884b3a37dbbeed23bfb4c64772113650",algorithm=MD5 (154) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 13: Expires: 600 (12) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 14: Content-Length: 0 (17) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 15: (0) [Jun 10 14:57:40] VERBOSE[3363] logger.c: --- (15 headers 0 lines) --- [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: = Found Their Call ID: 3c26b1e9e60e-hmjv96ktqzhp Their Tag ea12o5y2gj Our tag: as6cbe01aa [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Jun 10 14:57:40] VERBOSE[3363] logger.c: Using latest REGISTER request as basis request [Jun 10 14:57:40] VERBOSE[3363] logger.c: Sending to 192.168.161.250 : 5060 (NAT) [Jun 10 14:57:40] VERBOSE[3363] logger.c: <--- Transmitting (no NAT) to 192.168.161.250:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.161.250:5060;branch=z9hG4bK-dcmd7d1dw9mj;received=192.168.161.250;rport=5060 From: "Toestel 401" ;tag=ea12o5y2gj To: "Toestel 401" Call-ID: 3c26b1e9e60e-hmjv96ktqzhp CSeq: 360 REGISTER User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Jun 10 14:57:40] DEBUG[3363] acl.c: ##### Testing 192.168.161.250 with 192.168.161.0 [Jun 10 14:57:40] DEBUG[3363] acl.c: ##### Testing 192.168.161.250 with 192.168.200.0 [Jun 10 14:57:40] DEBUG[3363] acl.c: ##### Testing 192.168.161.250 with 192.168.1.0 [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 0: OPTIONS sip:401@192.168.161.250:5060 SIP/2.0 (44) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK6a1aa427;rport (66) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 2: From: "asterisk" ;tag=as7159f53b (62) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 3: To: (34) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 4: Contact: (39) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 5: Call-ID: 5585f4a26fe3efe54e5d4e152987fa71@pbx.example.net (57) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 7: User-Agent: atCOM PBX (21) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 8: Max-Forwards: 70 (16) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 9: Date: Tue, 10 Jun 2008 12:57:40 GMT (35) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 11: Supported: replaces (19) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 12: Content-Length: 0 (17) [Jun 10 14:57:40] VERBOSE[3363] logger.c: Reliably Transmitting (no NAT) to 192.168.161.250:5060: OPTIONS sip:401@192.168.161.250:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK6a1aa427;rport From: "asterisk" ;tag=as7159f53b To: Contact: Call-ID: 5585f4a26fe3efe54e5d4e152987fa71@pbx.example.net CSeq: 102 OPTIONS User-Agent: atCOM PBX Max-Forwards: 70 Date: Tue, 10 Jun 2008 12:57:40 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #0 [Jun 10 14:57:40] VERBOSE[3363] logger.c: -- Registered SIP '401' at 192.168.161.250 port 5060 expires 600 [Jun 10 14:57:40] VERBOSE[3363] logger.c: -- Saved useragent "snom360/7.1.33" for peer 401 [Jun 10 14:57:40] VERBOSE[3363] logger.c: <--- Transmitting (no NAT) to 192.168.161.250:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.161.250:5060;branch=z9hG4bK-dcmd7d1dw9mj;received=192.168.161.250;rport=5060 From: "Toestel 401" ;tag=ea12o5y2gj To: "Toestel 401" ;tag=as6cbe01aa Call-ID: 3c26b1e9e60e-hmjv96ktqzhp CSeq: 360 REGISTER User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Expires: 600 Contact: ;expires=600 Date: Tue, 10 Jun 2008 12:57:40 GMT Content-Length: 0 <------------> [Jun 10 14:57:40] DEBUG[3363] devicestate.c: Notification of state change to be queued on device/channel SIP/401 [Jun 10 14:57:40] VERBOSE[3363] logger.c: Scheduling destruction of SIP dialog '3c26b1e9e60e-hmjv96ktqzhp' in 32000 ms (Method: REGISTER) [Jun 10 14:57:40] NOTICE[3363] chan_sip.c: We don't have subscription for peer: 401 [Jun 10 14:57:40] DEBUG[3342] devicestate.c: No provider found, checking channel drivers for SIP - 401 [Jun 10 14:57:40] DEBUG[3342] chan_sip.c: Checking device state for peer 401 [Jun 10 14:57:40] DEBUG[3342] devicestate.c: Changing state for SIP/401 - state 1 (Not in use) [Jun 10 14:57:40] DEBUG[3342] devicestate.c: No provider found, checking channel drivers for SIP - 401 [Jun 10 14:57:40] DEBUG[3342] chan_sip.c: Checking device state for peer 401 [Jun 10 14:57:40] DEBUG[3365] app_queue.c: Device 'SIP/401' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Jun 10 14:57:40] VERBOSE[3363] logger.c: <--- SIP read from 192.168.161.250:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK6a1aa427;rport=5060 From: "asterisk" ;tag=as7159f53b To: Call-ID: 5585f4a26fe3efe54e5d4e152987fa71@pbx.example.net CSeq: 102 OPTIONS Contact: ;flow-id=1 User-Agent: snom360/7.1.33 Accept-Language: en Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer, call-info Supported: timer, 100rel, replaces, from-change Content-Length: 0 <-------------> [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 0: SIP/2.0 200 OK (14) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK6a1aa427;rport=5060 (71) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 2: From: "asterisk" ;tag=as7159f53b (62) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 3: To: (34) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 4: Call-ID: 5585f4a26fe3efe54e5d4e152987fa71@pbx.example.net (57) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 5: CSeq: 102 OPTIONS (17) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 6: Contact: ;flow-id=1 (49) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 7: User-Agent: snom360/7.1.33 (26) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 8: Accept-Language: en (19) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 9: Accept: application/sdp (23) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 11: Allow-Events: talk, hold, refer, call-info (42) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 12: Supported: timer, 100rel, replaces, from-change (47) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 13: Content-Length: 0 (17) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 14: (0) [Jun 10 14:57:40] VERBOSE[3363] logger.c: --- (14 headers 0 lines) --- [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: = Found Their Call ID: 5585f4a26fe3efe54e5d4e152987fa71@pbx.example.net Their Tag Our tag: as7159f53b [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #208 [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Stopping retransmission on '5585f4a26fe3efe54e5d4e152987fa71@pbx.example.net' of Request 102: Match Not Found [Jun 10 14:57:40] NOTICE[3363] chan_sip.c: Peer '401' is now Reachable. (55ms / 5000ms) [Jun 10 14:57:40] DEBUG[3363] devicestate.c: Notification of state change to be queued on device/channel SIP/401 [Jun 10 14:57:40] NOTICE[3363] chan_sip.c: We don't have subscription for peer: 401 [Jun 10 14:57:40] VERBOSE[3363] logger.c: Really destroying SIP dialog '5585f4a26fe3efe54e5d4e152987fa71@pbx.example.net' Method: OPTIONS [Jun 10 14:57:40] DEBUG[3342] devicestate.c: No provider found, checking channel drivers for SIP - 401 [Jun 10 14:57:40] DEBUG[3342] chan_sip.c: Checking device state for peer 401 [Jun 10 14:57:40] DEBUG[3342] devicestate.c: Changing state for SIP/401 - state 1 (Not in use) [Jun 10 14:57:40] DEBUG[3342] devicestate.c: No provider found, checking channel drivers for SIP - 401 [Jun 10 14:57:40] DEBUG[3342] chan_sip.c: Checking device state for peer 401 [Jun 10 14:57:40] DEBUG[3365] app_queue.c: Device 'SIP/401' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Jun 10 14:57:40] VERBOSE[3363] logger.c: <--- SIP read from 192.168.161.250:5060 ---> SUBSCRIBE sip:401@pbx.example.net SIP/2.0 Via: SIP/2.0/UDP 192.168.161.250:5060;branch=z9hG4bK-0yy2wfviywju;rport From: ;tag=83hrqnfzz9 To: Call-ID: 3c26b1ea495a-hhcoa1v0d101 CSeq: 1 SUBSCRIBE Max-Forwards: 70 Contact: ;flow-id=1 Event: message-summary Accept: application/simple-message-summary User-Agent: snom360/7.1.33 Expires: 3600 Content-Length: 0 <-------------> [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 0: SUBSCRIBE sip:401@pbx.example.net SIP/2.0 (41) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.250:5060;branch=z9hG4bK-0yy2wfviywju;rport (71) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 2: From: ;tag=83hrqnfzz9 (46) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 3: To: (29) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 4: Call-ID: 3c26b1ea495a-hhcoa1v0d101 (34) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 5: CSeq: 1 SUBSCRIBE (17) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 6: Max-Forwards: 70 (16) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 7: Contact: ;flow-id=1 (49) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 8: Event: message-summary (22) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 9: Accept: application/simple-message-summary (42) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 10: User-Agent: snom360/7.1.33 (26) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 11: Expires: 3600 (13) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 12: Content-Length: 0 (17) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Header 13: (0) [Jun 10 14:57:40] VERBOSE[3363] logger.c: --- (13 headers 0 lines) --- [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: = No match Their Call ID: 3c26b1e9e60e-hmjv96ktqzhp Their Tag ea12o5y2gj Our tag: as6cbe01aa [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: = No match Their Call ID: 3c26b193771a-rw1x9mnlj9x9 Their Tag 3jfu9k8e4g Our tag: as631c9486 [Jun 10 14:57:40] DEBUG[3363] acl.c: ##### Testing 192.168.161.250 with 192.168.161.0 [Jun 10 14:57:40] DEBUG[3363] acl.c: ##### Testing 192.168.161.250 with 192.168.200.0 [Jun 10 14:57:40] DEBUG[3363] acl.c: ##### Testing 192.168.161.250 with 192.168.1.0 [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: Allocating new SIP dialog for 3c26b1ea495a-hhcoa1v0d101 - SUBSCRIBE (No RTP) [Jun 10 14:57:40] DEBUG[3363] chan_sip.c: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE [Jun 10 14:57:40] VERBOSE[3363] logger.c: Creating new subscription [Jun 10 14:57:40] VERBOSE[3363] logger.c: Sending to 192.168.161.250 : 5060 (NAT) [Jun 10 14:57:40] VERBOSE[3363] logger.c: Found peer '401' [Jun 10 14:57:40] VERBOSE[3363] logger.c: <--- Transmitting (no NAT) to 192.168.161.250:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.161.250:5060;branch=z9hG4bK-0yy2wfviywju;received=192.168.161.250;rport=5060 From: ;tag=83hrqnfzz9 To: ;tag=as7c2916b5 Call-ID: 3c26b1ea495a-hhcoa1v0d101 CSeq: 1 SUBSCRIBE User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces WWW-Authenticate: Digest algorithm=MD5, realm="siprealm", nonce="12a4f41e" Content-Length: 0 <------------> [Jun 10 14:57:40] VERBOSE[3363] logger.c: Scheduling destruction of SIP dialog '3c26b1ea495a-hhcoa1v0d101' in 32000 ms (Method: SUBSCRIBE) [Jun 10 14:57:40] NOTICE[3363] chan_sip.c: We don't have subscription for peer: 401 [Jun 10 14:57:41] VERBOSE[3363] logger.c: <--- SIP read from 192.168.161.250:5060 ---> SUBSCRIBE sip:401@pbx.example.net SIP/2.0 Via: SIP/2.0/UDP 192.168.161.250:5060;branch=z9hG4bK-evgethyuq9np;rport From: ;tag=83hrqnfzz9 To: Call-ID: 3c26b1ea495a-hhcoa1v0d101 CSeq: 2 SUBSCRIBE Max-Forwards: 70 Contact: ;flow-id=1 Event: message-summary Accept: application/simple-message-summary User-Agent: snom360/7.1.33 Authorization: Digest username="401",realm="siprealm",nonce="12a4f41e",uri="sip:401@pbx.example.net",response="d0072845826864a8b8218eb9c3ca131b",algorithm=MD5 Expires: 3600 Content-Length: 0 <-------------> [Jun 10 14:57:41] DEBUG[3363] chan_sip.c: Header 0: SUBSCRIBE sip:401@pbx.example.net SIP/2.0 (41) [Jun 10 14:57:41] DEBUG[3363] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.250:5060;branch=z9hG4bK-evgethyuq9np;rport (71) [Jun 10 14:57:41] DEBUG[3363] chan_sip.c: Header 2: From: ;tag=83hrqnfzz9 (46) [Jun 10 14:57:41] DEBUG[3363] chan_sip.c: Header 3: To: (29) [Jun 10 14:57:41] DEBUG[3363] chan_sip.c: Header 4: Call-ID: 3c26b1ea495a-hhcoa1v0d101 (34) [Jun 10 14:57:41] DEBUG[3363] chan_sip.c: Header 5: CSeq: 2 SUBSCRIBE (17) [Jun 10 14:57:41] DEBUG[3363] chan_sip.c: Header 6: Max-Forwards: 70 (16) [Jun 10 14:57:41] DEBUG[3363] chan_sip.c: Header 7: Contact: ;flow-id=1 (49) [Jun 10 14:57:41] DEBUG[3363] chan_sip.c: Header 8: Event: message-summary (22) [Jun 10 14:57:41] DEBUG[3363] chan_sip.c: Header 9: Accept: application/simple-message-summary (42) [Jun 10 14:57:41] DEBUG[3363] chan_sip.c: Header 10: User-Agent: snom360/7.1.33 (26) [Jun 10 14:57:41] DEBUG[3363] chan_sip.c: Header 11: Authorization: Digest username="401",realm="siprealm",nonce="12a4f41e",uri="sip:401@pbx.example.net",response="d0072845826864a8b8218eb9c3ca131b",algorithm=MD5 (158) [Jun 10 14:57:41] DEBUG[3363] chan_sip.c: Header 12: Expires: 3600 (13) [Jun 10 14:57:41] DEBUG[3363] chan_sip.c: Header 13: Content-Length: 0 (17) [Jun 10 14:57:41] DEBUG[3363] chan_sip.c: Header 14: (0) [Jun 10 14:57:41] VERBOSE[3363] logger.c: --- (14 headers 0 lines) --- [Jun 10 14:57:41] DEBUG[3363] chan_sip.c: = Found Their Call ID: 3c26b1ea495a-hhcoa1v0d101 Their Tag 83hrqnfzz9 Our tag: as7c2916b5 [Jun 10 14:57:41] DEBUG[3363] chan_sip.c: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE [Jun 10 14:57:41] DEBUG[3363] chan_sip.c: Got a new subscription 3c26b1ea495a-hhcoa1v0d101 (possibly with auth) [Jun 10 14:57:41] VERBOSE[3363] logger.c: Creating new subscription [Jun 10 14:57:41] VERBOSE[3363] logger.c: Sending to 192.168.161.250 : 5060 (NAT) [Jun 10 14:57:41] VERBOSE[3363] logger.c: Found peer '401' [Jun 10 14:57:41] VERBOSE[3363] logger.c: Looking for 401 in subscriptions (domain pbx.example.net) [Jun 10 14:57:41] DEBUG[3363] chan_sip.c: Adding subscription for mailbox notification - peer 401 Mailbox 401@voice-00 [Jun 10 14:57:41] VERBOSE[3363] logger.c: Scheduling destruction of SIP dialog '3c26b1ea495a-hhcoa1v0d101' in 3610000 ms (Method: SUBSCRIBE) [Jun 10 14:57:41] VERBOSE[3363] logger.c: <--- Transmitting (no NAT) to 192.168.161.250:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.161.250:5060;branch=z9hG4bK-evgethyuq9np;received=192.168.161.250;rport=5060 From: ;tag=83hrqnfzz9 To: ;tag=as7c2916b5 Call-ID: 3c26b1ea495a-hhcoa1v0d101 CSeq: 2 SUBSCRIBE User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Expires: 3600 Contact: ;expires=3600 Content-Length: 0 <------------> [Jun 10 14:57:43] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:57:45] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:57:47] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:57:49] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:57:51] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:57:53] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:57:55] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:57:57] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:57:58] DEBUG[3363] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Jun 10 14:57:58] DEBUG[3363] acl.c: ##### Testing 192.168.161.242 with 192.168.161.0 [Jun 10 14:57:58] DEBUG[3363] acl.c: ##### Testing 192.168.161.242 with 192.168.200.0 [Jun 10 14:57:58] DEBUG[3363] acl.c: ##### Testing 192.168.161.242 with 192.168.1.0 [Jun 10 14:57:58] DEBUG[3363] chan_sip.c: Header 0: OPTIONS sip:422@192.168.161.242:5060 SIP/2.0 (44) [Jun 10 14:57:58] DEBUG[3363] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK5a100c83;rport (66) [Jun 10 14:57:58] DEBUG[3363] chan_sip.c: Header 2: From: "asterisk" ;tag=as03d951a0 (62) [Jun 10 14:57:58] DEBUG[3363] chan_sip.c: Header 3: To: (34) [Jun 10 14:57:58] DEBUG[3363] chan_sip.c: Header 4: Contact: (39) [Jun 10 14:57:58] DEBUG[3363] chan_sip.c: Header 5: Call-ID: 69fe4f8a5af16f876cf3ce9351063ec8@pbx.example.net (57) [Jun 10 14:57:58] DEBUG[3363] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17) [Jun 10 14:57:58] DEBUG[3363] chan_sip.c: Header 7: User-Agent: atCOM PBX (21) [Jun 10 14:57:58] DEBUG[3363] chan_sip.c: Header 8: Max-Forwards: 70 (16) [Jun 10 14:57:58] DEBUG[3363] chan_sip.c: Header 9: Date: Tue, 10 Jun 2008 12:57:58 GMT (35) [Jun 10 14:57:58] DEBUG[3363] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jun 10 14:57:58] DEBUG[3363] chan_sip.c: Header 11: Supported: replaces (19) [Jun 10 14:57:58] DEBUG[3363] chan_sip.c: Header 12: Content-Length: 0 (17) [Jun 10 14:57:58] VERBOSE[3363] logger.c: Reliably Transmitting (no NAT) to 192.168.161.242:5060: OPTIONS sip:422@192.168.161.242:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK5a100c83;rport From: "asterisk" ;tag=as03d951a0 To: Contact: Call-ID: 69fe4f8a5af16f876cf3ce9351063ec8@pbx.example.net CSeq: 102 OPTIONS User-Agent: atCOM PBX Max-Forwards: 70 Date: Tue, 10 Jun 2008 12:57:58 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- [Jun 10 14:57:58] DEBUG[3363] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #0 [Jun 10 14:57:59] DEBUG[3363] chan_sip.c: Stopping retransmission on '49d7e6634c39a9a72e853bb836a128d3@pbx.example.net' of Request 102: Match Not Found [Jun 10 14:57:59] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:58:01] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:58:03] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:58:05] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:58:07] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:58:09] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:58:11] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:58:13] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:58:15] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:58:17] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:58:19] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:58:21] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:58:23] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:58:25] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:58:27] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:58:29] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:58:31] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:58:33] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:58:35] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:58:37] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:58:39] NOTICE[3363] chan_sip.c: Checking status change MWI for peer: 401 [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Jun 10 14:58:40] DEBUG[3363] acl.c: ##### Testing 192.168.161.250 with 192.168.161.0 [Jun 10 14:58:40] DEBUG[3363] acl.c: ##### Testing 192.168.161.250 with 192.168.200.0 [Jun 10 14:58:40] DEBUG[3363] acl.c: ##### Testing 192.168.161.250 with 192.168.1.0 [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 0: OPTIONS sip:401@192.168.161.250:5060 SIP/2.0 (44) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK47318e4b;rport (66) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 2: From: "asterisk" ;tag=as5e135a76 (62) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 3: To: (34) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 4: Contact: (39) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 5: Call-ID: 32a412116f071131195ffb500ca03ff7@pbx.example.net (57) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 7: User-Agent: atCOM PBX (21) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 8: Max-Forwards: 70 (16) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 9: Date: Tue, 10 Jun 2008 12:58:40 GMT (35) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 11: Supported: replaces (19) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 12: Content-Length: 0 (17) [Jun 10 14:58:40] VERBOSE[3363] logger.c: Reliably Transmitting (no NAT) to 192.168.161.250:5060: OPTIONS sip:401@192.168.161.250:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK47318e4b;rport From: "asterisk" ;tag=as5e135a76 To: Contact: Call-ID: 32a412116f071131195ffb500ca03ff7@pbx.example.net CSeq: 102 OPTIONS User-Agent: atCOM PBX Max-Forwards: 70 Date: Tue, 10 Jun 2008 12:58:40 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #0 [Jun 10 14:58:40] VERBOSE[3363] logger.c: <--- SIP read from 192.168.161.250:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK47318e4b;rport=5060 From: "asterisk" ;tag=as5e135a76 To: Call-ID: 32a412116f071131195ffb500ca03ff7@pbx.example.net CSeq: 102 OPTIONS Contact: ;flow-id=1 User-Agent: snom360/7.1.33 Accept-Language: en Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer, call-info Supported: timer, 100rel, replaces, from-change Content-Length: 0 <-------------> [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 0: SIP/2.0 200 OK (14) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK47318e4b;rport=5060 (71) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 2: From: "asterisk" ;tag=as5e135a76 (62) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 3: To: (34) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 4: Call-ID: 32a412116f071131195ffb500ca03ff7@pbx.example.net (57) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 5: CSeq: 102 OPTIONS (17) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 6: Contact: ;flow-id=1 (49) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 7: User-Agent: snom360/7.1.33 (26) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 8: Accept-Language: en (19) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 9: Accept: application/sdp (23) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 11: Allow-Events: talk, hold, refer, call-info (42) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 12: Supported: timer, 100rel, replaces, from-change (47) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 13: Content-Length: 0 (17) [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Header 14: (0) [Jun 10 14:58:40] VERBOSE[3363] logger.c: --- (14 headers 0 lines) --- [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: = Found Their Call ID: 32a412116f071131195ffb500ca03ff7@pbx.example.net Their Tag Our tag: as5e135a76 [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #289 [Jun 10 14:58:40] DEBUG[3363] chan_sip.c: Stopping retransmission on '32a412116f071131195ffb500ca03ff7@pbx.example.net' of Request 102: Match Not Found [Jun 10 14:58:40] VERBOSE[3363] logger.c: Really destroying SIP dialog '32a412116f071131195ffb500ca03ff7@pbx.example.net' Method: OPTIONS [Jun 10 14:58:41] NOTICE[3363] chan_sip.c: We don't have subscription for peer: 401 [Jun 10 14:58:42] DEBUG[3363] chan_sip.c: Auto destroying SIP dialog '3c26702775b0-f459rxlh8554' [Jun 10 14:58:42] DEBUG[3363] chan_sip.c: Destroying SIP dialog 3c26702775b0-f459rxlh8554 [Jun 10 14:58:42] VERBOSE[3363] logger.c: Really destroying SIP dialog '3c26702775b0-f459rxlh8554' Method: REGISTER [Jun 10 14:58:42] NOTICE[3363] chan_sip.c: We don't have subscription for peer: 401 [Jun 10 14:58:43] NOTICE[3363] chan_sip.c: We don't have subscription for peer: 401 [Jun 10 14:58:43] DEBUG[3363] chan_sip.c: Auto destroying SIP dialog '3c267014d2b7-fzuvlki6qcfr' [Jun 10 14:58:43] DEBUG[3363] chan_sip.c: Destroying SIP dialog 3c267014d2b7-fzuvlki6qcfr [Jun 10 14:58:43] VERBOSE[3363] logger.c: Really destroying SIP dialog '3c267014d2b7-fzuvlki6qcfr' Method: REGISTER [Jun 10 14:58:43] NOTICE[3363] chan_sip.c: We don't have subscription for peer: 401 [Jun 10 14:58:44] NOTICE[3363] chan_sip.c: We don't have subscription for peer: 401