[Feb 12 19:35:56] !! Unknown IE 49 (cs5, Unknown Information Element) [Feb 12 19:35:56] !! Unknown IE 50 (cs5, Unknown Information Element) [Feb 12 19:35:56] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for Zap/1 - state 2 (In use) [Feb 12 19:35:56] -- Accepting call from '344' to '89001' on channel 0/1, span 1 [Feb 12 19:35:56] DEBUG[23171]: chan_zap.c:1406 zt_enable_ec: No echo cancellation requested [Feb 12 19:35:56] DEBUG[23175]: app_queue.c:500 changethread: Device 'Zap/1' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Feb 12 19:35:56] DEBUG[23174]: pbx.c:1677 pbx_extension_helper: Launching 'Answer' [Feb 12 19:35:56] -- Executing Answer("Zap/1-1", "") in new stack [Feb 12 19:35:56] DEBUG[23167]: channel.c:771 channel_find_locked: Avoiding initial deadlock for 'Zap/1-1' [Feb 12 19:35:56] DEBUG[23174]: pbx.c:1677 pbx_extension_helper: Launching 'Macro' [Feb 12 19:35:56] -- Executing Macro("Zap/1-1", "chooselang") in new stack [Feb 12 19:35:56] DEBUG[23174]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '344' [Feb 12 19:35:56] DEBUG[23174]: pbx.c:1677 pbx_extension_helper: Launching 'Set' [Feb 12 19:35:56] -- Executing Set("Zap/1-1", "INTERNATIONALEVORWAHL=34") in new stack [Feb 12 19:35:56] DEBUG[23174]: pbx.c:1677 pbx_extension_helper: Launching 'NoOp' [Feb 12 19:35:56] -- Executing NoOp("Zap/1-1", "34") in new stack [Feb 12 19:35:56] DEBUG[23174]: pbx.c:1589 pbx_substitute_variables_helper_full: Expression result is '0' [Feb 12 19:35:56] DEBUG[23174]: pbx.c:1677 pbx_extension_helper: Launching 'GotoIf' [Feb 12 19:35:56] -- Executing GotoIf("Zap/1-1", "0?10|4") in new stack [Feb 12 19:35:56] DEBUG[23174]: pbx.c:6177 pbx_builtin_gotoif: Not taking any branch [Feb 12 19:35:56] DEBUG[23174]: pbx.c:1677 pbx_extension_helper: Launching 'Set' [Feb 12 19:35:56] -- Executing Set("Zap/1-1", "LANGUAGE()=de") in new stack [Feb 12 19:35:56] DEBUG[23174]: pbx.c:1677 pbx_extension_helper: Launching 'Set' [Feb 12 19:35:56] -- Executing Set("Zap/1-1", "__FROMQ=yes") in new stack [Feb 12 19:35:56] DEBUG[23174]: pbx.c:1677 pbx_extension_helper: Launching 'Queue' [Feb 12 19:35:56] -- Executing Queue("Zap/1-1", "ite|tT|||10") in new stack [Feb 12 19:35:56] DEBUG[23174]: app_queue.c:3068 queue_exec: NO QUEUE_PRIO variable found. Using default. [Feb 12 19:35:56] DEBUG[23174]: app_queue.c:3076 queue_exec: queue: ite, options: tT, url: , announce: , expires: 1171305366, priority: 0 [Feb 12 19:35:56] DEBUG[23174]: app_queue.c:1170 join_queue: Queue 'ite' Join, Channel 'Zap/1-1', Position '1' [Feb 12 19:35:56] -- Started music on hold, class 'queue_helpdesk', on Zap/1-1 [Feb 12 19:35:56] DEBUG[23174]: channel.c:1755 ast_settimeout: Scheduling timer at 160 sample intervals [Feb 12 19:35:56] DEBUG[23174]: app_queue.c:2020 is_our_turn: It's our turn (Zap/1-1). [Feb 12 19:35:56] DEBUG[23174]: app_queue.c:2215 try_calling: Zap/1-1 is trying to call a queue member. [Feb 12 19:35:56] DEBUG[23174]: app_queue.c:2237 try_calling: Queue with URL=_ [Feb 12 19:35:56] DEBUG[23174]: app_queue.c:2237 try_calling: Queue with URL=_ [Feb 12 19:35:56] DEBUG[23174]: app_queue.c:1632 ring_one: (Parallel) Trying 'Agent/88344' with metric 0 [Feb 12 19:35:56] DEBUG[23174]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-tenovis_in-89001-4. [Feb 12 19:35:56] DEBUG[23174]: channel.c:2897 ast_channel_inherit_variables: Copying hard-transferable variable FROMQ. [Feb 12 19:35:56] DEBUG[23174]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-tenovis_in-89001-3. [Feb 12 19:35:56] DEBUG[23174]: channel.c:2902 ast_channel_inherit_variables: Not copying variable MACRO_DEPTH. [Feb 12 19:35:56] DEBUG[23174]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-macro-chooselang-s-4. [Feb 12 19:35:56] DEBUG[23174]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-macro-chooselang-s-3. [Feb 12 19:35:56] DEBUG[23174]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-macro-chooselang-s-2. [Feb 12 19:35:56] DEBUG[23174]: channel.c:2902 ast_channel_inherit_variables: Not copying variable INTERNATIONALEVORWAHL. [Feb 12 19:35:56] DEBUG[23174]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-macro-chooselang-s-1. [Feb 12 19:35:56] DEBUG[23174]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-tenovis_in-89001-2. [Feb 12 19:35:56] DEBUG[23174]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-tenovis_in-89001-1. [Feb 12 19:35:56] DEBUG[23174]: channel.c:2902 ast_channel_inherit_variables: Not copying variable CALLEDTON. [Feb 12 19:35:56] DEBUG[23174]: channel.c:2902 ast_channel_inherit_variables: Not copying variable ANI2. [Feb 12 19:35:56] DEBUG[23174]: channel.c:2902 ast_channel_inherit_variables: Not copying variable TRANSFERCAPABILITY. [Feb 12 19:35:56] -- outgoing agentcall, to agent '88344', on 'Local/88344@sip_in-62a3,1' [Feb 12 19:35:56] DEBUG[23174]: channel.c:2897 ast_channel_inherit_variables: Copying hard-transferable variable FROMQ. [Feb 12 19:35:56] -- Called Agent/88344 [Feb 12 19:35:56] DEBUG[23174]: app_queue.c:1632 ring_one: (Parallel) Trying 'Agent/88906' with metric 0 [Feb 12 19:35:56] DEBUG[23176]: pbx.c:1677 pbx_extension_helper: Launching 'Set' [Feb 12 19:35:56] DEBUG[23174]: channel.c:2021 ast_read: Generator got voice, switching to phase locked mode [Feb 12 19:35:56] -- Executing Set("Local/88344@sip_in-62a3,2", "LANGUAGE()=de") in new stack [Feb 12 19:35:56] DEBUG[23174]: channel.c:1755 ast_settimeout: Scheduling timer at 0 sample intervals [Feb 12 19:35:56] DEBUG[23176]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '3' [Feb 12 19:35:56] DEBUG[23176]: pbx.c:1589 pbx_substitute_variables_helper_full: Expression result is '0' [Feb 12 19:35:56] DEBUG[23176]: pbx.c:1677 pbx_extension_helper: Launching 'GotoIf' [Feb 12 19:35:56] -- Executing GotoIf("Local/88344@sip_in-62a3,2", "0?10") in new stack [Feb 12 19:35:56] DEBUG[23176]: pbx.c:6177 pbx_builtin_gotoif: Not taking any branch [Feb 12 19:35:56] DEBUG[23176]: pbx.c:1677 pbx_extension_helper: Launching 'SIPAddHeader' [Feb 12 19:35:56] DEBUG[23174]: channel.c:2408 set_format: Set channel Zap/1-1 to write format slin [Feb 12 19:35:56] -- Executing SIPAddHeader("Local/88344@sip_in-62a3,2", ""Alert-Info: "") in new stack [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:13308 sip_addheader: SIP Header added ""Alert-Info: "" as _SIPADDHEADER01 [Feb 12 19:35:56] DEBUG[23176]: pbx.c:1677 pbx_extension_helper: Launching 'Dial' [Feb 12 19:35:56] DEBUG[23174]: res_musiconhold.c:235 ast_moh_files_next: Zap/1-1 Opened file 0 '/etc/asterisk/moh/queue_helpdesk/icarus4db' [Feb 12 19:35:56] -- Executing Dial("Local/88344@sip_in-62a3,2", "SIP/88344|310|tTowWhHm") in new stack [Feb 12 19:35:56] DEBUG[23167]: channel.c:771 channel_find_locked: Avoiding initial deadlock for 'Zap/1-1' [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:3183 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:1889 create_addr_from_peer: Setting NAT on RTP to 0 [Feb 12 19:35:56] DEBUG[23176]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-sip_in-88344-4. [Feb 12 19:35:56] DEBUG[23176]: channel.c:2889 ast_channel_inherit_variables: Copying soft-transferable variable SIPADDHEADER01. [Feb 12 19:35:56] DEBUG[23176]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-sip_in-88344-3. [Feb 12 19:35:56] DEBUG[23176]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-sip_in-88344-2. [Feb 12 19:35:56] DEBUG[23176]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-sip_in-88344-1. [Feb 12 19:35:56] DEBUG[23176]: channel.c:2897 ast_channel_inherit_variables: Copying hard-transferable variable FROMQ. [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:2089 sip_call: Outgoing Call for 88344 [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:2227 update_call_counter: Updating call counter for outgoing call [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:5128 transmit_invite: Adding SIP Header "Alert-Info" with content :: [Feb 12 19:35:56] We're at 10.1.10.72 port 16586 [Feb 12 19:35:56] Adding codec 0x8 (alaw) to SDP [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:3434 parse_request: Header 0: INVITE sip:88344@10.1.18.2:5060;line=6wijgpup SIP/2.0 (53) [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK4e60dc46;rport (61) [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:3434 parse_request: Header 2: From: "344" ;tag=as42cf2b76 (47) [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:3434 parse_request: Header 3: To: (44) [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:3434 parse_request: Header 4: Contact: (29) [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:3434 parse_request: Header 5: Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 (52) [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:3434 parse_request: Header 6: CSeq: 102 INVITE (16) [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:3434 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:3434 parse_request: Header 8: Max-Forwards: 70 (16) [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:3434 parse_request: Header 9: Date: Mon, 12 Feb 2007 18:35:56 GMT (35) [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:3434 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:3434 parse_request: Header 11: Alert-Info: (61) [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:3434 parse_request: Header 12: Content-Type: application/sdp (29) [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:3434 parse_request: Header 13: Content-Length: 156 (19) [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:3434 parse_request: Header 14: (0) [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:3466 parse_request: Line: v=0 (3) [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:3466 parse_request: Line: o=root 23162 23162 IN IP4 10.1.10.72 (36) [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:3466 parse_request: Line: s=session (9) [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:3466 parse_request: Line: c=IN IP4 10.1.10.72 (19) [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:3466 parse_request: Line: t=0 0 (5) [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:3466 parse_request: Line: m=audio 16586 RTP/AVP 8 (23) [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:3466 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:3466 parse_request: Line: a=silenceSupp:off - - - - (25) [Feb 12 19:35:56] 14 headers, 8 lines [Feb 12 19:35:56] Reliably Transmitting (no NAT) to 10.1.18.2:5060: INVITE sip:88344@10.1.18.2:5060;line=6wijgpup SIP/2.0 Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK4e60dc46;rport From: "344" ;tag=as42cf2b76 To: Contact: Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Mon, 12 Feb 2007 18:35:56 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Alert-Info: Content-Type: application/sdp Content-Length: 156 v=0 o=root 23162 23162 IN IP4 10.1.10.72 s=session c=IN IP4 10.1.10.72 t=0 0 m=audio 16586 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=silenceSupp:off - - - - --- [Feb 12 19:35:56] DEBUG[23176]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #47 [Feb 12 19:35:56] -- Called 88344 [Feb 12 19:35:56] DEBUG[23176]: channel.c:2213 ast_prod: Prodding channel 'Local/88344@sip_in-62a3,2' [Feb 12 19:35:56] DEBUG[23174]: app_queue.c:1953 wait_for_answer: Dunno what to do with control type 14 [Feb 12 19:35:56] -- Started music on hold, class 'default', on Local/88344@sip_in-62a3,2 [Feb 12 19:35:56] DEBUG[23176]: channel.c:1755 ast_settimeout: Scheduling timer at 160 sample intervals [Feb 12 19:35:56] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for Zap/1 - state 2 (In use) [Feb 12 19:35:56] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for Local/88344@sip_in - state 2 (In use) [Feb 12 19:35:56] DEBUG[23177]: app_queue.c:500 changethread: Device 'Zap/1' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Feb 12 19:35:56] DEBUG[23178]: app_queue.c:500 changethread: Device 'Local/88344@sip_in' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Feb 12 19:35:56] DEBUG[23174]: chan_zap.c:4712 my_zt_write: Write returned -1 (Resource temporarily unavailable) on channel 1 [Feb 12 19:35:56] DEBUG[23176]: res_musiconhold.c:235 ast_moh_files_next: Local/88344@sip_in-62a3,2 Opened file 0 '/etc/asterisk/moh/icarus4db' [Feb 12 19:35:56] <-- SIP read from 10.1.18.2:5060: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK4e60dc46;rport=5060 From: "344" ;tag=as42cf2b76 To: ;tag=3of76qsx41 Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 CSeq: 102 INVITE Contact: ;flow-id=1 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Content-Length: 0 [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK4e60dc46;rport=5060 (66) [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "344" ;tag=as42cf2b76 (47) [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: ;tag=3of76qsx41 (59) [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 (52) [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 102 INVITE (16) [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Contact: ;flow-id=1 (59) [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: Allow-Events: talk, hold, refer (31) [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: Content-Length: 0 (17) [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: (0) [Feb 12 19:35:56] --- (10 headers 0 lines) --- [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:1459 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #47 - INVITE (got response) [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:1468 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '7926766d420cfe483e732a6d4ed595c9@10.1.10.72' Request 102: Found [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:9756 handle_response_invite: SIP response 180 to standard invite [Feb 12 19:35:56] -- SIP/88344-081ec490 is ringing [Feb 12 19:35:56] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88344 [Feb 12 19:35:56] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for SIP/88344 - state 6 (Ringing) [Feb 12 19:35:56] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88344 [Feb 12 19:35:56] DEBUG[23179]: app_queue.c:500 changethread: Device 'SIP/88344' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Feb 12 19:35:56] <-- SIP read from 10.1.18.2:5060: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK4e60dc46;rport=5060 From: "344" ;tag=as42cf2b76 To: ;tag=3of76qsx41 Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 CSeq: 102 INVITE Contact: ;flow-id=1 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Content-Length: 0 [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK4e60dc46;rport=5060 (66) [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "344" ;tag=as42cf2b76 (47) [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: ;tag=3of76qsx41 (59) [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 (52) [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 102 INVITE (16) [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Contact: ;flow-id=1 (59) [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: Allow-Events: talk, hold, refer (31) [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: Content-Length: 0 (17) [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: (0) [Feb 12 19:35:56] --- (10 headers 0 lines) --- [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:1468 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '7926766d420cfe483e732a6d4ed595c9@10.1.10.72' Request 102: Found [Feb 12 19:35:56] DEBUG[23169]: chan_sip.c:9756 handle_response_invite: SIP response 180 to standard invite [Feb 12 19:35:56] -- SIP/88344-081ec490 is ringing [Feb 12 19:35:57] <-- SIP read from 10.1.18.2:5060: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK4e60dc46;rport=5060 From: "344" ;tag=as42cf2b76 To: ;tag=3of76qsx41 Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 CSeq: 102 INVITE Contact: ;flow-id=1 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Content-Length: 0 [Feb 12 19:35:57] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Feb 12 19:35:57] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK4e60dc46;rport=5060 (66) [Feb 12 19:35:57] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "344" ;tag=as42cf2b76 (47) [Feb 12 19:35:57] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: ;tag=3of76qsx41 (59) [Feb 12 19:35:57] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 (52) [Feb 12 19:35:57] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 102 INVITE (16) [Feb 12 19:35:57] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Contact: ;flow-id=1 (59) [Feb 12 19:35:57] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Feb 12 19:35:57] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: Allow-Events: talk, hold, refer (31) [Feb 12 19:35:57] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: Content-Length: 0 (17) [Feb 12 19:35:57] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: (0) [Feb 12 19:35:57] --- (10 headers 0 lines) --- [Feb 12 19:35:57] DEBUG[23169]: chan_sip.c:1468 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '7926766d420cfe483e732a6d4ed595c9@10.1.10.72' Request 102: Found [Feb 12 19:35:57] DEBUG[23169]: chan_sip.c:9756 handle_response_invite: SIP response 180 to standard invite [Feb 12 19:35:57] -- SIP/88344-081ec490 is ringing [Feb 12 19:35:58] DEBUG[23176]: rtp.c:411 ast_rtcp_read: Got RTCP report of 52 bytes [Feb 12 19:35:58] <-- SIP read from 10.1.18.2:5060: SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK4e60dc46;rport=5060 From: "344" ;tag=as42cf2b76 To: ;tag=3of76qsx41 Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 CSeq: 102 INVITE Contact: ;flow-id=1 User-Agent: snom360/6.5.2 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Content-Type: application/sdp Content-Length: 144 v=0 o=root 660656425 660656426 IN IP4 10.1.18.2 s=call c=IN IP4 10.1.18.2 t=0 0 m=audio 56886 RTP/AVP 8 a=rtpmap:8 pcma/8000 a=sendrecv [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: SIP/2.0 200 Ok (14) [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK4e60dc46;rport=5060 (66) [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "344" ;tag=as42cf2b76 (47) [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: ;tag=3of76qsx41 (59) [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 (52) [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 102 INVITE (16) [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Contact: ;flow-id=1 (59) [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: User-Agent: snom360/6.5.2 (25) [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: Allow-Events: talk, hold, refer (31) [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: Supported: timer, 100rel, replaces, callerid (44) [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 11: Content-Type: application/sdp (29) [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 12: Content-Length: 144 (19) [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 13: (0) [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: v=0 (3) [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: o=root 660656425 660656426 IN IP4 10.1.18.2 (43) [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: s=call (6) [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: c=IN IP4 10.1.18.2 (18) [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: t=0 0 (5) [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: m=audio 56886 RTP/AVP 8 (23) [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: a=rtpmap:8 pcma/8000 (20) [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: a=sendrecv (10) [Feb 12 19:35:58] --- (13 headers 8 lines) --- [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:1392 __sip_ack: Acked pending invite 102 [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:1415 __sip_ack: Stopping retransmission on '7926766d420cfe483e732a6d4ed595c9@10.1.10.72' of Request 102: Match Found [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:9756 handle_response_invite: SIP response 200 to standard invite [Feb 12 19:35:58] Found RTP audio format 8 [Feb 12 19:35:58] Peer audio RTP is at port 10.1.18.2:56886 [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:3675 process_sdp: Peer audio RTP is at port 10.1.18.2:56886 [Feb 12 19:35:58] Found description format pcma [Feb 12 19:35:58] Capabilities: us - 0x8 (alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) [Feb 12 19:35:58] Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) [Feb 12 19:35:58] DEBUG[23169]: chan_sip.c:6276 build_route: build_route: Contact hop: ;flow-id=1 [Feb 12 19:35:58] list_route: hop: [Feb 12 19:35:58] set_destination: Parsing for address/port to send to [Feb 12 19:35:58] set_destination: set destination to 10.1.18.2, port 5060 [Feb 12 19:35:58] Transmitting (no NAT) to 10.1.18.2:5060: ACK sip:88344@10.1.18.2:5060;line=6wijgpup SIP/2.0 Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK2cbd1ed0;rport From: "344" ;tag=as42cf2b76 To: ;tag=3of76qsx41 Contact: Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Feb 12 19:35:58] -- SIP/88344-081ec490 answered Local/88344@sip_in-62a3,2 [Feb 12 19:35:58] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88344 [Feb 12 19:35:58] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for SIP/88344 - state 2 (In use) [Feb 12 19:35:58] -- Stopped music on hold on Local/88344@sip_in-62a3,2 [Feb 12 19:35:58] DEBUG[23180]: app_queue.c:500 changethread: Device 'SIP/88344' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Feb 12 19:35:58] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88344 [Feb 12 19:35:58] DEBUG[23176]: channel.c:1755 ast_settimeout: Scheduling timer at 0 sample intervals [Feb 12 19:35:58] DEBUG[23176]: channel.c:2408 set_format: Set channel SIP/88344-081ec490 to write format slin [Feb 12 19:35:58] DEBUG[23176]: channel.c:2408 set_format: Set channel SIP/88344-081ec490 to read format slin [Feb 12 19:35:58] -- Agent/88344 answered Zap/1-1 [Feb 12 19:35:58] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for Local/88344@sip_in - state 2 (In use) [Feb 12 19:35:58] DEBUG[23181]: app_queue.c:500 changethread: Device 'Local/88344@sip_in' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Feb 12 19:35:58] DEBUG[23174]: chan_zap.c:2764 zt_setoption: Set option TONE VERIFY, mode: MUTECONF(1) on Zap/1-1 [Feb 12 19:35:58] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for Local/88344@sip_in - state 2 (In use) [Feb 12 19:35:58] DEBUG[23167]: devicestate.c:187 do_state_change: [Feb 12 19:35:58] -- Stopped music on hold on Zap/1-1 Changing state for Agent/88344 - state 3 (Busy) [Feb 12 19:35:58] DEBUG[23183]: app_queue.c:506 changethread: Device 'Agent/88344' changed to state '3' (Busy) [Feb 12 19:35:58] DEBUG[23174]: channel.c:2408 set_format: Set channel Zap/1-1 to write format alaw [Feb 12 19:35:58] DEBUG[23174]: channel.c:1755 ast_settimeout: Scheduling timer at 0 sample intervals [Feb 12 19:35:58] DEBUG[23182]: app_queue.c:500 changethread: Device 'Local/88344@sip_in' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Feb 12 19:35:58] DEBUG[23174]: channel.c:2408 set_format: Set channel Zap/1-1 to read format slin [Feb 12 19:35:58] DEBUG[23174]: channel.c:2408 set_format: Set channel Zap/1-1 to write format slin [Feb 12 19:35:58] DEBUG[23176]: rtp.c:1361 ast_rtp_write: Ooh, format changed from unknown to alaw [Feb 12 19:35:58] DEBUG[23176]: chan_sip.c:3043 sip_rtp_read: Oooh, format changed to 4 [Feb 12 19:35:58] DEBUG[23176]: channel.c:2408 set_format: Set channel SIP/88344-081ec490 to read format slin [Feb 12 19:35:58] DEBUG[23176]: channel.c:2408 set_format: Set channel SIP/88344-081ec490 to write format slin [Feb 12 19:35:58] DEBUG[23176]: channel.c:2834 ast_channel_masquerade: Planning to masquerade channel SIP/88344-081ec490 into the structure of Local/88344@sip_in-62a3,1 [Feb 12 19:35:58] DEBUG[23176]: channel.c:2847 ast_channel_masquerade: Done planning to masquerade channel SIP/88344-081ec490 into the structure of Local/88344@sip_in-62a3,1 [Feb 12 19:35:58] DEBUG[23176]: chan_local.c:262 local_write: Not posting to queue since already masked on 'Local/88344@sip_in-62a3,2' [Feb 12 19:35:58] DEBUG[23174]: channel.c:2961 ast_do_masquerade: Actually Masquerading SIP/88344-081ec490(6) into the structure of Local/88344@sip_in-62a3,1(6) [Feb 12 19:35:58] DEBUG[23174]: channel.c:2972 ast_do_masquerade: Got clone lock for masquerade on 'SIP/88344-081ec490' at 0x81f1a9c [Feb 12 19:35:58] DEBUG[23174]: channel.c:2408 set_format: Set channel SIP/88344-081ec490 to write format slin [Feb 12 19:35:58] DEBUG[23176]: channel.c:3380 ast_generic_bridge: Didn't get a frame from channel: Local/88344@sip_in-62a3,2 [Feb 12 19:35:58] DEBUG[23176]: channel.c:3669 ast_channel_bridge: Bridge stops bridging channels Local/88344@sip_in-62a3,2 and Local/88344@sip_in-62a3,1 [Feb 12 19:35:58] DEBUG[23174]: channel.c:2408 set_format: Set channel SIP/88344-081ec490 to read format slin [Feb 12 19:35:58] DEBUG[23174]: channel.c:3154 ast_do_masquerade: Putting channel SIP/88344-081ec490 in 64/64 formats [Feb 12 19:35:58] DEBUG[23174]: channel.c:3189 ast_do_masquerade: Released clone lock on 'Local/88344@sip_in-62a3,1' [Feb 12 19:35:58] DEBUG[23174]: channel.c:3198 ast_do_masquerade: Done Masquerading SIP/88344-081ec490 (6) [Feb 12 19:35:58] DEBUG[23176]: channel.c:1372 ast_hangup: Hanging up zombie 'Local/88344@sip_in-62a3,1' [Feb 12 19:35:58] DEBUG[23176]: app_dial.c:1636 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Feb 12 19:35:58] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for Local/88344@sip_in - state 2 (In use) [Feb 12 19:35:58] DEBUG[23176]: pbx.c:2316 __ast_pbx_run: Spawn extension (sip_in,88344,4) exited non-zero on 'Local/88344@sip_in-62a3,2' [Feb 12 19:35:58] DEBUG[23184]: app_queue.c:500 changethread: [Feb 12 19:35:58] == Spawn extension (sip_in, 88344, 4) exited non-zero on 'Local/88344@sip_in-62a3,2' Device 'Local/88344@sip_in' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Feb 12 19:35:58] DEBUG[23174]: chan_agent.c:547 agent_read: Bridge on 'SIP/88344-081ec490' being set to 'Agent/88344' (3) [Feb 12 19:35:58] DEBUG[23176]: channel.c:1367 ast_hangup: Hanging up channel 'Local/88344@sip_in-62a3,2' [Feb 12 19:35:58] DEBUG[23174]: chan_agent.c:470 agent_read: Native formats changing from 64 to 4 [Feb 12 19:35:58] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for Local/88344@sip_in - state 0 (Unknown) [Feb 12 19:35:58] DEBUG[23185]: app_queue.c:500 changethread: Device 'Local/88344@sip_in' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. [Feb 12 19:35:58] DEBUG[23174]: chan_agent.c:470 agent_read: Resetting read to 64 and write to 64 [Feb 12 19:35:58] DEBUG[23174]: channel.c:2408 set_format: Set channel Agent/88344 to read format slin [Feb 12 19:35:58] DEBUG[23174]: channel.c:2408 set_format: Set channel Agent/88344 to write format slin [Feb 12 19:35:58] DEBUG[23174]: channel.c:2408 set_format: Set channel SIP/88344-081ec490 to read format ulaw [Feb 12 19:35:58] DEBUG[23174]: channel.c:2408 set_format: Set channel SIP/88344-081ec490 to write format ulaw [Feb 12 19:35:58] DEBUG[23174]: rtp.c:1361 ast_rtp_write: Ooh, format changed from alaw to ulaw [Feb 12 19:35:58] DEBUG[23174]: chan_sip.c:3043 sip_rtp_read: Oooh, format changed to 8 [Feb 12 19:35:58] DEBUG[23174]: channel.c:2408 set_format: Set channel SIP/88344-081ec490 to read format ulaw [Feb 12 19:35:58] DEBUG[23174]: channel.c:2408 set_format: Set channel SIP/88344-081ec490 to write format ulaw [Feb 12 19:35:58] DEBUG[23174]: chan_agent.c:582 agent_write: Native formats changing from 4 to 8 [Feb 12 19:35:58] DEBUG[23174]: chan_agent.c:582 agent_write: Resetting read to 64 and write to 64 [Feb 12 19:35:58] DEBUG[23174]: channel.c:2408 set_format: Set channel Agent/88344 to read format slin [Feb 12 19:35:58] DEBUG[23174]: channel.c:2408 set_format: Set channel Agent/88344 to write format slin [Feb 12 19:35:58] DEBUG[23174]: channel.c:2408 set_format: Set channel SIP/88344-081ec490 to read format alaw [Feb 12 19:35:58] DEBUG[23174]: channel.c:2408 set_format: Set channel SIP/88344-081ec490 to write format alaw [Feb 12 19:35:58] DEBUG[23174]: chan_agent.c:589 agent_write: Dropping one incompatible voice frame on 'Agent/88344' to 'SIP/88344-081ec490' [Feb 12 19:35:58] DEBUG[23174]: channel.c:2408 set_format: Set channel Zap/1-1 to read format alaw [Feb 12 19:35:58] DEBUG[23174]: channel.c:2408 set_format: Set channel Agent/88344 to write format alaw [Feb 12 19:35:58] DEBUG[23174]: channel.c:2408 set_format: Set channel Agent/88344 to read format alaw [Feb 12 19:35:58] DEBUG[23174]: channel.c:2408 set_format: Set channel Zap/1-1 to write format alaw [Feb 12 19:35:58] DEBUG[23174]: rtp.c:1361 ast_rtp_write: Ooh, format changed from ulaw to alaw [Feb 12 19:35:59] <-- SIP read from 10.1.18.1:5060: REGISTER sip:10.1.10.72 SIP/2.0 Via: SIP/2.0/UDP 10.1.18.1:5060;branch=z9hG4bK-6zoeod9kcj12;rport From: "Matthias Morsbach" ;tag=nvcv4gvdjp To: "Matthias Morsbach" Call-ID: 3c26700a222e-4s1fp3v93f07@snom360-0004132346B8 CSeq: 706 REGISTER Max-Forwards: 70 Contact: ;flow-id=1;q=1.0;+sip.instance="";audio;mobility="fixed";duplex="full";description="snom360";actor="principal";events="dialog";methods="INVITE,ACK,CANCEL,BYE,REFER,OPTIONS,NOTIFY,SUBSCRIBE,PRACK,MESSAGE,INFO" User-Agent: snom360/6.5.2 Supported: gruu Allow-Events: dialog X-Real-IP: 10.1.18.1 WWW-Contact: WWW-Contact: Expires: 3600 Content-Length: 0 [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: REGISTER sip:10.1.10.72 SIP/2.0 (31) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.18.1:5060;branch=z9hG4bK-6zoeod9kcj12;rport (65) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "Matthias Morsbach" ;tag=nvcv4gvdjp (63) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: "Matthias Morsbach" (46) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 3c26700a222e-4s1fp3v93f07@snom360-0004132346B8 (55) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 706 REGISTER (18) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Max-Forwards: 70 (16) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: Contact: ;flow-id=1;q=1.0;+sip.instance="";audio;mobility="fixed";duplex="full";description="snom360";actor="principal";events="dialog";methods="INVITE,ACK,CANCEL,BYE,REFER,OPTIONS,NOTIFY,SUBSCRIBE,PRACK,MESSAGE,INFO" (304) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: User-Agent: snom360/6.5.2 (25) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: Supported: gruu (15) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: Allow-Events: dialog (20) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 11: X-Real-IP: 10.1.18.1 (20) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 12: WWW-Contact: (34) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 13: WWW-Contact: (36) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 14: Expires: 3600 (13) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 15: Content-Length: 0 (17) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 16: (0) [Feb 12 19:35:59] --- (16 headers 0 lines) --- [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3183 sip_alloc: Allocating new SIP dialog for 3c26700a222e-4s1fp3v93f07@snom360-0004132346B8 - REGISTER (No RTP) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:11377 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER [Feb 12 19:35:59] Using latest REGISTER request as basis request [Feb 12 19:35:59] Sending to 10.1.18.1 : 5060 (NAT) [Feb 12 19:35:59] Transmitting (no NAT) to 10.1.18.1:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.1.18.1:5060;branch=z9hG4bK-6zoeod9kcj12;received=10.1.18.1;rport=5060 From: "Matthias Morsbach" ;tag=nvcv4gvdjp To: "Matthias Morsbach" Call-ID: 3c26700a222e-4s1fp3v93f07@snom360-0004132346B8 CSeq: 706 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- [Feb 12 19:35:59] -- Saved useragent "snom360/6.5.2" for peer 88254 [Feb 12 19:35:59] Transmitting (no NAT) to 10.1.18.1:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.1.18.1:5060;branch=z9hG4bK-6zoeod9kcj12;received=10.1.18.1;rport=5060 From: "Matthias Morsbach" ;tag=nvcv4gvdjp To: "Matthias Morsbach" ;tag=as5eb0f4ab Call-ID: 3c26700a222e-4s1fp3v93f07@snom360-0004132346B8 CSeq: 706 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Expires: 60 Contact: ;expires=60 Date: Mon, 12 Feb 2007 18:35:59 GMT Content-Length: 0 --- [Feb 12 19:35:59] Scheduling destruction of call '3c26700a222e-4s1fp3v93f07@snom360-0004132346B8' in 15000 ms [Feb 12 19:35:59] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88254 [Feb 12 19:35:59] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for SIP/88254 - state 1 (Not in use) [Feb 12 19:35:59] DEBUG[23186]: app_queue.c:500 changethread: Device 'SIP/88254' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 12 19:35:59] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88254 [Feb 12 19:35:59] <-- SIP read from 10.1.18.2:5060: REGISTER sip:10.1.10.72 SIP/2.0 Via: SIP/2.0/UDP 10.1.18.2:5060;branch=z9hG4bK-atub6awvaot1;rport From: "Thomas Gick" ;tag=8vf461dkt2 To: "Thomas Gick" Call-ID: 3c26700a0c35-ftsl5idl4l5i@snom360-000413232807 CSeq: 706 REGISTER Max-Forwards: 70 Contact: ;flow-id=1;q=1.0;+sip.instance="";audio;mobility="fixed";duplex="full";description="snom360";actor="principal";events="dialog";methods="INVITE,ACK,CANCEL,BYE,REFER,OPTIONS,NOTIFY,SUBSCRIBE,PRACK,MESSAGE,INFO" User-Agent: snom360/6.5.2 Supported: gruu Allow-Events: dialog X-Real-IP: 10.1.18.2 WWW-Contact: WWW-Contact: Expires: 3600 Content-Length: 0 [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: REGISTER sip:10.1.10.72 SIP/2.0 (31) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.18.2:5060;branch=z9hG4bK-atub6awvaot1;rport (65) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "Thomas Gick" ;tag=8vf461dkt2 (57) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: "Thomas Gick" (40) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 3c26700a0c35-ftsl5idl4l5i@snom360-000413232807 (55) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 706 REGISTER (18) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Max-Forwards: 70 (16) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: Contact: ;flow-id=1;q=1.0;+sip.instance="";audio;mobility="fixed";duplex="full";description="snom360";actor="principal";events="dialog";methods="INVITE,ACK,CANCEL,BYE,REFER,OPTIONS,NOTIFY,SUBSCRIBE,PRACK,MESSAGE,INFO" (304) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: User-Agent: snom360/6.5.2 (25) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: Supported: gruu (15) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: Allow-Events: dialog (20) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 11: X-Real-IP: 10.1.18.2 (20) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 12: WWW-Contact: (34) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 13: WWW-Contact: (36) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 14: Expires: 3600 (13) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 15: Content-Length: 0 (17) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 16: (0) [Feb 12 19:35:59] --- (16 headers 0 lines) --- [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:3183 sip_alloc: Allocating new SIP dialog for 3c26700a0c35-ftsl5idl4l5i@snom360-000413232807 - REGISTER (No RTP) [Feb 12 19:35:59] DEBUG[23169]: chan_sip.c:11377 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER [Feb 12 19:35:59] Using latest REGISTER request as basis request [Feb 12 19:35:59] Sending to 10.1.18.2 : 5060 (NAT) [Feb 12 19:35:59] Transmitting (no NAT) to 10.1.18.2:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.1.18.2:5060;branch=z9hG4bK-atub6awvaot1;received=10.1.18.2;rport=5060 From: "Thomas Gick" ;tag=8vf461dkt2 To: "Thomas Gick" Call-ID: 3c26700a0c35-ftsl5idl4l5i@snom360-000413232807 CSeq: 706 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- [Feb 12 19:35:59] -- Saved useragent "snom360/6.5.2" for peer 88344 [Feb 12 19:35:59] Transmitting (no NAT) to 10.1.18.2:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.1.18.2:5060;branch=z9hG4bK-atub6awvaot1;received=10.1.18.2;rport=5060 From: "Thomas Gick" ;tag=8vf461dkt2 To: "Thomas Gick" ;tag=as7b0f32a5 Call-ID: 3c26700a0c35-ftsl5idl4l5i@snom360-000413232807 CSeq: 706 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Expires: 60 Contact: ;expires=60 Date: Mon, 12 Feb 2007 18:35:59 GMT Content-Length: 0 --- [Feb 12 19:35:59] Scheduling destruction of call '3c26700a0c35-ftsl5idl4l5i@snom360-000413232807' in 15000 ms [Feb 12 19:35:59] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88344 [Feb 12 19:35:59] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for SIP/88344 - state 2 (In use) [Feb 12 19:35:59] DEBUG[23187]: app_queue.c:500 changethread: Device 'SIP/88344' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Feb 12 19:35:59] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88344 [Feb 12 19:36:00] <-- SIP read from 10.1.18.2:5060: INVITE sip:344@10.1.10.72 SIP/2.0 Via: SIP/2.0/UDP 10.1.18.2:5060;branch=z9hG4bK-oh39x87rlmmr;rport From: ;tag=3of76qsx41 To: "344" ;tag=as42cf2b76 Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 CSeq: 1 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: resolution="31x13", keys="4" User-Agent: snom360/6.5.2 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Session-Expires: 3600;refresher=uas Min-SE: 90 Content-Type: application/sdp Content-Length: 302 v=0 o=root 660656425 660656427 IN IP4 10.1.18.2 s=call c=IN IP4 0.0.0.0 t=0 0 m=audio 56886 RTP/AVP 8 0 9 2 3 18 4 a=rtpmap:8 pcma/8000 a=rtpmap:0 pcmu/8000 a=rtpmap:9 g722/8000 a=rtpmap:2 g726-32/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=ptime:10 a=sendonly [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: INVITE sip:344@10.1.10.72 SIP/2.0 (33) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.18.2:5060;branch=z9hG4bK-oh39x87rlmmr;rport (65) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: ;tag=3of76qsx41 (61) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: "344" ;tag=as42cf2b76 (45) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 (52) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 1 INVITE (14) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Max-Forwards: 70 (16) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: Contact: ;flow-id=1 (59) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: P-Key-Flags: resolution="31x13", keys="4" (41) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: User-Agent: snom360/6.5.2 (25) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: Accept: application/sdp (23) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 12: Allow-Events: talk, hold, refer (31) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 13: Supported: timer, 100rel, replaces, callerid (44) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 14: Session-Expires: 3600;refresher=uas (35) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 15: Min-SE: 90 (10) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 16: Content-Type: application/sdp (29) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 17: Content-Length: 302 (19) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 18: (0) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: v=0 (3) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: o=root 660656425 660656427 IN IP4 10.1.18.2 (43) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: s=call (6) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: c=IN IP4 0.0.0.0 (16) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: t=0 0 (5) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: m=audio 56886 RTP/AVP 8 0 9 2 3 18 4 (36) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: a=rtpmap:8 pcma/8000 (20) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: a=rtpmap:0 pcmu/8000 (20) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: a=rtpmap:9 g722/8000 (20) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: a=rtpmap:3 gsm/8000 (19) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: a=rtpmap:18 g729/8000 (21) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: a=rtpmap:4 g723/8000 (20) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: a=ptime:10 (10) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: a=sendonly (10) [Feb 12 19:36:00] --- (18 headers 15 lines) --- [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:11377 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:1015 parse_sip_options: Begin: parsing SIP "Supported: timer, 100rel, replaces, callerid" [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:1027 parse_sip_options: Found SIP option: -timer- [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:1033 parse_sip_options: Matched SIP option: timer [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:1027 parse_sip_options: Found SIP option: -100rel- [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:1033 parse_sip_options: Matched SIP option: 100rel [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:1027 parse_sip_options: Found SIP option: -replaces- [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:1033 parse_sip_options: Matched SIP option: replaces [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:1027 parse_sip_options: Found SIP option: -callerid- [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:1038 parse_sip_options: Found no match for SIP option: callerid (Please file bug report!) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:1044 parse_sip_options: * SIP extension value: 7 for call 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 [Feb 12 19:36:00] Using INVITE request as basis request - 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 [Feb 12 19:36:00] Sending to 10.1.18.2 : 5060 (NAT) [Feb 12 19:36:00] Found RTP audio format 8 [Feb 12 19:36:00] Found RTP audio format 0 [Feb 12 19:36:00] Found RTP audio format 9 [Feb 12 19:36:00] Found RTP audio format 2 [Feb 12 19:36:00] Found RTP audio format 3 [Feb 12 19:36:00] Found RTP audio format 18 [Feb 12 19:36:00] Found RTP audio format 4 [Feb 12 19:36:00] Peer audio RTP is at port 0.0.0.0:56886 [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3675 process_sdp: Peer audio RTP is at port 0.0.0.0:56886 [Feb 12 19:36:00] Found description format pcma [Feb 12 19:36:00] Found description format pcmu [Feb 12 19:36:00] Found description format g722 [Feb 12 19:36:00] Found description format g726-32 [Feb 12 19:36:00] Found description format gsm [Feb 12 19:36:00] Found description format g729 [Feb 12 19:36:00] Found description format g723 [Feb 12 19:36:00] Capabilities: us - 0x8 (alaw), peer - audio=0x11f (g723|gsm|ulaw|alaw|g726|g729)/video=0x0 (nothing), combined - 0x8 (alaw) [Feb 12 19:36:00] Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) [Feb 12 19:36:00] DEBUG[23169]: chan_agent.c:920 agent_bridgedchannel: Asked for bridged channel on 'SIP/88344-081ec490'/'Agent/88344', returning 'Zap/1-1' [Feb 12 19:36:00] -- Started music on hold, class 'default', on Zap/1-1 [Feb 12 19:36:00] DEBUG[23169]: channel.c:1755 ast_settimeout: Scheduling timer at 160 sample intervals [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:10785 handle_request_invite: Got a SIP re-invite for call 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 [Feb 12 19:36:00] We're at 10.1.10.72 port 16586 [Feb 12 19:36:00] Adding codec 0x8 (alaw) to SDP [Feb 12 19:36:00] Reliably Transmitting (NAT) to 10.1.18.2:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.1.18.2:5060;branch=z9hG4bK-oh39x87rlmmr;received=10.1.18.2;rport=5060 From: ;tag=3of76qsx41 To: "344" ;tag=as42cf2b76 Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 156 v=0 o=root 23162 23163 IN IP4 10.1.10.72 s=session c=IN IP4 10.1.10.72 t=0 0 m=audio 16586 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=silenceSupp:off - - - - --- [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #52 [Feb 12 19:36:00] DEBUG[23174]: channel.c:2021 ast_read: Generator got voice, switching to phase locked mode [Feb 12 19:36:00] DEBUG[23174]: channel.c:1755 ast_settimeout: Scheduling timer at 0 sample intervals [Feb 12 19:36:00] DEBUG[23174]: channel.c:2408 set_format: Set channel Zap/1-1 to write format slin [Feb 12 19:36:00] DEBUG[23174]: res_musiconhold.c:235 ast_moh_files_next: Zap/1-1 Opened file 1 '/etc/asterisk/moh/ww4db' [Feb 12 19:36:00] <-- SIP read from 10.1.18.2:5060: ACK sip:344@10.1.10.72 SIP/2.0 Via: SIP/2.0/UDP 10.1.18.2:5060;branch=z9hG4bK-gj7ar0bcwvje;rport From: ;tag=3of76qsx41 To: "344" ;tag=as42cf2b76 Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 CSeq: 1 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: ACK sip:344@10.1.10.72 SIP/2.0 (30) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.18.2:5060;branch=z9hG4bK-gj7ar0bcwvje;rport (65) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: ;tag=3of76qsx41 (61) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: "344" ;tag=as42cf2b76 (45) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 (52) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 1 ACK (11) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Max-Forwards: 70 (16) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: Contact: ;flow-id=1 (59) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: Content-Length: 0 (17) [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: (0) [Feb 12 19:36:00] --- (9 headers 0 lines) --- [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:11377 handle_request: **** Received ACK (6) - Command in SIP ACK [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:1403 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #52 [Feb 12 19:36:00] DEBUG[23169]: chan_sip.c:1415 __sip_ack: Stopping retransmission on '7926766d420cfe483e732a6d4ed595c9@10.1.10.72' of Response 1: Match Found [Feb 12 19:36:01] -- Remote UNIX connection [Feb 12 19:36:01] -- Remote UNIX connection disconnected [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3183 sip_alloc: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: NOTIFY sip:88254@10.1.18.1:5060;line=baskt6xr SIP/2.0 (53) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK786a1a4a;rport (61) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "asterisk" ;tag=as3eae2d39 (57) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: (44) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Contact: (34) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: Call-ID: 441f91a07c34e6b214f83aa305c195dd@10.1.10.72 (52) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: CSeq: 102 NOTIFY (16) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: Max-Forwards: 70 (16) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: Event: message-summary (22) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: Content-Type: application/simple-message-summary (48) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 11: Content-Length: 91 (18) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 12: (0) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Messages-Waiting: no (20) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Message-Account: sip:voicemail@10.1.10.72 (41) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Voice-Message: 0/0 (0/0) (24) [Feb 12 19:36:02] 12 headers, 3 lines [Feb 12 19:36:02] Reliably Transmitting (no NAT) to 10.1.18.1:5060: NOTIFY sip:88254@10.1.18.1:5060;line=baskt6xr SIP/2.0 Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK786a1a4a;rport From: "asterisk" ;tag=as3eae2d39 To: Contact: Call-ID: 441f91a07c34e6b214f83aa305c195dd@10.1.10.72 CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: message-summary Content-Type: application/simple-message-summary Content-Length: 91 Messages-Waiting: no Message-Account: sip:voicemail@10.1.10.72 Voice-Message: 0/0 (0/0) --- [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #53 [Feb 12 19:36:02] Scheduling destruction of call '441f91a07c34e6b214f83aa305c195dd@10.1.10.72' in 15000 ms [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3183 sip_alloc: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: NOTIFY sip:88344@10.1.18.2:5060;line=6wijgpup SIP/2.0 (53) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK31ec59de;rport (61) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "asterisk" ;tag=as16f87086 (57) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: (44) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Contact: (34) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: Call-ID: 2eaecf487f3a619759d2941a783272ea@10.1.10.72 (52) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: CSeq: 102 NOTIFY (16) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: Max-Forwards: 70 (16) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: Event: message-summary (22) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: Content-Type: application/simple-message-summary (48) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 11: Content-Length: 91 (18) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 12: (0) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Messages-Waiting: no (20) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Message-Account: sip:voicemail@10.1.10.72 (41) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Voice-Message: 0/5 (0/0) (24) [Feb 12 19:36:02] 12 headers, 3 lines [Feb 12 19:36:02] Reliably Transmitting (no NAT) to 10.1.18.2:5060: NOTIFY sip:88344@10.1.18.2:5060;line=6wijgpup SIP/2.0 Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK31ec59de;rport From: "asterisk" ;tag=as16f87086 To: Contact: Call-ID: 2eaecf487f3a619759d2941a783272ea@10.1.10.72 CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: message-summary Content-Type: application/simple-message-summary Content-Length: 91 Messages-Waiting: no Message-Account: sip:voicemail@10.1.10.72 Voice-Message: 0/5 (0/0) --- [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #55 [Feb 12 19:36:02] Scheduling destruction of call '2eaecf487f3a619759d2941a783272ea@10.1.10.72' in 15000 ms [Feb 12 19:36:02] <-- SIP read from 10.1.18.9:5060: REGISTER sip:10.1.10.72 SIP/2.0 Via: SIP/2.0/UDP 10.1.18.9:5060;branch=z9hG4bK-nx0pfp1lqt92;rport From: "Cenan Izejroski" ;tag=xa6phg962z To: "Cenan Izejroski" Call-ID: 3c26700a0000-x4kkws5ejsgn@snom360-000413237C3A CSeq: 707 REGISTER Max-Forwards: 70 Contact: ;flow-id=1;q=1.0;+sip.instance="";audio;mobility="fixed";duplex="full";description="snom360";actor="principal";events="dialog";methods="INVITE,ACK,CANCEL,BYE,REFER,OPTIONS,NOTIFY,SUBSCRIBE,PRACK,MESSAGE,INFO" User-Agent: snom360/6.5.2 Supported: gruu Allow-Events: dialog X-Real-IP: 10.1.18.9 WWW-Contact: WWW-Contact: Expires: 3600 Content-Length: 0 [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: REGISTER sip:10.1.10.72 SIP/2.0 (31) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.18.9:5060;branch=z9hG4bK-nx0pfp1lqt92;rport (65) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "Cenan Izejroski" ;tag=xa6phg962z (61) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: "Cenan Izejroski" (44) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 3c26700a0000-x4kkws5ejsgn@snom360-000413237C3A (55) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 707 REGISTER (18) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Max-Forwards: 70 (16) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: Contact: ;flow-id=1;q=1.0;+sip.instance="";audio;mobility="fixed";duplex="full";description="snom360";actor="principal";events="dialog";methods="INVITE,ACK,CANCEL,BYE,REFER,OPTIONS,NOTIFY,SUBSCRIBE,PRACK,MESSAGE,INFO" (304) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: User-Agent: snom360/6.5.2 (25) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: Supported: gruu (15) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: Allow-Events: dialog (20) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 11: X-Real-IP: 10.1.18.9 (20) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 12: WWW-Contact: (34) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 13: WWW-Contact: (36) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 14: Expires: 3600 (13) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 15: Content-Length: 0 (17) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 16: (0) [Feb 12 19:36:02] --- (16 headers 0 lines) --- [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3183 sip_alloc: Allocating new SIP dialog for 3c26700a0000-x4kkws5ejsgn@snom360-000413237C3A - REGISTER (No RTP) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:11377 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER [Feb 12 19:36:02] Using latest REGISTER request as basis request [Feb 12 19:36:02] Sending to 10.1.18.9 : 5060 (NAT) [Feb 12 19:36:02] Transmitting (no NAT) to 10.1.18.9:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.1.18.9:5060;branch=z9hG4bK-nx0pfp1lqt92;received=10.1.18.9;rport=5060 From: "Cenan Izejroski" ;tag=xa6phg962z To: "Cenan Izejroski" Call-ID: 3c26700a0000-x4kkws5ejsgn@snom360-000413237C3A CSeq: 707 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- [Feb 12 19:36:02] -- Saved useragent "snom360/6.5.2" for peer 88565 [Feb 12 19:36:02] Transmitting (no NAT) to 10.1.18.9:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.1.18.9:5060;branch=z9hG4bK-nx0pfp1lqt92;received=10.1.18.9;rport=5060 From: "Cenan Izejroski" ;tag=xa6phg962z To: "Cenan Izejroski" ;tag=as34d1e62e Call-ID: 3c26700a0000-x4kkws5ejsgn@snom360-000413237C3A CSeq: 707 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Expires: 60 Contact: ;expires=60 Date: Mon, 12 Feb 2007 18:36:02 GMT Content-Length: 0 --- [Feb 12 19:36:02] Scheduling destruction of call '3c26700a0000-x4kkws5ejsgn@snom360-000413237C3A' in 15000 ms [Feb 12 19:36:02] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88565 [Feb 12 19:36:02] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for SIP/88565 - state 1 (Not in use) [Feb 12 19:36:02] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88565 [Feb 12 19:36:02] DEBUG[23192]: app_queue.c:500 changethread: Device 'SIP/88565' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 12 19:36:02] <-- SIP read from 10.1.18.1:5060: SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK786a1a4a;rport=5060 From: "asterisk" ;tag=as3eae2d39 To: Call-ID: 441f91a07c34e6b214f83aa305c195dd@10.1.10.72 CSeq: 102 NOTIFY Content-Length: 0 [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: SIP/2.0 200 Ok (14) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK786a1a4a;rport=5060 (66) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "asterisk" ;tag=as3eae2d39 (57) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: (44) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 441f91a07c34e6b214f83aa305c195dd@10.1.10.72 (52) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 102 NOTIFY (16) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Content-Length: 0 (17) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: (0) [Feb 12 19:36:02] --- (7 headers 0 lines) --- [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:1403 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #53 [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:1415 __sip_ack: Stopping retransmission on '441f91a07c34e6b214f83aa305c195dd@10.1.10.72' of Request 102: Match Found [Feb 12 19:36:02] Destroying call '441f91a07c34e6b214f83aa305c195dd@10.1.10.72' [Feb 12 19:36:02] <-- SIP read from 10.1.18.10:5060: REGISTER sip:10.1.10.72 SIP/2.0 Via: SIP/2.0/UDP 10.1.18.10:5060;branch=z9hG4bK-kk45gwoz5fpn;rport From: "Christine Ziegler" ;tag=9lnwupd6j6 To: "Christine Ziegler" Call-ID: 3c26700a2bf2-x4kkws5ejsgn@snom360-0004132346B0 CSeq: 707 REGISTER Max-Forwards: 70 Contact: ;flow-id=1;q=1.0;+sip.instance="";audio;mobility="fixed";duplex="full";description="snom360";actor="principal";events="dialog";methods="INVITE,ACK,CANCEL,BYE,REFER,OPTIONS,NOTIFY,SUBSCRIBE,PRACK,MESSAGE,INFO" User-Agent: snom360/6.5.2 Supported: gruu Allow-Events: dialog X-Real-IP: 10.1.18.10 WWW-Contact: WWW-Contact: Expires: 3600 Content-Length: 0 [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: REGISTER sip:10.1.10.72 SIP/2.0 (31) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.18.10:5060;branch=z9hG4bK-kk45gwoz5fpn;rport (66) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "Christine Ziegler" ;tag=9lnwupd6j6 (63) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: "Christine Ziegler" (46) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 3c26700a2bf2-x4kkws5ejsgn@snom360-0004132346B0 (55) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 707 REGISTER (18) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Max-Forwards: 70 (16) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: Contact: ;flow-id=1;q=1.0;+sip.instance="";audio;mobility="fixed";duplex="full";description="snom360";actor="principal";events="dialog";methods="INVITE,ACK,CANCEL,BYE,REFER,OPTIONS,NOTIFY,SUBSCRIBE,PRACK,MESSAGE,INFO" (305) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: User-Agent: snom360/6.5.2 (25) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: Supported: gruu (15) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: Allow-Events: dialog (20) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 11: X-Real-IP: 10.1.18.10 (21) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 12: WWW-Contact: (35) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 13: WWW-Contact: (37) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 14: Expires: 3600 (13) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 15: Content-Length: 0 (17) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 16: (0) [Feb 12 19:36:02] --- (16 headers 0 lines) --- [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3183 sip_alloc: Allocating new SIP dialog for 3c26700a2bf2-x4kkws5ejsgn@snom360-0004132346B0 - REGISTER (No RTP) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:11377 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER [Feb 12 19:36:02] Using latest REGISTER request as basis request [Feb 12 19:36:02] Sending to 10.1.18.10 : 5060 (NAT) [Feb 12 19:36:02] Transmitting (no NAT) to 10.1.18.10:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.1.18.10:5060;branch=z9hG4bK-kk45gwoz5fpn;received=10.1.18.10;rport=5060 From: "Christine Ziegler" ;tag=9lnwupd6j6 To: "Christine Ziegler" Call-ID: 3c26700a2bf2-x4kkws5ejsgn@snom360-0004132346B0 CSeq: 707 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- [Feb 12 19:36:02] -- Saved useragent "snom360/6.5.2" for peer 88564 [Feb 12 19:36:02] Transmitting (no NAT) to 10.1.18.10:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.1.18.10:5060;branch=z9hG4bK-kk45gwoz5fpn;received=10.1.18.10;rport=5060 From: "Christine Ziegler" ;tag=9lnwupd6j6 To: "Christine Ziegler" ;tag=as29b7b708 Call-ID: 3c26700a2bf2-x4kkws5ejsgn@snom360-0004132346B0 CSeq: 707 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Expires: 60 Contact: ;expires=60 Date: Mon, 12 Feb 2007 18:36:02 GMT Content-Length: 0 --- [Feb 12 19:36:02] Scheduling destruction of call '3c26700a2bf2-x4kkws5ejsgn@snom360-0004132346B0' in 15000 ms [Feb 12 19:36:02] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88564 [Feb 12 19:36:02] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for SIP/88564 - state 1 (Not in use) [Feb 12 19:36:02] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88564 [Feb 12 19:36:02] DEBUG[23193]: app_queue.c:500 changethread: Device 'SIP/88564' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 12 19:36:02] <-- SIP read from 10.1.18.2:5060: SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK31ec59de;rport=5060 From: "asterisk" ;tag=as16f87086 To: Call-ID: 2eaecf487f3a619759d2941a783272ea@10.1.10.72 CSeq: 102 NOTIFY Content-Length: 0 [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: SIP/2.0 200 Ok (14) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK31ec59de;rport=5060 (66) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "asterisk" ;tag=as16f87086 (57) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: (44) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 2eaecf487f3a619759d2941a783272ea@10.1.10.72 (52) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 102 NOTIFY (16) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Content-Length: 0 (17) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: (0) [Feb 12 19:36:02] --- (7 headers 0 lines) --- [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:1403 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #55 [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:1415 __sip_ack: Stopping retransmission on '2eaecf487f3a619759d2941a783272ea@10.1.10.72' of Request 102: Match Found [Feb 12 19:36:02] Destroying call '2eaecf487f3a619759d2941a783272ea@10.1.10.72' [Feb 12 19:36:02] <-- SIP read from 10.1.18.6:5060: REGISTER sip:10.1.10.72 SIP/2.0 Via: SIP/2.0/UDP 10.1.18.6:5060;branch=z9hG4bK-kjs6vg3n00uo;rport From: "Thomas Denzlein" ;tag=iua1i9lj4w To: "Thomas Denzlein" Call-ID: 3c26700a0000-rmj158vik8vf@snom360-0004132346B5 CSeq: 707 REGISTER Max-Forwards: 70 Contact: ;flow-id=1;q=1.0;+sip.instance="";audio;mobility="fixed";duplex="full";description="snom360";actor="principal";events="dialog";methods="INVITE,ACK,CANCEL,BYE,REFER,OPTIONS,NOTIFY,SUBSCRIBE,PRACK,MESSAGE,INFO" User-Agent: snom360/6.5.2 Supported: gruu Allow-Events: dialog X-Real-IP: 10.1.18.6 WWW-Contact: WWW-Contact: Expires: 3600 Content-Length: 0 [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: REGISTER sip:10.1.10.72 SIP/2.0 (31) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.18.6:5060;branch=z9hG4bK-kjs6vg3n00uo;rport (65) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "Thomas Denzlein" ;tag=iua1i9lj4w (61) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: "Thomas Denzlein" (44) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 3c26700a0000-rmj158vik8vf@snom360-0004132346B5 (55) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 707 REGISTER (18) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Max-Forwards: 70 (16) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: Contact: ;flow-id=1;q=1.0;+sip.instance="";audio;mobility="fixed";duplex="full";description="snom360";actor="principal";events="dialog";methods="INVITE,ACK,CANCEL,BYE,REFER,OPTIONS,NOTIFY,SUBSCRIBE,PRACK,MESSAGE,INFO" (304) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: User-Agent: snom360/6.5.2 (25) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: Supported: gruu (15) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: Allow-Events: dialog (20) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 11: X-Real-IP: 10.1.18.6 (20) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 12: WWW-Contact: (34) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 13: WWW-Contact: (36) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 14: Expires: 3600 (13) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 15: Content-Length: 0 (17) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 16: (0) [Feb 12 19:36:02] --- (16 headers 0 lines) --- [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:3183 sip_alloc: Allocating new SIP dialog for 3c26700a0000-rmj158vik8vf@snom360-0004132346B5 - REGISTER (No RTP) [Feb 12 19:36:02] DEBUG[23169]: chan_sip.c:11377 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER [Feb 12 19:36:02] Using latest REGISTER request as basis request [Feb 12 19:36:02] Sending to 10.1.18.6 : 5060 (NAT) [Feb 12 19:36:02] Transmitting (no NAT) to 10.1.18.6:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.1.18.6:5060;branch=z9hG4bK-kjs6vg3n00uo;received=10.1.18.6;rport=5060 From: "Thomas Denzlein" ;tag=iua1i9lj4w To: "Thomas Denzlein" Call-ID: 3c26700a0000-rmj158vik8vf@snom360-0004132346B5 CSeq: 707 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- [Feb 12 19:36:02] -- Saved useragent "snom360/6.5.2" for peer 88520 [Feb 12 19:36:02] Transmitting (no NAT) to 10.1.18.6:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.1.18.6:5060;branch=z9hG4bK-kjs6vg3n00uo;received=10.1.18.6;rport=5060 From: "Thomas Denzlein" ;tag=iua1i9lj4w To: "Thomas Denzlein" ;tag=as433548d6 Call-ID: 3c26700a0000-rmj158vik8vf@snom360-0004132346B5 CSeq: 707 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Expires: 60 Contact: ;expires=60 Date: Mon, 12 Feb 2007 18:36:02 GMT Content-Length: 0 --- [Feb 12 19:36:02] Scheduling destruction of call '3c26700a0000-rmj158vik8vf@snom360-0004132346B5' in 15000 ms [Feb 12 19:36:02] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88520 [Feb 12 19:36:02] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for SIP/88520 - state 1 (Not in use) [Feb 12 19:36:02] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88520 [Feb 12 19:36:02] DEBUG[23194]: app_queue.c:500 changethread: Device 'SIP/88520' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 12 19:36:03] <-- SIP read from 10.1.18.12:5060: REGISTER sip:10.1.10.72 SIP/2.0 Via: SIP/2.0/UDP 10.1.18.12:5060;branch=z9hG4bK-8zkm5ah2dqlt;rport From: "Michael Griessinger" ;tag=dza7wehv8u To: "Michael Griessinger" Call-ID: 3c26700a0271-x4kkws5ejsgn@snom360-0004132346AF CSeq: 707 REGISTER Max-Forwards: 70 Contact: ;flow-id=1;q=1.0;+sip.instance="";audio;mobility="fixed";duplex="full";description="snom360";actor="principal";events="dialog";methods="INVITE,ACK,CANCEL,BYE,REFER,OPTIONS,NOTIFY,SUBSCRIBE,PRACK,MESSAGE,INFO" User-Agent: snom360/6.5.2 Supported: gruu Allow-Events: dialog X-Real-IP: 10.1.18.12 WWW-Contact: WWW-Contact: Expires: 3600 Content-Length: 0 [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: REGISTER sip:10.1.10.72 SIP/2.0 (31) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.18.12:5060;branch=z9hG4bK-8zkm5ah2dqlt;rport (66) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "Michael Griessinger" ;tag=dza7wehv8u (65) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: "Michael Griessinger" (48) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 3c26700a0271-x4kkws5ejsgn@snom360-0004132346AF (55) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 707 REGISTER (18) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Max-Forwards: 70 (16) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: Contact: ;flow-id=1;q=1.0;+sip.instance="";audio;mobility="fixed";duplex="full";description="snom360";actor="principal";events="dialog";methods="INVITE,ACK,CANCEL,BYE,REFER,OPTIONS,NOTIFY,SUBSCRIBE,PRACK,MESSAGE,INFO" (305) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: User-Agent: snom360/6.5.2 (25) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: Supported: gruu (15) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: Allow-Events: dialog (20) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 11: X-Real-IP: 10.1.18.12 (21) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 12: WWW-Contact: (35) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 13: WWW-Contact: (37) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 14: Expires: 3600 (13) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 15: Content-Length: 0 (17) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 16: (0) [Feb 12 19:36:03] --- (16 headers 0 lines) --- [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3183 sip_alloc: Allocating new SIP dialog for 3c26700a0271-x4kkws5ejsgn@snom360-0004132346AF - REGISTER (No RTP) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:11377 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER [Feb 12 19:36:03] Using latest REGISTER request as basis request [Feb 12 19:36:03] Sending to 10.1.18.12 : 5060 (NAT) [Feb 12 19:36:03] Transmitting (no NAT) to 10.1.18.12:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.1.18.12:5060;branch=z9hG4bK-8zkm5ah2dqlt;received=10.1.18.12;rport=5060 From: "Michael Griessinger" ;tag=dza7wehv8u To: "Michael Griessinger" Call-ID: 3c26700a0271-x4kkws5ejsgn@snom360-0004132346AF CSeq: 707 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- [Feb 12 19:36:03] -- Saved useragent "snom360/6.5.2" for peer 88142 [Feb 12 19:36:03] Transmitting (no NAT) to 10.1.18.12:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.1.18.12:5060;branch=z9hG4bK-8zkm5ah2dqlt;received=10.1.18.12;rport=5060 From: "Michael Griessinger" ;tag=dza7wehv8u To: "Michael Griessinger" ;tag=as2b7eac3f Call-ID: 3c26700a0271-x4kkws5ejsgn@snom360-0004132346AF CSeq: 707 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Expires: 60 Contact: ;expires=60 Date: Mon, 12 Feb 2007 18:36:03 GMT Content-Length: 0 --- [Feb 12 19:36:03] Scheduling destruction of call '3c26700a0271-x4kkws5ejsgn@snom360-0004132346AF' in 15000 ms [Feb 12 19:36:03] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88142 [Feb 12 19:36:03] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for SIP/88142 - state 1 (Not in use) [Feb 12 19:36:03] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88142 [Feb 12 19:36:03] DEBUG[23195]: app_queue.c:500 changethread: Device 'SIP/88142' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 12 19:36:03] <-- SIP read from 10.1.18.11:5060: REGISTER sip:10.1.10.72 SIP/2.0 Via: SIP/2.0/UDP 10.1.18.11:5060;branch=z9hG4bK-xsf5kdcq4d51;rport From: "Christoph Decker" ;tag=d29q59z9ww To: "Christoph Decker" Call-ID: 3c26700a445c-x4kkws5ejsgn@snom360-000413237C3B CSeq: 707 REGISTER Max-Forwards: 70 Contact: ;flow-id=1;q=1.0;+sip.instance="";audio;mobility="fixed";duplex="full";description="snom360";actor="principal";events="dialog";methods="INVITE,ACK,CANCEL,BYE,REFER,OPTIONS,NOTIFY,SUBSCRIBE,PRACK,MESSAGE,INFO" User-Agent: snom360/6.5.2 Supported: gruu Allow-Events: dialog X-Real-IP: 10.1.18.11 WWW-Contact: WWW-Contact: Expires: 3600 Content-Length: 0 [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: REGISTER sip:10.1.10.72 SIP/2.0 (31) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.18.11:5060;branch=z9hG4bK-xsf5kdcq4d51;rport (66) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "Christoph Decker" ;tag=d29q59z9ww (62) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: "Christoph Decker" (45) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 3c26700a445c-x4kkws5ejsgn@snom360-000413237C3B (55) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 707 REGISTER (18) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Max-Forwards: 70 (16) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: Contact: ;flow-id=1;q=1.0;+sip.instance="";audio;mobility="fixed";duplex="full";description="snom360";actor="principal";events="dialog";methods="INVITE,ACK,CANCEL,BYE,REFER,OPTIONS,NOTIFY,SUBSCRIBE,PRACK,MESSAGE,INFO" (305) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: User-Agent: snom360/6.5.2 (25) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: Supported: gruu (15) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: Allow-Events: dialog (20) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 11: X-Real-IP: 10.1.18.11 (21) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 12: WWW-Contact: (35) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 13: WWW-Contact: (37) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 14: Expires: 3600 (13) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 15: Content-Length: 0 (17) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 16: (0) [Feb 12 19:36:03] --- (16 headers 0 lines) --- [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:3183 sip_alloc: Allocating new SIP dialog for 3c26700a445c-x4kkws5ejsgn@snom360-000413237C3B - REGISTER (No RTP) [Feb 12 19:36:03] DEBUG[23169]: chan_sip.c:11377 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER [Feb 12 19:36:03] Using latest REGISTER request as basis request [Feb 12 19:36:03] Sending to 10.1.18.11 : 5060 (NAT) [Feb 12 19:36:03] Transmitting (no NAT) to 10.1.18.11:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.1.18.11:5060;branch=z9hG4bK-xsf5kdcq4d51;received=10.1.18.11;rport=5060 From: "Christoph Decker" ;tag=d29q59z9ww To: "Christoph Decker" Call-ID: 3c26700a445c-x4kkws5ejsgn@snom360-000413237C3B CSeq: 707 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- [Feb 12 19:36:03] -- Saved useragent "snom360/6.5.2" for peer 88432 [Feb 12 19:36:03] Transmitting (no NAT) to 10.1.18.11:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.1.18.11:5060;branch=z9hG4bK-xsf5kdcq4d51;received=10.1.18.11;rport=5060 From: "Christoph Decker" ;tag=d29q59z9ww To: "Christoph Decker" ;tag=as6a8fc8d3 Call-ID: 3c26700a445c-x4kkws5ejsgn@snom360-000413237C3B CSeq: 707 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Expires: 60 Contact: ;expires=60 Date: Mon, 12 Feb 2007 18:36:03 GMT Content-Length: 0 --- [Feb 12 19:36:03] Scheduling destruction of call '3c26700a445c-x4kkws5ejsgn@snom360-000413237C3B' in 15000 ms [Feb 12 19:36:03] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88432 [Feb 12 19:36:03] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for SIP/88432 - state 1 (Not in use) [Feb 12 19:36:03] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88432 [Feb 12 19:36:03] DEBUG[23196]: app_queue.c:500 changethread: Device 'SIP/88432' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 12 19:36:04] <-- SIP read from 10.1.18.2:5060: INVITE sip:182@10.1.10.72 SIP/2.0 Via: SIP/2.0/UDP 10.1.18.2:5060;branch=z9hG4bK-2q5dlurwymv3;rport From: "Thomas Gick" ;tag=bajakq6bzy To: Call-ID: 3c26c37b3d09-bfly826gtsm0@snom360-000413232807 CSeq: 1 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: resolution="31x13", keys="4" User-Agent: snom360/6.5.2 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Session-Expires: 3600;refresher=uas Min-SE: 90 Content-Type: application/sdp Content-Length: 306 v=0 o=root 2107071880 2107071880 IN IP4 10.1.18.2 s=call c=IN IP4 10.1.18.2 t=0 0 m=audio 52474 RTP/AVP 8 0 9 2 3 18 4 a=rtpmap:8 pcma/8000 a=rtpmap:0 pcmu/8000 a=rtpmap:9 g722/8000 a=rtpmap:2 g726-32/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=ptime:10 a=sendrecv [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: INVITE sip:182@10.1.10.72 SIP/2.0 (33) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.18.2:5060;branch=z9hG4bK-2q5dlurwymv3;rport (65) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "Thomas Gick" ;tag=bajakq6bzy (57) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: (24) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 3c26c37b3d09-bfly826gtsm0@snom360-000413232807 (55) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 1 INVITE (14) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Max-Forwards: 70 (16) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: Contact: ;flow-id=1 (59) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: P-Key-Flags: resolution="31x13", keys="4" (41) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: User-Agent: snom360/6.5.2 (25) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: Accept: application/sdp (23) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 12: Allow-Events: talk, hold, refer (31) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 13: Supported: timer, 100rel, replaces, callerid (44) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 14: Session-Expires: 3600;refresher=uas (35) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 15: Min-SE: 90 (10) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 16: Content-Type: application/sdp (29) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 17: Content-Length: 306 (19) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 18: (0) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: v=0 (3) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: o=root 2107071880 2107071880 IN IP4 10.1.18.2 (45) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: s=call (6) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: c=IN IP4 10.1.18.2 (18) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: t=0 0 (5) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: m=audio 52474 RTP/AVP 8 0 9 2 3 18 4 (36) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: a=rtpmap:8 pcma/8000 (20) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: a=rtpmap:0 pcmu/8000 (20) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: a=rtpmap:9 g722/8000 (20) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: a=rtpmap:3 gsm/8000 (19) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: a=rtpmap:18 g729/8000 (21) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: a=rtpmap:4 g723/8000 (20) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: a=ptime:10 (10) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: a=sendrecv (10) [Feb 12 19:36:04] --- (18 headers 15 lines) --- [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3183 sip_alloc: Allocating new SIP dialog for 3c26c37b3d09-bfly826gtsm0@snom360-000413232807 - INVITE (With RTP) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:11377 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:1015 parse_sip_options: Begin: parsing SIP "Supported: timer, 100rel, replaces, callerid" [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:1027 parse_sip_options: Found SIP option: -timer- [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:1033 parse_sip_options: Matched SIP option: timer [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:1027 parse_sip_options: Found SIP option: -100rel- [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:1033 parse_sip_options: Matched SIP option: 100rel [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:1027 parse_sip_options: Found SIP option: -replaces- [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:1033 parse_sip_options: Matched SIP option: replaces [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:1027 parse_sip_options: Found SIP option: -callerid- [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:1038 parse_sip_options: Found no match for SIP option: callerid (Please file bug report!) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:1044 parse_sip_options: * SIP extension value: 7 for call 3c26c37b3d09-bfly826gtsm0@snom360-000413232807 [Feb 12 19:36:04] Using INVITE request as basis request - 3c26c37b3d09-bfly826gtsm0@snom360-000413232807 [Feb 12 19:36:04] Sending to 10.1.18.2 : 5060 (NAT) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:7323 check_user_full: Setting NAT on RTP to 0 [Feb 12 19:36:04] Found user '88344' [Feb 12 19:36:04] Found RTP audio format 8 [Feb 12 19:36:04] Found RTP audio format 0 [Feb 12 19:36:04] Found RTP audio format 9 [Feb 12 19:36:04] Found RTP audio format 2 [Feb 12 19:36:04] Found RTP audio format 3 [Feb 12 19:36:04] Found RTP audio format 18 [Feb 12 19:36:04] Found RTP audio format 4 [Feb 12 19:36:04] Peer audio RTP is at port 10.1.18.2:52474 [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:3675 process_sdp: Peer audio RTP is at port 10.1.18.2:52474 [Feb 12 19:36:04] Found description format pcma [Feb 12 19:36:04] Found description format pcmu [Feb 12 19:36:04] Found description format g722 [Feb 12 19:36:04] Found description format g726-32 [Feb 12 19:36:04] Found description format gsm [Feb 12 19:36:04] Found description format g729 [Feb 12 19:36:04] Found description format g723 [Feb 12 19:36:04] Capabilities: us - 0x8 (alaw), peer - audio=0x11f (g723|gsm|ulaw|alaw|g726|g729)/video=0x0 (nothing), combined - 0x8 (alaw) [Feb 12 19:36:04] Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:10708 handle_request_invite: Checking SIP call limits for device 88344 [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:2227 update_call_counter: Updating call counter for incoming call [Feb 12 19:36:04] Looking for 182 in sip_in (domain 10.1.10.72) [Feb 12 19:36:04] DEBUG[23169]: chan_sip.c:6276 build_route: build_route: Contact hop: ;flow-id=1 [Feb 12 19:36:04] list_route: hop: [Feb 12 19:36:04] Transmitting (no NAT) to 10.1.18.2:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.1.18.2:5060;branch=z9hG4bK-2q5dlurwymv3;received=10.1.18.2;rport=5060 From: "Thomas Gick" ;tag=bajakq6bzy To: Call-ID: 3c26c37b3d09-bfly826gtsm0@snom360-000413232807 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- [Feb 12 19:36:04] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88344 [Feb 12 19:36:04] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for SIP/88344 - state 2 (In use) [Feb 12 19:36:04] DEBUG[23197]: pbx.c:1677 pbx_extension_helper: Launching 'Dial' [Feb 12 19:36:04] -- Executing Dial("SIP/88344-0820eda0", "ZAP/g1/182||tTowWhH") in new stack [Feb 12 19:36:04] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88344 [Feb 12 19:36:04] DEBUG[23197]: chan_zap.c:7576 zt_request: Using channel 2 [Feb 12 19:36:04] DEBUG[23198]: app_queue.c:500 changethread: Device 'SIP/88344' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Feb 12 19:36:04] DEBUG[23197]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-sip_in-182-1. [Feb 12 19:36:04] DEBUG[23197]: channel.c:2902 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Feb 12 19:36:04] DEBUG[23197]: channel.c:2902 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. [Feb 12 19:36:04] DEBUG[23197]: channel.c:2902 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Feb 12 19:36:04] DEBUG[23197]: channel.c:2902 ast_channel_inherit_variables: Not copying variable SIPURI. [Feb 12 19:36:04] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for Zap/2 - state 2 (In use) [Feb 12 19:36:04] -- Requested transfer capability: 0x00 - SPEECH [Feb 12 19:36:04] DEBUG[23199]: app_queue.c:500 changethread: Device 'Zap/2' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Feb 12 19:36:04] -- Called g1/182 [Feb 12 19:36:04] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for Zap/2 - state 2 (In use) [Feb 12 19:36:04] DEBUG[23200]: app_queue.c:500 changethread: Device 'Zap/2' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Feb 12 19:36:04] We're at 10.1.10.72 port 23408 [Feb 12 19:36:04] Adding codec 0x8 (alaw) to SDP [Feb 12 19:36:04] Transmitting (no NAT) to 10.1.18.2:5060: SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 10.1.18.2:5060;branch=z9hG4bK-2q5dlurwymv3;received=10.1.18.2;rport=5060 From: "Thomas Gick" ;tag=bajakq6bzy To: ;tag=as1b7b7f06 Call-ID: 3c26c37b3d09-bfly826gtsm0@snom360-000413232807 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 156 v=0 o=root 23162 23162 IN IP4 10.1.10.72 s=session c=IN IP4 10.1.10.72 t=0 0 m=audio 23408 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=silenceSupp:off - - - - --- [Feb 12 19:36:04] DEBUG[23197]: rtp.c:1361 ast_rtp_write: Ooh, format changed from unknown to alaw [Feb 12 19:36:04] DEBUG[23171]: chan_zap.c:8698 pri_dchannel: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/2 span 1 [Feb 12 19:36:04] -- Zap/2-1 is proceeding passing it to SIP/88344-0820eda0 [Feb 12 19:36:04] !! Unknown IE 50 (cs5, Unknown Information Element) [Feb 12 19:36:04] DEBUG[23171]: chan_zap.c:1406 zt_enable_ec: No echo cancellation requested [Feb 12 19:36:04] DEBUG[23167]: devicestate.c:187 do_state_change: [Feb 12 19:36:04] -- Zap/2-1 is ringing Changing state for Zap/2 - state 6 (Ringing) [Feb 12 19:36:04] DEBUG[23201]: app_queue.c:500 changethread: [Feb 12 19:36:04] Transmitting (no NAT) to 10.1.18.2:5060: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.1.18.2:5060;branch=z9hG4bK-2q5dlurwymv3;received=10.1.18.2;rport=5060 From: "Thomas Gick" ;tag=bajakq6bzy To: ;tag=as1b7b7f06 Call-ID: 3c26c37b3d09-bfly826gtsm0@snom360-000413232807 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Device 'Zap/2' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Feb 12 19:36:04] DEBUG[23197]: rtp.c:411 ast_rtcp_read: Got RTCP report of 52 bytes [Feb 12 19:36:05] <-- SIP read from 10.1.18.5:5060: REGISTER sip:10.1.10.72 SIP/2.0 Via: SIP/2.0/UDP 10.1.18.5:5060;branch=z9hG4bK-b4s5ybcd3v1o;rport From: "Thomas Klauer" ;tag=rj7c8cxhgp To: "Thomas Klauer" Call-ID: 3c26700c0271-x4kkws5ejsgn@snom360-0004132346B2 CSeq: 707 REGISTER Max-Forwards: 70 Contact: ;flow-id=1;q=1.0;+sip.instance="";audio;mobility="fixed";duplex="full";description="snom360";actor="principal";events="dialog";methods="INVITE,ACK,CANCEL,BYE,REFER,OPTIONS,NOTIFY,SUBSCRIBE,PRACK,MESSAGE,INFO" User-Agent: snom360/6.5.2 Supported: gruu Allow-Events: dialog X-Real-IP: 10.1.18.5 WWW-Contact: WWW-Contact: Expires: 3600 Content-Length: 0 [Feb 12 19:36:05] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: REGISTER sip:10.1.10.72 SIP/2.0 (31) [Feb 12 19:36:05] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.18.5:5060;branch=z9hG4bK-b4s5ybcd3v1o;rport (65) [Feb 12 19:36:05] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "Thomas Klauer" ;tag=rj7c8cxhgp (59) [Feb 12 19:36:05] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: "Thomas Klauer" (42) [Feb 12 19:36:05] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 3c26700c0271-x4kkws5ejsgn@snom360-0004132346B2 (55) [Feb 12 19:36:05] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 707 REGISTER (18) [Feb 12 19:36:05] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Max-Forwards: 70 (16) [Feb 12 19:36:05] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: Contact: ;flow-id=1;q=1.0;+sip.instance="";audio;mobility="fixed";duplex="full";description="snom360";actor="principal";events="dialog";methods="INVITE,ACK,CANCEL,BYE,REFER,OPTIONS,NOTIFY,SUBSCRIBE,PRACK,MESSAGE,INFO" (304) [Feb 12 19:36:05] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: User-Agent: snom360/6.5.2 (25) [Feb 12 19:36:05] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: Supported: gruu (15) [Feb 12 19:36:05] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: Allow-Events: dialog (20) [Feb 12 19:36:05] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 11: X-Real-IP: 10.1.18.5 (20) [Feb 12 19:36:05] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 12: WWW-Contact: (34) [Feb 12 19:36:05] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 13: WWW-Contact: (36) [Feb 12 19:36:05] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 14: Expires: 3600 (13) [Feb 12 19:36:05] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 15: Content-Length: 0 (17) [Feb 12 19:36:05] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 16: (0) [Feb 12 19:36:05] --- (16 headers 0 lines) --- [Feb 12 19:36:05] DEBUG[23169]: chan_sip.c:3183 sip_alloc: Allocating new SIP dialog for 3c26700c0271-x4kkws5ejsgn@snom360-0004132346B2 - REGISTER (No RTP) [Feb 12 19:36:05] DEBUG[23169]: chan_sip.c:11377 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER [Feb 12 19:36:05] Using latest REGISTER request as basis request [Feb 12 19:36:05] Sending to 10.1.18.5 : 5060 (NAT) [Feb 12 19:36:05] Transmitting (no NAT) to 10.1.18.5:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.1.18.5:5060;branch=z9hG4bK-b4s5ybcd3v1o;received=10.1.18.5;rport=5060 From: "Thomas Klauer" ;tag=rj7c8cxhgp To: "Thomas Klauer" Call-ID: 3c26700c0271-x4kkws5ejsgn@snom360-0004132346B2 CSeq: 707 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- [Feb 12 19:36:05] Transmitting (no NAT) to 10.1.18.5:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.1.18.5:5060;branch=z9hG4bK-b4s5ybcd3v1o;received=10.1.18.5;rport=5060 From: "Thomas Klauer" ;tag=rj7c8cxhgp To: "Thomas Klauer" ;tag=as458e19ba Call-ID: 3c26700c0271-x4kkws5ejsgn@snom360-0004132346B2 CSeq: 707 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Expires: 60 Contact: ;expires=60 Date: Mon, 12 Feb 2007 18:36:05 GMT Content-Length: 0 --- [Feb 12 19:36:05] Scheduling destruction of call '3c26700c0271-x4kkws5ejsgn@snom360-0004132346B2' in 15000 ms [Feb 12 19:36:05] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88906 [Feb 12 19:36:05] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for SIP/88906 - state 1 (Not in use) [Feb 12 19:36:05] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88906 [Feb 12 19:36:05] DEBUG[23202]: app_queue.c:500 changethread: Device 'SIP/88906' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 12 19:36:06] !! Unknown IE 50 (cs5, Unknown Information Element) [Feb 12 19:36:06] DEBUG[23171]: chan_zap.c:1406 zt_enable_ec: No echo cancellation requested [Feb 12 19:36:06] -- Zap/2-1 answered SIP/88344-0820eda0 [Feb 12 19:36:06] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for Zap/2 - state 2 (In use) [Feb 12 19:36:06] DEBUG[23203]: app_queue.c:500 changethread: Device 'Zap/2' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Feb 12 19:36:06] DEBUG[23197]: chan_sip.c:2567 sip_answer: sip_answer(SIP/88344-0820eda0) [Feb 12 19:36:06] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88344 [Feb 12 19:36:06] DEBUG[23167]: channel.c:771 channel_find_locked: Avoiding initial deadlock for 'SIP/88344-0820eda0' [Feb 12 19:36:06] We're at 10.1.10.72 port 23408 [Feb 12 19:36:06] Adding codec 0x8 (alaw) to SDP [Feb 12 19:36:06] Reliably Transmitting (no NAT) to 10.1.18.2:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.1.18.2:5060;branch=z9hG4bK-2q5dlurwymv3;received=10.1.18.2;rport=5060 From: "Thomas Gick" ;tag=bajakq6bzy To: ;tag=as1b7b7f06 Call-ID: 3c26c37b3d09-bfly826gtsm0@snom360-000413232807 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 156 v=0 o=root 23162 23163 IN IP4 10.1.10.72 s=session c=IN IP4 10.1.10.72 t=0 0 m=audio 23408 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=silenceSupp:off - - - - --- [Feb 12 19:36:06] DEBUG[23197]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #69 [Feb 12 19:36:06] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for SIP/88344 - state 2 (In use) [Feb 12 19:36:06] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88344 [Feb 12 19:36:06] DEBUG[23204]: app_queue.c:500 changethread: Device 'SIP/88344' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Feb 12 19:36:06] <-- SIP read from 10.1.18.2:5060: ACK sip:182@10.1.10.72 SIP/2.0 Via: SIP/2.0/UDP 10.1.18.2:5060;branch=z9hG4bK-vnxhymu3h50z;rport From: "Thomas Gick" ;tag=bajakq6bzy To: ;tag=as1b7b7f06 Call-ID: 3c26c37b3d09-bfly826gtsm0@snom360-000413232807 CSeq: 1 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 [Feb 12 19:36:06] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: ACK sip:182@10.1.10.72 SIP/2.0 (30) [Feb 12 19:36:06] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.18.2:5060;branch=z9hG4bK-vnxhymu3h50z;rport (65) [Feb 12 19:36:06] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "Thomas Gick" ;tag=bajakq6bzy (57) [Feb 12 19:36:06] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: ;tag=as1b7b7f06 (39) [Feb 12 19:36:06] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 3c26c37b3d09-bfly826gtsm0@snom360-000413232807 (55) [Feb 12 19:36:06] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 1 ACK (11) [Feb 12 19:36:06] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Max-Forwards: 70 (16) [Feb 12 19:36:06] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: Contact: ;flow-id=1 (59) [Feb 12 19:36:06] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: Content-Length: 0 (17) [Feb 12 19:36:06] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: (0) [Feb 12 19:36:06] --- (9 headers 0 lines) --- [Feb 12 19:36:06] DEBUG[23169]: chan_sip.c:11377 handle_request: **** Received ACK (6) - Command in SIP ACK [Feb 12 19:36:06] DEBUG[23169]: chan_sip.c:1403 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #69 [Feb 12 19:36:06] DEBUG[23169]: chan_sip.c:1415 __sip_ack: Stopping retransmission on '3c26c37b3d09-bfly826gtsm0@snom360-000413232807' of Response 1: Match Found [Feb 12 19:36:06] DEBUG[23197]: rtp.c:411 ast_rtcp_read: Got RTCP report of 52 bytes [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3183 sip_alloc: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: NOTIFY sip:88142@10.1.18.12:5060;line=gv8x1x75 SIP/2.0 (54) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK71c33293;rport (61) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "asterisk" ;tag=as55259536 (57) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: (45) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Contact: (34) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: Call-ID: 4b61f311666e5f4e3da7d716206447e3@10.1.10.72 (52) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: CSeq: 102 NOTIFY (16) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: Max-Forwards: 70 (16) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: Event: message-summary (22) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: Content-Type: application/simple-message-summary (48) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 11: Content-Length: 91 (18) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 12: (0) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Messages-Waiting: no (20) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Message-Account: sip:voicemail@10.1.10.72 (41) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Voice-Message: 0/1 (0/0) (24) [Feb 12 19:36:08] 12 headers, 3 lines [Feb 12 19:36:08] Reliably Transmitting (no NAT) to 10.1.18.12:5060: NOTIFY sip:88142@10.1.18.12:5060;line=gv8x1x75 SIP/2.0 Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK71c33293;rport From: "asterisk" ;tag=as55259536 To: Contact: Call-ID: 4b61f311666e5f4e3da7d716206447e3@10.1.10.72 CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: message-summary Content-Type: application/simple-message-summary Content-Length: 91 Messages-Waiting: no Message-Account: sip:voicemail@10.1.10.72 Voice-Message: 0/1 (0/0) --- [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #70 [Feb 12 19:36:08] Scheduling destruction of call '4b61f311666e5f4e3da7d716206447e3@10.1.10.72' in 15000 ms [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3183 sip_alloc: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: NOTIFY sip:88432@10.1.18.11:5060;line=gv8x1x75 SIP/2.0 (54) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK10c96751;rport (61) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "asterisk" ;tag=as09efddbe (57) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: (45) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Contact: (34) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: Call-ID: 468f1e0d55c5919638a3542c3102e8c4@10.1.10.72 (52) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: CSeq: 102 NOTIFY (16) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: Max-Forwards: 70 (16) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: Event: message-summary (22) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: Content-Type: application/simple-message-summary (48) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 11: Content-Length: 92 (18) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 12: (0) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Messages-Waiting: yes (21) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Message-Account: sip:voicemail@10.1.10.72 (41) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Voice-Message: 6/0 (0/0) (24) [Feb 12 19:36:08] 12 headers, 3 lines [Feb 12 19:36:08] Reliably Transmitting (no NAT) to 10.1.18.11:5060: NOTIFY sip:88432@10.1.18.11:5060;line=gv8x1x75 SIP/2.0 Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK10c96751;rport From: "asterisk" ;tag=as09efddbe To: Contact: Call-ID: 468f1e0d55c5919638a3542c3102e8c4@10.1.10.72 CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: message-summary Content-Type: application/simple-message-summary Content-Length: 92 Messages-Waiting: yes Message-Account: sip:voicemail@10.1.10.72 Voice-Message: 6/0 (0/0) --- [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #72 [Feb 12 19:36:08] Scheduling destruction of call '468f1e0d55c5919638a3542c3102e8c4@10.1.10.72' in 15000 ms [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3183 sip_alloc: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: NOTIFY sip:88564@10.1.18.10:5060;line=gv8x1x75 SIP/2.0 (54) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK0fb3dd6f;rport (61) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "asterisk" ;tag=as149ec90b (57) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: (45) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Contact: (34) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: Call-ID: 462553f5095c3baa7272bb0b4965ef11@10.1.10.72 (52) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: CSeq: 102 NOTIFY (16) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: Max-Forwards: 70 (16) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: Event: message-summary (22) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: Content-Type: application/simple-message-summary (48) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 11: Content-Length: 91 (18) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 12: (0) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Messages-Waiting: no (20) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Message-Account: sip:voicemail@10.1.10.72 (41) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Voice-Message: 0/0 (0/0) (24) [Feb 12 19:36:08] 12 headers, 3 lines [Feb 12 19:36:08] Reliably Transmitting (no NAT) to 10.1.18.10:5060: NOTIFY sip:88564@10.1.18.10:5060;line=gv8x1x75 SIP/2.0 Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK0fb3dd6f;rport From: "asterisk" ;tag=as149ec90b To: Contact: Call-ID: 462553f5095c3baa7272bb0b4965ef11@10.1.10.72 CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: message-summary Content-Type: application/simple-message-summary Content-Length: 91 Messages-Waiting: no Message-Account: sip:voicemail@10.1.10.72 Voice-Message: 0/0 (0/0) --- [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #74 [Feb 12 19:36:08] Scheduling destruction of call '462553f5095c3baa7272bb0b4965ef11@10.1.10.72' in 15000 ms [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3183 sip_alloc: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: NOTIFY sip:88565@10.1.18.9:5060;line=gv8x1x75 SIP/2.0 (53) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK2088f9eb;rport (61) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "asterisk" ;tag=as64a88b8b (57) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: (44) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Contact: (34) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: Call-ID: 447c0d233caeceb13e8e53744a7a1309@10.1.10.72 (52) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: CSeq: 102 NOTIFY (16) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: Max-Forwards: 70 (16) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: Event: message-summary (22) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: Content-Type: application/simple-message-summary (48) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 11: Content-Length: 91 (18) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 12: (0) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Messages-Waiting: no (20) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Message-Account: sip:voicemail@10.1.10.72 (41) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Voice-Message: 0/7 (0/0) (24) [Feb 12 19:36:08] 12 headers, 3 lines [Feb 12 19:36:08] Reliably Transmitting (no NAT) to 10.1.18.9:5060: NOTIFY sip:88565@10.1.18.9:5060;line=gv8x1x75 SIP/2.0 Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK2088f9eb;rport From: "asterisk" ;tag=as64a88b8b To: Contact: Call-ID: 447c0d233caeceb13e8e53744a7a1309@10.1.10.72 CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: message-summary Content-Type: application/simple-message-summary Content-Length: 91 Messages-Waiting: no Message-Account: sip:voicemail@10.1.10.72 Voice-Message: 0/7 (0/0) --- [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #76 [Feb 12 19:36:08] Scheduling destruction of call '447c0d233caeceb13e8e53744a7a1309@10.1.10.72' in 15000 ms [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3183 sip_alloc: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: NOTIFY sip:88906@10.1.18.5:5060;line=gv8x1x75 SIP/2.0 (53) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK415bac9c;rport (61) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "asterisk" ;tag=as700a7be4 (57) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: (44) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Contact: (34) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: Call-ID: 6132e8231d92dd41474a944921610d6e@10.1.10.72 (52) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: CSeq: 102 NOTIFY (16) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: Max-Forwards: 70 (16) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: Event: message-summary (22) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: Content-Type: application/simple-message-summary (48) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 11: Content-Length: 91 (18) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 12: (0) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Messages-Waiting: no (20) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Message-Account: sip:voicemail@10.1.10.72 (41) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Voice-Message: 0/1 (0/0) (24) [Feb 12 19:36:08] 12 headers, 3 lines [Feb 12 19:36:08] Reliably Transmitting (no NAT) to 10.1.18.5:5060: NOTIFY sip:88906@10.1.18.5:5060;line=gv8x1x75 SIP/2.0 Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK415bac9c;rport From: "asterisk" ;tag=as700a7be4 To: Contact: Call-ID: 6132e8231d92dd41474a944921610d6e@10.1.10.72 CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: message-summary Content-Type: application/simple-message-summary Content-Length: 91 Messages-Waiting: no Message-Account: sip:voicemail@10.1.10.72 Voice-Message: 0/1 (0/0) --- [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #78 [Feb 12 19:36:08] Scheduling destruction of call '6132e8231d92dd41474a944921610d6e@10.1.10.72' in 15000 ms [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3183 sip_alloc: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: NOTIFY sip:88520@10.1.18.6:5060;line=wuyxv403 SIP/2.0 (53) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK64965644;rport (61) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "asterisk" ;tag=as774c09dd (57) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: (44) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Contact: (34) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: Call-ID: 49dfcacb33e9706957283346214ac87f@10.1.10.72 (52) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: CSeq: 102 NOTIFY (16) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: Max-Forwards: 70 (16) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: Event: message-summary (22) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: Content-Type: application/simple-message-summary (48) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 11: Content-Length: 91 (18) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 12: (0) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Messages-Waiting: no (20) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Message-Account: sip:voicemail@10.1.10.72 (41) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Voice-Message: 0/1 (0/0) (24) [Feb 12 19:36:08] 12 headers, 3 lines [Feb 12 19:36:08] Reliably Transmitting (no NAT) to 10.1.18.6:5060: NOTIFY sip:88520@10.1.18.6:5060;line=wuyxv403 SIP/2.0 Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK64965644;rport From: "asterisk" ;tag=as774c09dd To: Contact: Call-ID: 49dfcacb33e9706957283346214ac87f@10.1.10.72 CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: message-summary Content-Type: application/simple-message-summary Content-Length: 91 Messages-Waiting: no Message-Account: sip:voicemail@10.1.10.72 Voice-Message: 0/1 (0/0) --- [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #80 [Feb 12 19:36:08] Scheduling destruction of call '49dfcacb33e9706957283346214ac87f@10.1.10.72' in 15000 ms [Feb 12 19:36:08] <-- SIP read from 10.1.18.12:5060: SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK71c33293;rport=5060 From: "asterisk" ;tag=as55259536 To: Call-ID: 4b61f311666e5f4e3da7d716206447e3@10.1.10.72 CSeq: 102 NOTIFY Content-Length: 0 [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: SIP/2.0 200 Ok (14) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK71c33293;rport=5060 (66) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "asterisk" ;tag=as55259536 (57) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: (45) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 4b61f311666e5f4e3da7d716206447e3@10.1.10.72 (52) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 102 NOTIFY (16) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Content-Length: 0 (17) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: (0) [Feb 12 19:36:08] --- (7 headers 0 lines) --- [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:1403 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #70 [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:1415 __sip_ack: Stopping retransmission on '4b61f311666e5f4e3da7d716206447e3@10.1.10.72' of Request 102: Match Found [Feb 12 19:36:08] <-- SIP read from 10.1.18.11:5060: SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK10c96751;rport=5060 From: "asterisk" ;tag=as09efddbe To: Call-ID: 468f1e0d55c5919638a3542c3102e8c4@10.1.10.72 CSeq: 102 NOTIFY Content-Length: 0 [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: SIP/2.0 200 Ok (14) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK10c96751;rport=5060 (66) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "asterisk" ;tag=as09efddbe (57) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: (45) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 468f1e0d55c5919638a3542c3102e8c4@10.1.10.72 (52) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 102 NOTIFY (16) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Content-Length: 0 (17) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: (0) [Feb 12 19:36:08] --- (7 headers 0 lines) --- [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:1403 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #72 [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:1415 __sip_ack: Stopping retransmission on '468f1e0d55c5919638a3542c3102e8c4@10.1.10.72' of Request 102: Match Found [Feb 12 19:36:08] <-- SIP read from 10.1.18.10:5060: SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK0fb3dd6f;rport=5060 From: "asterisk" ;tag=as149ec90b To: Call-ID: 462553f5095c3baa7272bb0b4965ef11@10.1.10.72 CSeq: 102 NOTIFY Content-Length: 0 [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: SIP/2.0 200 Ok (14) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK0fb3dd6f;rport=5060 (66) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "asterisk" ;tag=as149ec90b (57) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: (45) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 462553f5095c3baa7272bb0b4965ef11@10.1.10.72 (52) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 102 NOTIFY (16) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Content-Length: 0 (17) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: (0) [Feb 12 19:36:08] --- (7 headers 0 lines) --- [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:1403 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #74 [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:1415 __sip_ack: Stopping retransmission on '462553f5095c3baa7272bb0b4965ef11@10.1.10.72' of Request 102: Match Found [Feb 12 19:36:08] Destroying call '462553f5095c3baa7272bb0b4965ef11@10.1.10.72' [Feb 12 19:36:08] Destroying call '468f1e0d55c5919638a3542c3102e8c4@10.1.10.72' [Feb 12 19:36:08] Destroying call '4b61f311666e5f4e3da7d716206447e3@10.1.10.72' [Feb 12 19:36:08] <-- SIP read from 10.1.18.9:5060: SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK2088f9eb;rport=5060 From: "asterisk" ;tag=as64a88b8b To: Call-ID: 447c0d233caeceb13e8e53744a7a1309@10.1.10.72 CSeq: 102 NOTIFY Content-Length: 0 [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: SIP/2.0 200 Ok (14) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK2088f9eb;rport=5060 (66) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "asterisk" ;tag=as64a88b8b (57) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: (44) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 447c0d233caeceb13e8e53744a7a1309@10.1.10.72 (52) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 102 NOTIFY (16) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Content-Length: 0 (17) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: (0) [Feb 12 19:36:08] --- (7 headers 0 lines) --- [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:1403 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #76 [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:1415 __sip_ack: Stopping retransmission on '447c0d233caeceb13e8e53744a7a1309@10.1.10.72' of Request 102: Match Found [Feb 12 19:36:08] Destroying call '447c0d233caeceb13e8e53744a7a1309@10.1.10.72' [Feb 12 19:36:08] <-- SIP read from 10.1.18.5:5060: SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK415bac9c;rport=5060 From: "asterisk" ;tag=as700a7be4 To: Call-ID: 6132e8231d92dd41474a944921610d6e@10.1.10.72 CSeq: 102 NOTIFY Content-Length: 0 [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: SIP/2.0 200 Ok (14) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK415bac9c;rport=5060 (66) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "asterisk" ;tag=as700a7be4 (57) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: (44) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 6132e8231d92dd41474a944921610d6e@10.1.10.72 (52) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 102 NOTIFY (16) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Content-Length: 0 (17) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: (0) [Feb 12 19:36:08] --- (7 headers 0 lines) --- [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:1403 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #78 [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:1415 __sip_ack: Stopping retransmission on '6132e8231d92dd41474a944921610d6e@10.1.10.72' of Request 102: Match Found [Feb 12 19:36:08] Destroying call '6132e8231d92dd41474a944921610d6e@10.1.10.72' [Feb 12 19:36:08] <-- SIP read from 10.1.18.6:5060: SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK64965644;rport=5060 From: "asterisk" ;tag=as774c09dd To: Call-ID: 49dfcacb33e9706957283346214ac87f@10.1.10.72 CSeq: 102 NOTIFY Content-Length: 0 [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: SIP/2.0 200 Ok (14) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK64965644;rport=5060 (66) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "asterisk" ;tag=as774c09dd (57) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: (44) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 49dfcacb33e9706957283346214ac87f@10.1.10.72 (52) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 102 NOTIFY (16) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Content-Length: 0 (17) [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: (0) [Feb 12 19:36:08] --- (7 headers 0 lines) --- [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:1403 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #80 [Feb 12 19:36:08] DEBUG[23169]: chan_sip.c:1415 __sip_ack: Stopping retransmission on '49dfcacb33e9706957283346214ac87f@10.1.10.72' of Request 102: Match Found [Feb 12 19:36:08] Destroying call '49dfcacb33e9706957283346214ac87f@10.1.10.72' [Feb 12 19:36:09] <-- SIP read from 10.1.18.4:5060: REGISTER sip:10.1.10.72 SIP/2.0 Via: SIP/2.0/UDP 10.1.18.4:5060;branch=z9hG4bK-l2af862gurvg;rport From: "Thomas Gick" ;tag=tbju36y039 To: "Thomas Gick" Call-ID: 3c26700a0c35-rmj158vik8vf@snom360-0004132346B3 CSeq: 707 REGISTER Max-Forwards: 70 Contact: ;flow-id=1;q=1.0;+sip.instance="";audio;mobility="fixed";duplex="full";description="snom360";actor="principal";events="dialog";methods="INVITE,ACK,CANCEL,BYE,REFER,OPTIONS,NOTIFY,SUBSCRIBE,PRACK,MESSAGE,INFO" User-Agent: snom360/6.5.2 Supported: gruu Allow-Events: dialog X-Real-IP: 10.1.18.4 WWW-Contact: WWW-Contact: Expires: 3600 Content-Length: 0 [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: REGISTER sip:10.1.10.72 SIP/2.0 (31) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.18.4:5060;branch=z9hG4bK-l2af862gurvg;rport (65) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "Thomas Gick" ;tag=tbju36y039 (57) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: "Thomas Gick" (40) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 3c26700a0c35-rmj158vik8vf@snom360-0004132346B3 (55) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 707 REGISTER (18) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Max-Forwards: 70 (16) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: Contact: ;flow-id=1;q=1.0;+sip.instance="";audio;mobility="fixed";duplex="full";description="snom360";actor="principal";events="dialog";methods="INVITE,ACK,CANCEL,BYE,REFER,OPTIONS,NOTIFY,SUBSCRIBE,PRACK,MESSAGE,INFO" (304) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: User-Agent: snom360/6.5.2 (25) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: Supported: gruu (15) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: Allow-Events: dialog (20) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 11: X-Real-IP: 10.1.18.4 (20) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 12: WWW-Contact: (34) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 13: WWW-Contact: (36) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 14: Expires: 3600 (13) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 15: Content-Length: 0 (17) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 16: (0) [Feb 12 19:36:09] --- (16 headers 0 lines) --- [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3183 sip_alloc: Allocating new SIP dialog for 3c26700a0c35-rmj158vik8vf@snom360-0004132346B3 - REGISTER (No RTP) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:11377 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER [Feb 12 19:36:09] Using latest REGISTER request as basis request [Feb 12 19:36:09] Sending to 10.1.18.4 : 5060 (NAT) [Feb 12 19:36:09] Transmitting (no NAT) to 10.1.18.4:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.1.18.4:5060;branch=z9hG4bK-l2af862gurvg;received=10.1.18.4;rport=5060 From: "Thomas Gick" ;tag=tbju36y039 To: "Thomas Gick" Call-ID: 3c26700a0c35-rmj158vik8vf@snom360-0004132346B3 CSeq: 707 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- [Feb 12 19:36:09] -- Saved useragent "snom360/6.5.2" for peer 88801 [Feb 12 19:36:09] Transmitting (no NAT) to 10.1.18.4:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.1.18.4:5060;branch=z9hG4bK-l2af862gurvg;received=10.1.18.4;rport=5060 From: "Thomas Gick" ;tag=tbju36y039 To: "Thomas Gick" ;tag=as05392428 Call-ID: 3c26700a0c35-rmj158vik8vf@snom360-0004132346B3 CSeq: 707 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Expires: 60 Contact: ;expires=60 Date: Mon, 12 Feb 2007 18:36:09 GMT Content-Length: 0 --- [Feb 12 19:36:09] Scheduling destruction of call '3c26700a0c35-rmj158vik8vf@snom360-0004132346B3' in 15000 ms [Feb 12 19:36:09] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88801 [Feb 12 19:36:09] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for SIP/88801 - state 1 (Not in use) [Feb 12 19:36:09] <-- SIP read from 10.1.18.2:5060: REFER sip:344@10.1.10.72 SIP/2.0 Via: SIP/2.0/UDP 10.1.18.2:5060;branch=z9hG4bK-bv3vz86nb8de;rport From: ;tag=3of76qsx41 To: "344" ;tag=as42cf2b76 Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 CSeq: 2 REFER Max-Forwards: 70 Contact: ;flow-id=1 Refer-To: Referred-By: sip:88344@10.1.10.72 User-Agent: snom360/6.5.2 Content-Length: 0 [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: REFER sip:344@10.1.10.72 SIP/2.0 (32) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.18.2:5060;branch=z9hG4bK-bv3vz86nb8de;rport (65) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: ;tag=3of76qsx41 (61) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: "344" ;tag=as42cf2b76 (45) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 (52) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 2 REFER (13) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Max-Forwards: 70 (16) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: Contact: ;flow-id=1 (59) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: Refer-To: (134) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: Referred-By: sip:88344@10.1.10.72 (33) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: User-Agent: snom360/6.5.2 (25) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 11: Content-Length: 0 (17) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 12: (0) [Feb 12 19:36:09] DEBUG[23205]: app_queue.c:500 changethread: Device 'SIP/88801' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 12 19:36:09] --- (12 headers 0 lines) --- [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:11377 handle_request: **** Received REFER (9) - Command in SIP REFER [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:10891 handle_request_refer: SIP call transfer received for call 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 (REFER)! [Feb 12 19:36:09] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88801 [Feb 12 19:36:09] Transfer to 182 in sip_in [Feb 12 19:36:09] Transfer from 88344 in sip_in [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:7023 get_refer_info: Assigning Replace-Call-ID Info 3c26c37b3d09-bfly826gtsm0@snom360-000413232807 to REPLACE_CALL_ID [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:10905 handle_request_refer: 202 Accepted (supervised) [Feb 12 19:36:09] DEBUG[23169]: chan_agent.c:920 agent_bridgedchannel: Asked for bridged channel on 'SIP/88344-081ec490'/'Agent/88344', returning 'Zap/1-1' [Feb 12 19:36:09] -- Stopped music on hold on Zap/1-1 [Feb 12 19:36:09] DEBUG[23169]: channel.c:2408 set_format: Set channel Zap/1-1 to write format alaw [Feb 12 19:36:09] DEBUG[23169]: channel.c:1755 ast_settimeout: Scheduling timer at 0 sample intervals [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:10527 attempt_transfer: Trying to masquerade SIP/88344-0820eda0 and Zap/1-1 [Feb 12 19:36:09] DEBUG[23169]: chan_agent.c:920 agent_bridgedchannel: Asked for bridged channel on 'Zap/1-1'/'Agent/88344', returning 'SIP/88344-081ec490' [Feb 12 19:36:09] DEBUG[23169]: channel.c:2834 ast_channel_masquerade: Planning to masquerade channel Agent/88344 into the structure of SIP/88344-0820eda0 [Feb 12 19:36:09] DEBUG[23169]: channel.c:2847 ast_channel_masquerade: Done planning to masquerade channel Agent/88344 into the structure of SIP/88344-0820eda0 [Feb 12 19:36:09] DEBUG[23197]: channel.c:2961 ast_do_masquerade: Actually Masquerading Agent/88344(6) into the structure of SIP/88344-0820eda0(6) [Feb 12 19:36:09] DEBUG[23197]: channel.c:2972 ast_do_masquerade: Got clone lock for masquerade on 'Agent/88344' at 0x81eb66c [Feb 12 19:36:09] DEBUG[23197]: chan_sip.c:2437 sip_hangup: Hangup call Agent/88344, SIP callid 3c26c37b3d09-bfly826gtsm0@snom360-000413232807) [Feb 12 19:36:09] DEBUG[23197]: chan_sip.c:2445 sip_hangup: update_call_counter(88344) - decrement call limit counter [Feb 12 19:36:09] DEBUG[23197]: chan_sip.c:2227 update_call_counter: Updating call counter for incoming call [Feb 12 19:36:09] Scheduling destruction of call '3c26c37b3d09-bfly826gtsm0@snom360-000413232807' in 32000 ms [Feb 12 19:36:09] set_destination: Parsing for address/port to send to [Feb 12 19:36:09] set_destination: set destination to 10.1.18.2, port 5060 [Feb 12 19:36:09] Reliably Transmitting (no NAT) to 10.1.18.2:5060: BYE sip:88344@10.1.18.2:5060 SIP/2.0 Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK7c2c8c3a;rport From: ;tag=as1b7b7f06 To: "Thomas Gick" ;tag=bajakq6bzy Call-ID: 3c26c37b3d09-bfly826gtsm0@snom360-000413232807 CSeq: 102 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Feb 12 19:36:09] DEBUG[23197]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #85 [Feb 12 19:36:09] DEBUG[23197]: channel.c:3154 ast_do_masquerade: Putting channel Agent/88344 in 8/8 formats [Feb 12 19:36:09] DEBUG[23197]: channel.c:3189 ast_do_masquerade: [Feb 12 19:36:09] Transmitting (NAT) to 10.1.18.2:5060: SIP/2.0 202 Accepted Via: SIP/2.0/UDP 10.1.18.2:5060;branch=z9hG4bK-bv3vz86nb8de;received=10.1.18.2;rport=5060 From: ;tag=3of76qsx41 To: "344" ;tag=as42cf2b76 Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 CSeq: 2 REFER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Released clone lock on 'SIP/88344-0820eda0' [Feb 12 19:36:09] DEBUG[23197]: channel.c:3198 ast_do_masquerade: Done Masquerading Agent/88344 (6) [Feb 12 19:36:09] set_destination: Parsing for address/port to send to [Feb 12 19:36:09] DEBUG[23174]: channel.c:3380 ast_generic_bridge: Didn't get a frame from channel: SIP/88344-0820eda0 [Feb 12 19:36:09] set_destination: set destination to 10.1.18.2, port 5060 [Feb 12 19:36:09] DEBUG[23174]: channel.c:3669 ast_channel_bridge: Bridge stops bridging channels Zap/1-1 and SIP/88344-0820eda0 [Feb 12 19:36:09] Reliably Transmitting (NAT) to 10.1.18.2:5060: NOTIFY sip:88344@10.1.18.2:5060;line=6wijgpup SIP/2.0 Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK10376ea5;rport From: "344" ;tag=as42cf2b76 To: ;tag=3of76qsx41 Contact: Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 CSeq: 103 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: refer;id=2 Subscription-state: terminated;reason=noresource Content-Type: message/sipfrag;version=2.0 Content-Length: 14 SIP/2.0 200 OK --- [Feb 12 19:36:09] DEBUG[23174]: channel.c:1372 ast_hangup: Hanging up zombie 'SIP/88344-0820eda0' [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #86 [Feb 12 19:36:09] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88344 [Feb 12 19:36:09] set_destination: Parsing for address/port to send to [Feb 12 19:36:09] DEBUG[23167]: channel.c:771 channel_find_locked: Avoiding initial deadlock for 'SIP/88344-081ec490' [Feb 12 19:36:09] set_destination: set destination to 10.1.18.2, port 5060 [Feb 12 19:36:09] DEBUG[23174]: pbx.c:2316 __ast_pbx_run: Spawn extension (tenovis_in,89001,4) exited non-zero on 'Zap/1-1' [Feb 12 19:36:09] Reliably Transmitting (NAT) to 10.1.18.2:5060: BYE sip:88344@10.1.18.2:5060;line=6wijgpup SIP/2.0 Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK01876b0e;rport From: "344" ;tag=as42cf2b76 To: ;tag=3of76qsx41 Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 CSeq: 104 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Feb 12 19:36:09] == Spawn extension (tenovis_in, 89001, 4) exited non-zero on 'Zap/1-1' [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #87 [Feb 12 19:36:09] DEBUG[23174]: channel.c:1367 ast_hangup: Hanging up channel 'Zap/1-1' [Feb 12 19:36:09] DEBUG[23174]: chan_zap.c:2309 zt_hangup: zt_hangup(Zap/1-1) [Feb 12 19:36:09] DEBUG[23174]: chan_zap.c:2861 zt_setoption: Set option AUDIO MODE, value: ON(1) on Zap/1-1 [Feb 12 19:36:09] DEBUG[23174]: chan_zap.c:2342 zt_hangup: Hangup: channel: 1 index = 0, normal = 11, callwait = -1, thirdcall = -1 [Feb 12 19:36:09] DEBUG[23174]: chan_zap.c:2491 zt_hangup: Not yet hungup... Calling hangup once with icause, and clearing call [Feb 12 19:36:09] DEBUG[23174]: chan_zap.c:2782 zt_setoption: Set option TDD MODE, value: OFF(0) on Zap/1-1 [Feb 12 19:36:09] DEBUG[23174]: chan_zap.c:1372 update_conf: Updated conferencing on 1, with 0 conference users [Feb 12 19:36:09] DEBUG[23174]: chan_zap.c:2857 zt_setoption: Set option AUDIO MODE, value: OFF(0) on Zap/1-1 [Feb 12 19:36:09] -- Hungup 'Zap/1-1' [Feb 12 19:36:09] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for SIP/88344 - state 2 (In use) [Feb 12 19:36:09] DEBUG[23206]: app_queue.c:500 changethread: Device 'SIP/88344' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Feb 12 19:36:09] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88344 [Feb 12 19:36:09] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for Zap/1 - state 0 (Unknown) [Feb 12 19:36:09] DEBUG[23207]: app_queue.c:500 changethread: Device 'Zap/1' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. [Feb 12 19:36:09] <-- SIP read from 10.1.18.2:5060: SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK10376ea5;rport=5060 From: "344" ;tag=as42cf2b76 To: ;tag=3of76qsx41 Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 CSeq: 103 NOTIFY Contact: ;flow-id=1 Content-Length: 0 [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: SIP/2.0 200 Ok (14) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK10376ea5;rport=5060 (66) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "344" ;tag=as42cf2b76 (47) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: ;tag=3of76qsx41 (59) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 (52) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 103 NOTIFY (16) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Contact: ;flow-id=1 (59) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: Content-Length: 0 (17) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: (0) [Feb 12 19:36:09] --- (8 headers 0 lines) --- [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:1403 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #86 [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:1415 __sip_ack: Stopping retransmission on '7926766d420cfe483e732a6d4ed595c9@10.1.10.72' of Request 103: Match Found [Feb 12 19:36:09] <-- SIP read from 10.1.18.2:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK7c2c8c3a;rport=5060 From: ;tag=as1b7b7f06 To: "Thomas Gick" ;tag=bajakq6bzy Call-ID: 3c26c37b3d09-bfly826gtsm0@snom360-000413232807 CSeq: 102 BYE Contact: ;flow-id=1 User-Agent: snom360/6.5.2 RTP-RxStat: Total_Rx_Pkts=238,Rx_Pkts=238,Rx_Pkts_Lost=0,Remote_Rx_Pkts_Lost=0 RTP-TxStat: Total_Tx_Pkts=150,Tx_Pkts=150,Remote_Tx_Pkts=0 Content-Length: 0 [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: SIP/2.0 200 OK (14) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK7c2c8c3a;rport=5060 (66) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: ;tag=as1b7b7f06 (41) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: "Thomas Gick" ;tag=bajakq6bzy (55) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 3c26c37b3d09-bfly826gtsm0@snom360-000413232807 (55) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 102 BYE (13) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Contact: ;flow-id=1 (59) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: User-Agent: snom360/6.5.2 (25) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: RTP-RxStat: Total_Rx_Pkts=238,Rx_Pkts=238,Rx_Pkts_Lost=0,Remote_Rx_Pkts_Lost=0 (78) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: RTP-TxStat: Total_Tx_Pkts=150,Tx_Pkts=150,Remote_Tx_Pkts=0 (58) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: Content-Length: 0 (17) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 11: (0) [Feb 12 19:36:09] --- (11 headers 0 lines) --- [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:1403 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #85 [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:1415 __sip_ack: Stopping retransmission on '3c26c37b3d09-bfly826gtsm0@snom360-000413232807' of Request 102: Match Found [Feb 12 19:36:09] Destroying call '3c26c37b3d09-bfly826gtsm0@snom360-000413232807' [Feb 12 19:36:09] <-- SIP read from 10.1.18.2:5060: BYE sip:344@10.1.10.72 SIP/2.0 Via: SIP/2.0/UDP 10.1.18.2:5060;branch=z9hG4bK-u90bxhicozt6;rport From: ;tag=3of76qsx41 To: "344" ;tag=as42cf2b76 Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 CSeq: 3 BYE Max-Forwards: 70 Contact: ;flow-id=1 User-Agent: snom360/6.5.2 RTP-RxStat: Total_Rx_Pkts=102,Rx_Pkts=238,Rx_Pkts_Lost=0,Remote_Rx_Pkts_Lost=0 RTP-TxStat: Total_Tx_Pkts=100,Tx_Pkts=150,Remote_Tx_Pkts=0 Content-Length: 0 [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: BYE sip:344@10.1.10.72 SIP/2.0 (30) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.18.2:5060;branch=z9hG4bK-u90bxhicozt6;rport (65) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: ;tag=3of76qsx41 (61) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: "344" ;tag=as42cf2b76 (45) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 (52) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 3 BYE (11) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Max-Forwards: 70 (16) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: Contact: ;flow-id=1 (59) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: User-Agent: snom360/6.5.2 (25) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: RTP-RxStat: Total_Rx_Pkts=102,Rx_Pkts=238,Rx_Pkts_Lost=0,Remote_Rx_Pkts_Lost=0 (78) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: RTP-TxStat: Total_Tx_Pkts=100,Tx_Pkts=150,Remote_Tx_Pkts=0 (58) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 11: Content-Length: 0 (17) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 12: (0) [Feb 12 19:36:09] --- (12 headers 0 lines) --- [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:11377 handle_request: **** Received BYE (8) - Command in SIP BYE [Feb 12 19:36:09] Sending to 10.1.18.2 : 5060 (NAT) [Feb 12 19:36:09] DEBUG[23169]: chan_sip.c:11030 handle_request_bye: Received bye, issuing owner hangup .[Feb 12 19:36:09] Transmitting (NAT) to 10.1.18.2:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.1.18.2:5060;branch=z9hG4bK-u90bxhicozt6;received=10.1.18.2;rport=5060 From: ;tag=3of76qsx41 To: "344" ;tag=as42cf2b76 Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 CSeq: 3 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 X-Asterisk-HangupCause: Normal Clearing --- [Feb 12 19:36:09] DEBUG[23197]: channel.c:3380 ast_generic_bridge: Didn't get a frame from channel: Agent/88344 [Feb 12 19:36:09] DEBUG[23197]: channel.c:3669 ast_channel_bridge: Bridge stops bridging channels Agent/88344 and Zap/2-1 [Feb 12 19:36:09] DEBUG[23197]: channel.c:1367 ast_hangup: Hanging up channel 'Zap/2-1' [Feb 12 19:36:09] DEBUG[23197]: chan_zap.c:2309 zt_hangup: zt_hangup(Zap/2-1) [Feb 12 19:36:09] DEBUG[23197]: chan_zap.c:2861 zt_setoption: Set option AUDIO MODE, value: ON(1) on Zap/2-1 [Feb 12 19:36:09] DEBUG[23197]: chan_zap.c:2342 zt_hangup: Hangup: channel: 2 index = 0, normal = 12, callwait = -1, thirdcall = -1 [Feb 12 19:36:09] DEBUG[23197]: chan_zap.c:2491 zt_hangup: Not yet hungup... Calling hangup once with icause, and clearing call [Feb 12 19:36:09] DEBUG[23197]: chan_zap.c:2782 zt_setoption: Set option TDD MODE, value: OFF(0) on Zap/2-1 [Feb 12 19:36:09] DEBUG[23197]: chan_zap.c:1372 update_conf: Updated conferencing on 2, with 0 conference users [Feb 12 19:36:09] DEBUG[23197]: chan_zap.c:2857 zt_setoption: Set option AUDIO MODE, value: OFF(0) on Zap/2-1 [Feb 12 19:36:09] -- Hungup 'Zap/2-1' [Feb 12 19:36:09] DEBUG[23197]: app_dial.c:1636 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Feb 12 19:36:09] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for Zap/2 - state 0 (Unknown) [Feb 12 19:36:09] DEBUG[23197]: pbx.c:2316 __ast_pbx_run: Spawn extension (sip_in,182,1) exited non-zero on 'Agent/88344' [Feb 12 19:36:09] == Spawn extension (sip_in, 182, 1) exited non-zero on 'Agent/88344' [Feb 12 19:36:09] DEBUG[23208]: app_queue.c:500 changethread: Device 'Zap/2' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. [Feb 12 19:36:09] DEBUG[23197]: channel.c:1367 ast_hangup: Hanging up channel 'Agent/88344' [Feb 12 19:36:09] DEBUG[23197]: chan_agent.c:750 agent_hangup: Hangup called for state Up [Feb 12 19:36:09] DEBUG[23197]: channel.c:1367 ast_hangup: Hanging up channel 'SIP/88344-081ec490' [Feb 12 19:36:09] DEBUG[23197]: chan_sip.c:2437 sip_hangup: Hangup call SIP/88344-081ec490, SIP callid 7926766d420cfe483e732a6d4ed595c9@10.1.10.72) [Feb 12 19:36:09] DEBUG[23197]: chan_sip.c:2445 sip_hangup: update_call_counter(88344) - decrement call limit counter [Feb 12 19:36:09] DEBUG[23197]: chan_sip.c:2227 update_call_counter: Updating call counter for incoming call [Feb 12 19:36:09] DEBUG[23197]: chan_agent.c:772 agent_hangup: Hungup, howlong is 0, autologoff is 0 [Feb 12 19:36:09] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88344 [Feb 12 19:36:09] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for SIP/88344 - state 1 (Not in use) [Feb 12 19:36:09] DEBUG[23167]: chan_sip.c:11927 sip_devicestate: Checking device state for peer 88344 [Feb 12 19:36:09] DEBUG[23209]: app_queue.c:500 changethread: Device 'SIP/88344' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 12 19:36:09] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for Agent/88344 - state 1 (Not in use) [Feb 12 19:36:09] DEBUG[23210]: app_queue.c:506 changethread: Device 'Agent/88344' changed to state '1' (Not in use) [Feb 12 19:36:09] DEBUG[23167]: devicestate.c:187 do_state_change: Changing state for Agent/88344 - state 1 (Not in use) [Feb 12 19:36:09] DEBUG[23211]: app_queue.c:506 changethread: Device 'Agent/88344' changed to state '1' (Not in use) [Feb 12 19:36:10] DEBUG[23169]: chan_sip.c:1195 retrans_pkt: SIP TIMER: Rescheduling retransmission #87 (1) BYE - 8 [Feb 12 19:36:10] DEBUG[23169]: chan_sip.c:1209 retrans_pkt: ** SIP timers: Rescheduling retransmission 2 to 1000 ms (t1 500 ms (Retrans id #87)) [Feb 12 19:36:10] Retransmitting #1 (NAT) to 10.1.18.2:5060: BYE sip:88344@10.1.18.2:5060;line=6wijgpup SIP/2.0 Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK01876b0e;rport From: "344" ;tag=as42cf2b76 To: ;tag=3of76qsx41 Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 CSeq: 104 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Feb 12 19:36:11] DEBUG[23169]: chan_sip.c:1195 retrans_pkt: SIP TIMER: Rescheduling retransmission #87 (2) BYE - 8 [Feb 12 19:36:11] DEBUG[23169]: chan_sip.c:1209 retrans_pkt: ** SIP timers: Rescheduling retransmission 3 to 2000 ms (t1 500 ms (Retrans id #87)) [Feb 12 19:36:11] Retransmitting #2 (NAT) to 10.1.18.2:5060: BYE sip:88344@10.1.18.2:5060;line=6wijgpup SIP/2.0 Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK01876b0e;rport From: "344" ;tag=as42cf2b76 To: ;tag=3of76qsx41 Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 CSeq: 104 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Feb 12 19:36:13] DEBUG[23169]: chan_sip.c:1195 retrans_pkt: SIP TIMER: Rescheduling retransmission #87 (3) BYE - 8 [Feb 12 19:36:13] DEBUG[23169]: chan_sip.c:1209 retrans_pkt: ** SIP timers: Rescheduling retransmission 4 to 4000 ms (t1 500 ms (Retrans id #87)) [Feb 12 19:36:13] Retransmitting #3 (NAT) to 10.1.18.2:5060: BYE sip:88344@10.1.18.2:5060;line=6wijgpup SIP/2.0 Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK01876b0e;rport From: "344" ;tag=as42cf2b76 To: ;tag=3of76qsx41 Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 CSeq: 104 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3183 sip_alloc: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP) [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: NOTIFY sip:88801@10.1.18.4:5060;line=wuyxv403 SIP/2.0 (53) [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK2061b6ca;rport (61) [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "asterisk" ;tag=as71e2935e (57) [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: (44) [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Contact: (34) [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: Call-ID: 083d611128a1a8f4396b1046435aee04@10.1.10.72 (52) [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: CSeq: 102 NOTIFY (16) [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 8: Max-Forwards: 70 (16) [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 9: Event: message-summary (22) [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 10: Content-Type: application/simple-message-summary (48) [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 11: Content-Length: 91 (18) [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 12: (0) [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Messages-Waiting: no (20) [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Message-Account: sip:voicemail@10.1.10.72 (41) [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3466 parse_request: Line: Voice-Message: 0/0 (0/0) (24) [Feb 12 19:36:14] 12 headers, 3 lines [Feb 12 19:36:14] Reliably Transmitting (no NAT) to 10.1.18.4:5060: NOTIFY sip:88801@10.1.18.4:5060;line=wuyxv403 SIP/2.0 Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK2061b6ca;rport From: "asterisk" ;tag=as71e2935e To: Contact: Call-ID: 083d611128a1a8f4396b1046435aee04@10.1.10.72 CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: message-summary Content-Type: application/simple-message-summary Content-Length: 91 Messages-Waiting: no Message-Account: sip:voicemail@10.1.10.72 Voice-Message: 0/0 (0/0) --- [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #88 [Feb 12 19:36:14] Scheduling destruction of call '083d611128a1a8f4396b1046435aee04@10.1.10.72' in 15000 ms [Feb 12 19:36:14] <-- SIP read from 10.1.18.4:5060: SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK2061b6ca;rport=5060 From: "asterisk" ;tag=as71e2935e To: Call-ID: 083d611128a1a8f4396b1046435aee04@10.1.10.72 CSeq: 102 NOTIFY Content-Length: 0 [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 0: SIP/2.0 200 Ok (14) [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK2061b6ca;rport=5060 (66) [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 2: From: "asterisk" ;tag=as71e2935e (57) [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 3: To: (44) [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 4: Call-ID: 083d611128a1a8f4396b1046435aee04@10.1.10.72 (52) [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 5: CSeq: 102 NOTIFY (16) [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 6: Content-Length: 0 (17) [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:3434 parse_request: Header 7: (0) [Feb 12 19:36:14] --- (7 headers 0 lines) --- [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:1403 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #88 [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:1415 __sip_ack: Stopping retransmission on '083d611128a1a8f4396b1046435aee04@10.1.10.72' of Request 102: Match Found [Feb 12 19:36:14] Destroying call '083d611128a1a8f4396b1046435aee04@10.1.10.72' [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:1336 __sip_autodestruct: Auto destroying call '3c26700a222e-4s1fp3v93f07@snom360-0004132346B8' [Feb 12 19:36:14] Destroying call '3c26700a222e-4s1fp3v93f07@snom360-0004132346B8' [Feb 12 19:36:14] DEBUG[23169]: chan_sip.c:1336 __sip_autodestruct: Auto destroying call '3c26700a0c35-ftsl5idl4l5i@snom360-000413232807' [Feb 12 19:36:14] Destroying call '3c26700a0c35-ftsl5idl4l5i@snom360-000413232807' [Feb 12 19:36:17] DEBUG[23169]: chan_sip.c:1195 retrans_pkt: SIP TIMER: Rescheduling retransmission #87 (4) BYE - 8 [Feb 12 19:36:17] DEBUG[23169]: chan_sip.c:1209 retrans_pkt: ** SIP timers: Rescheduling retransmission 5 to 4000 ms (t1 500 ms (Retrans id #87)) [Feb 12 19:36:17] Retransmitting #4 (NAT) to 10.1.18.2:5060: BYE sip:88344@10.1.18.2:5060;line=6wijgpup SIP/2.0 Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK01876b0e;rport From: "344" ;tag=as42cf2b76 To: ;tag=3of76qsx41 Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 CSeq: 104 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Feb 12 19:36:17] DEBUG[23169]: chan_sip.c:1336 __sip_autodestruct: Auto destroying call '3c26700a0000-x4kkws5ejsgn@snom360-000413237C3A' [Feb 12 19:36:17] Destroying call '3c26700a0000-x4kkws5ejsgn@snom360-000413237C3A' [Feb 12 19:36:17] DEBUG[23169]: chan_sip.c:1336 __sip_autodestruct: Auto destroying call '3c26700a2bf2-x4kkws5ejsgn@snom360-0004132346B0' [Feb 12 19:36:17] Destroying call '3c26700a2bf2-x4kkws5ejsgn@snom360-0004132346B0' [Feb 12 19:36:17] DEBUG[23169]: chan_sip.c:1336 __sip_autodestruct: Auto destroying call '3c26700a0000-rmj158vik8vf@snom360-0004132346B5' [Feb 12 19:36:17] Destroying call '3c26700a0000-rmj158vik8vf@snom360-0004132346B5' [Feb 12 19:36:18] DEBUG[23169]: chan_sip.c:1336 __sip_autodestruct: Auto destroying call '3c26700a0271-x4kkws5ejsgn@snom360-0004132346AF' [Feb 12 19:36:18] Destroying call '3c26700a0271-x4kkws5ejsgn@snom360-0004132346AF' [Feb 12 19:36:18] DEBUG[23169]: chan_sip.c:1336 __sip_autodestruct: Auto destroying call '3c26700a445c-x4kkws5ejsgn@snom360-000413237C3B' [Feb 12 19:36:18] Destroying call '3c26700a445c-x4kkws5ejsgn@snom360-000413237C3B' [Feb 12 19:36:20] DEBUG[23169]: chan_sip.c:1336 __sip_autodestruct: Auto destroying call '3c26700c0271-x4kkws5ejsgn@snom360-0004132346B2' [Feb 12 19:36:20] Destroying call '3c26700c0271-x4kkws5ejsgn@snom360-0004132346B2' [Feb 12 19:36:21] DEBUG[23169]: chan_sip.c:1195 retrans_pkt: SIP TIMER: Rescheduling retransmission #87 (5) BYE - 8 [Feb 12 19:36:21] DEBUG[23169]: chan_sip.c:1209 retrans_pkt: ** SIP timers: Rescheduling retransmission 6 to 4000 ms (t1 500 ms (Retrans id #87)) [Feb 12 19:36:21] Retransmitting #5 (NAT) to 10.1.18.2:5060: BYE sip:88344@10.1.18.2:5060;line=6wijgpup SIP/2.0 Via: SIP/2.0/UDP 10.1.10.72:5060;branch=z9hG4bK01876b0e;rport From: "344" ;tag=as42cf2b76 To: ;tag=3of76qsx41 Call-ID: 7926766d420cfe483e732a6d4ed595c9@10.1.10.72 CSeq: 104 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 ---