<--- SIP read from UDP:217.14.196.30:5060 ---> INVITE sip:970227@217.14.196.29:5060 SIP/2.0 Via: SIP/2.0/UDP 217.14.196.30:5060;rport;branch=z9hG4bK-oS1s-314234-1655 From: "89127600023" ;tag=314167dOr1655p0D1793D0t6 To: Call-ID: 1491-251858-314155 CSeq: 2 INVITE User-Agent: Eltex smg_pa_sip smg_pa_sip-3.7.0.20 Max-Forwards: 70 Contact: Accept: multipart/mixed, application/sdp Allow: INVITE, ACK, BYE, CANCEL, PRACK, REGISTER, INFO, REFER, NOTIFY, OPTIONS, UPDATE Supported: replaces Content-Type: application/sdp Content-Length: 235 v=0 o=- 1655 314528 IN IP4 217.14.196.30 s=SMG SIP session c=IN IP4 217.14.196.30 t=0 0 m=audio 26678 RTP/AVP 8 0 18 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=ptime:30 a=sendrecv <-------------> [2017-04-04 00:35:44.99018] DEBUG[24876] chan_sip.c: Header 0 [ 44]: INVITE sip:970227@217.14.196.29:5060 SIP/2.0 [2017-04-04 00:35:44.99019] DEBUG[24876] chan_sip.c: Header 1 [ 73]: Via: SIP/2.0/UDP 217.14.196.30:5060;rport;branch=z9hG4bK-oS1s-314234-1655 [2017-04-04 00:35:44.99019] DEBUG[24876] chan_sip.c: Header 2 [ 91]: From: "89127600023" ;tag=314167dOr1655p0D1793D0t6 [2017-04-04 00:35:44.99019] DEBUG[24876] chan_sip.c: Header 3 [ 41]: To: [2017-04-04 00:35:44.99019] DEBUG[24876] chan_sip.c: Header 4 [ 27]: Call-ID: 1491-251858-314155 [2017-04-04 00:35:44.99019] DEBUG[24876] chan_sip.c: Header 5 [ 14]: CSeq: 2 INVITE [2017-04-04 00:35:44.99020] DEBUG[24876] chan_sip.c: Header 6 [ 48]: User-Agent: Eltex smg_pa_sip smg_pa_sip-3.7.0.20 [2017-04-04 00:35:44.99020] DEBUG[24876] chan_sip.c: Header 7 [ 16]: Max-Forwards: 70 [2017-04-04 00:35:44.99020] DEBUG[24876] chan_sip.c: Header 8 [ 45]: Contact: [2017-04-04 00:35:44.99020] DEBUG[24876] chan_sip.c: Header 9 [ 40]: Accept: multipart/mixed, application/sdp [2017-04-04 00:35:44.99020] DEBUG[24876] chan_sip.c: Header 10 [ 86]: Allow: INVITE, ACK, BYE, CANCEL, PRACK, REGISTER, INFO, REFER, NOTIFY, OPTIONS, UPDATE [2017-04-04 00:35:44.99021] DEBUG[24876] chan_sip.c: Header 11 [ 19]: Supported: replaces [2017-04-04 00:35:44.99021] DEBUG[24876] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [2017-04-04 00:35:44.99021] DEBUG[24876] chan_sip.c: Header 13 [ 19]: Content-Length: 235 [2017-04-04 00:35:44.99021] DEBUG[24876] chan_sip.c: Header 14 [ 0]: [2017-04-04 00:35:44.99021] DEBUG[24876] chan_sip.c: Body 0 [ 3]: v=0 [2017-04-04 00:35:44.99021] DEBUG[24876] chan_sip.c: Body 1 [ 36]: o=- 1655 314528 IN IP4 217.14.196.30 [2017-04-04 00:35:44.99022] DEBUG[24876] chan_sip.c: Body 2 [ 17]: s=SMG SIP session [2017-04-04 00:35:44.99022] DEBUG[24876] chan_sip.c: Body 3 [ 22]: c=IN IP4 217.14.196.30 [2017-04-04 00:35:44.99022] DEBUG[24876] chan_sip.c: Body 4 [ 5]: t=0 0 [2017-04-04 00:35:44.99022] DEBUG[24876] chan_sip.c: Body 5 [ 28]: m=audio 26678 RTP/AVP 8 0 18 [2017-04-04 00:35:44.99022] DEBUG[24876] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [2017-04-04 00:35:44.99022] DEBUG[24876] chan_sip.c: Body 7 [ 20]: a=rtpmap:0 PCMU/8000 [2017-04-04 00:35:44.99023] DEBUG[24876] chan_sip.c: Body 8 [ 21]: a=rtpmap:18 G729/8000 [2017-04-04 00:35:44.99023] DEBUG[24876] chan_sip.c: Body 9 [ 19]: a=fmtp:18 annexb=no [2017-04-04 00:35:44.99023] DEBUG[24876] chan_sip.c: Body 10 [ 10]: a=ptime:30 [2017-04-04 00:35:44.99023] DEBUG[24876] chan_sip.c: Body 11 [ 10]: a=sendrecv [2017-04-04 00:35:44.99023] VERBOSE[24876] chan_sip.c: --- (14 headers 12 lines) --- [2017-04-04 00:35:44.99024] DEBUG[24876] chan_sip.c: = Looking for Call ID: 1491-251858-314155 (Checking From) --From tag 314167dOr1655p0D1793D0t6 --To-tag [2017-04-04 00:35:44.99027] DEBUG[24876] acl.c: For destination '217.14.196.30', our source address is '217.14.196.29'. [2017-04-04 00:35:44.99028] DEBUG[24876] chan_sip.c: Setting AST_TRANSPORT_UDP with address 217.14.196.29:5060 [2017-04-04 00:35:44.99028] DEBUG[24876] netsock2.c: Splitting '217.14.196.30:5060' into... [2017-04-04 00:35:44.99029] DEBUG[24876] netsock2.c: ...host '217.14.196.30' and port '5060'. [2017-04-04 00:35:44.99029] VERBOSE[24876] chan_sip.c: Sending to 217.14.196.30:5060 (no NAT) [2017-04-04 00:35:44.99030] DEBUG[24876] chan_sip.c: Allocating new SIP dialog for 1491-251858-314155 - INVITE (No RTP) [2017-04-04 00:35:44.99030] DEBUG[24876][C-00116155] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [2017-04-04 00:35:44.99031] DEBUG[24876][C-00116155] sip/reqresp_parser.c: Begin: parsing SIP "Supported: replaces" [2017-04-04 00:35:44.99031] DEBUG[24876][C-00116155] sip/reqresp_parser.c: Found SIP option: -replaces- [2017-04-04 00:35:44.99031] DEBUG[24876][C-00116155] sip/reqresp_parser.c: Matched SIP option: replaces [2017-04-04 00:35:44.99032] DEBUG[24876][C-00116155] netsock2.c: Splitting '217.14.196.30:5060' into... [2017-04-04 00:35:44.99032] DEBUG[24876][C-00116155] netsock2.c: ...host '217.14.196.30' and port '5060'. [2017-04-04 00:35:44.99032] VERBOSE[24876][C-00116155] chan_sip.c: Sending to 217.14.196.30:5060 (no NAT) [2017-04-04 00:35:44.99033] DEBUG[24876][C-00116155] chan_sip.c: Initializing initreq for method INVITE - callid 1491-251858-314155 [2017-04-04 00:35:44.99033] VERBOSE[24876][C-00116155] chan_sip.c: Using INVITE request as basis request - 1491-251858-314155 [2017-04-04 00:35:44.99034] DEBUG[24876][C-00116155] netsock2.c: Splitting '217.14.196.30' into... [2017-04-04 00:35:44.99034] DEBUG[24876][C-00116155] netsock2.c: ...host '217.14.196.30' and port ''. [2017-04-04 00:35:44.99037] VERBOSE[24876][C-00116155] chan_sip.c: Found peer 'sw1_to_smg2016' for '89127600023' from 217.14.196.30:5060 [2017-04-04 00:35:44.99038] DEBUG[24876][C-00116155] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f338a1fba20' [2017-04-04 00:35:44.99041] DEBUG[24876][C-00116155] res_rtp_asterisk.c: Allocated port 48676 for RTP instance '0x7f338a1fba20' [2017-04-04 00:35:44.99042] DEBUG[24876][C-00116155] res_rtp_asterisk.c: Creating ICE session 217.14.196.29:48676 (48676) for RTP instance '0x7f338a1fba20' [2017-04-04 00:35:44.99056] DEBUG[24876][C-00116155] netsock2.c: Splitting '192.168.10.77' into... [2017-04-04 00:35:44.99057] DEBUG[24876][C-00116155] netsock2.c: ...host '192.168.10.77' and port ''. [2017-04-04 00:35:44.99057] DEBUG[24876][C-00116155] netsock2.c: Splitting '192.168.10.77' into... [2017-04-04 00:35:44.99058] DEBUG[24876][C-00116155] netsock2.c: ...host '192.168.10.77' and port ''. [2017-04-04 00:35:44.99058] DEBUG[24876][C-00116155] netsock2.c: Splitting '217.14.196.29' into... [2017-04-04 00:35:44.99058] DEBUG[24876][C-00116155] netsock2.c: ...host '217.14.196.29' and port ''. [2017-04-04 00:35:44.99059] DEBUG[24876][C-00116155] netsock2.c: Splitting '217.14.196.29' into... [2017-04-04 00:35:44.99059] DEBUG[24876][C-00116155] netsock2.c: ...host '217.14.196.29' and port ''. [2017-04-04 00:35:44.99059] DEBUG[24876][C-00116155] rtp_engine.c: RTP instance '0x7f338a1fba20' is setup and ready to go [2017-04-04 00:35:44.99060] DEBUG[24876][C-00116155] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [2017-04-04 00:35:44.99061] DEBUG[24876][C-00116155] acl.c: Attached to given IP address [2017-04-04 00:35:44.99061] DEBUG[24876][C-00116155] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f338a1fba20' [2017-04-04 00:35:44.99063] DEBUG[24876][C-00116155] chan_sip.c: Setting NAT on RTP to Off [2017-04-04 00:35:44.99065] DEBUG[24876][C-00116155] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [2017-04-04 00:35:44.99065] DEBUG[24876][C-00116155] chan_sip.c: Processing session-level SDP o=- 1655 314528 IN IP4 217.14.196.30... OK. [2017-04-04 00:35:44.99065] DEBUG[24876][C-00116155] chan_sip.c: Processing session-level SDP s=SMG SIP session... UNSUPPORTED OR FAILED. [2017-04-04 00:35:44.99065] DEBUG[24876][C-00116155] netsock2.c: Splitting '217.14.196.30' into... [2017-04-04 00:35:44.99066] DEBUG[24876][C-00116155] netsock2.c: ...host '217.14.196.30' and port ''. [2017-04-04 00:35:44.99066] DEBUG[24876][C-00116155] chan_sip.c: Processing session-level SDP c=IN IP4 217.14.196.30... OK. [2017-04-04 00:35:44.99066] DEBUG[24876][C-00116155] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [2017-04-04 00:35:44.99067] VERBOSE[24876][C-00116155] chan_sip.c: Found RTP audio format 8 [2017-04-04 00:35:44.99067] DEBUG[24876][C-00116155] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7f336c3d9470 [2017-04-04 00:35:44.99067] VERBOSE[24876][C-00116155] chan_sip.c: Found RTP audio format 0 [2017-04-04 00:35:44.99067] DEBUG[24876][C-00116155] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7f336c3d9470 [2017-04-04 00:35:44.99068] VERBOSE[24876][C-00116155] chan_sip.c: Found RTP audio format 18 [2017-04-04 00:35:44.99068] DEBUG[24876][C-00116155] rtp_engine.c: Setting tx payload type 18 based on m type on 0x7f336c3d9470 [2017-04-04 00:35:44.99070] VERBOSE[24876][C-00116155] chan_sip.c: Found audio description format PCMA for ID 8 [2017-04-04 00:35:44.99070] DEBUG[24876][C-00116155] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [2017-04-04 00:35:44.99070] VERBOSE[24876][C-00116155] chan_sip.c: Found audio description format PCMU for ID 0 [2017-04-04 00:35:44.99070] DEBUG[24876][C-00116155] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [2017-04-04 00:35:44.99071] VERBOSE[24876][C-00116155] chan_sip.c: Found audio description format G729 for ID 18 [2017-04-04 00:35:44.99071] DEBUG[24876][C-00116155] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK. [2017-04-04 00:35:44.99072] DEBUG[24876][C-00116155] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=no... OK. [2017-04-04 00:35:44.99072] DEBUG[24876][C-00116155] chan_sip.c: Processing media-level (audio) SDP a=ptime:30... OK. [2017-04-04 00:35:44.99072] DEBUG[24876][C-00116155] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [2017-04-04 00:35:44.99073] VERBOSE[24876][C-00116155] chan_sip.c: Capabilities: us - (ulaw|alaw|g729), peer - audio=(ulaw|alaw|g729)/video=(nothing)/text=(nothing), combined - (ulaw|alaw|g729) [2017-04-04 00:35:44.99074] VERBOSE[24876][C-00116155] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x0 (nothing), combined - 0x0 (nothing) [2017-04-04 00:35:44.99074] DEBUG[24876][C-00116155] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [2017-04-04 00:35:44.99076] DEBUG[24876][C-00116155] acl.c: For destination '217.14.196.30', our source address is '217.14.196.29'. [2017-04-04 00:35:44.99076] DEBUG[24876][C-00116155] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f338a1fba20' [2017-04-04 00:35:44.99076] VERBOSE[24876][C-00116155] chan_sip.c: Peer audio RTP is at port 217.14.196.30:26678 [2017-04-04 00:35:44.99077] DEBUG[24876][C-00116155] rtp_engine.c: Copying payload 0 (0x7f338a238cf8) from 0x7f336c3d9470 to 0x7f338a1fbbe8 [2017-04-04 00:35:44.99077] DEBUG[24876][C-00116155] rtp_engine.c: Copying payload 8 (0x7f3356071b48) from 0x7f336c3d9470 to 0x7f338a1fbbe8 [2017-04-04 00:35:44.99077] DEBUG[24876][C-00116155] rtp_engine.c: Copying payload 18 (0x7f338a655cb8) from 0x7f336c3d9470 to 0x7f338a1fbbe8 [2017-04-04 00:35:44.99077] DEBUG[24876][C-00116155] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7f338a1fba20' [2017-04-04 00:35:44.99078] DEBUG[24876][C-00116155] chan_sip.c: We're settling with these formats: (ulaw|alaw|g729) [2017-04-04 00:35:44.99078] DEBUG[24876][C-00116155] chan_sip.c: Checking SIP call limits for device [2017-04-04 00:35:44.99078] DEBUG[24876][C-00116155] chan_sip.c: Updating call counter for incoming call [2017-04-04 00:35:44.99079] DEBUG[24876][C-00116155] chan_sip.c: Call from peer 'sw1_to_smg2016' is 1 out of 2147483647 [2017-04-04 00:35:44.99081] DEBUG[24876][C-00116155] netsock2.c: Splitting '217.14.196.29:5060' into... [2017-04-04 00:35:44.99081] DEBUG[24876][C-00116155] netsock2.c: ...host '217.14.196.29' and port ''. [2017-04-04 00:35:44.99081] DEBUG[24876][C-00116155] netsock2.c: Splitting '217.14.196.30' into... [2017-04-04 00:35:44.99081] DEBUG[24876][C-00116155] netsock2.c: ...host '217.14.196.30' and port ''. [2017-04-04 00:35:44.99082] VERBOSE[24876][C-00116155] chan_sip.c: Looking for 970227 in incomming (domain 217.14.196.29) [2017-04-04 00:35:44.99082] DEBUG[24815] devicestate.c: No provider found, checking channel drivers for SIP - sw1_to_smg2016 [2017-04-04 00:35:44.99083] DEBUG[24815] chan_sip.c: Checking device state for peer sw1_to_smg2016 [2017-04-04 00:35:44.99084] DEBUG[24815] devicestate.c: Changing state for SIP/sw1_to_smg2016 - state 2 (In use) [2017-04-04 00:35:44.99095] DEBUG[5169] manager.c: Examining AMI event: Event: DeviceStateChange Privilege: call,all SystemName: sw-new.mark-itt.ru Device: SIP/sw1_to_smg2016 State: INUSE [2017-04-04 00:35:44.99127] DEBUG[24886] app_queue.c: Device 'SIP/sw1_to_smg2016' changed to state '2' (In use) but we don't care because they're not a member of any queue. [2017-04-04 00:35:44.99137] DEBUG[24876][C-00116155] chan_sip.c: *** Our native formats are (ulaw) [2017-04-04 00:35:44.99137] DEBUG[24876][C-00116155] chan_sip.c: *** Joint capabilities are (ulaw|alaw|g729) [2017-04-04 00:35:44.99137] DEBUG[24876][C-00116155] chan_sip.c: *** Our capabilities are (ulaw|alaw|g729) [2017-04-04 00:35:44.99138] DEBUG[24876][C-00116155] chan_sip.c: *** AST_CODEC_CHOOSE formats are ulaw [2017-04-04 00:35:44.99138] DEBUG[24876][C-00116155] chan_sip.c: This channel will not be able to handle video. [2017-04-04 00:35:44.99139] DEBUG[24876][C-00116155] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21 [2017-04-04 00:35:44.99140] DEBUG[24876][C-00116155] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116 [2017-04-04 00:35:44.99138] DEBUG[5169] manager.c: Examining AMI event: Event: Newchannel Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: ConnectedLineName: Language: en AccountCode: Context: incomming Exten: 970227 Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 [2017-04-04 00:35:44.99148] VERBOSE[24876][C-00116155] sip/route.c: sip_route_dump: route/path hop: [2017-04-04 00:35:44.99150] DEBUG[24876][C-00116155] chan_sip.c: SIP/sw1_to_smg2016-001f9631: New call is still down.... Trying... [2017-04-04 00:35:44.99152] VERBOSE[24876][C-00116155] chan_sip.c: <--- Transmitting (no NAT) to 217.14.196.30:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 217.14.196.30:5060;branch=z9hG4bK-oS1s-314234-1655;received=217.14.196.30;rport=5060 From: "89127600023" ;tag=314167dOr1655p0D1793D0t6 To: Call-ID: 1491-251858-314155 CSeq: 2 INVITE Server: MarkTEL Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Session-Expires: 1800;refresher=uas Contact: Content-Length: 0 <------------> [2017-04-04 00:35:44.99153] DEBUG[24876][C-00116155] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 217.14.196.30:5060 [2017-04-04 00:35:44.99162] DEBUG[24815] devicestate.c: No provider found, checking channel drivers for SIP - sw1_to_smg2016 [2017-04-04 00:35:44.99162] DEBUG[5169] manager.c: Examining AMI event: Event: Newstate Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: ConnectedLineName: Language: ru AccountCode: Context: incomming Exten: 970227 Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 [2017-04-04 00:35:44.99163] DEBUG[24815] chan_sip.c: Checking device state for peer sw1_to_smg2016 [2017-04-04 00:35:44.99163] DEBUG[24815] devicestate.c: Changing state for SIP/sw1_to_smg2016 - state 2 (In use) [2017-04-04 00:35:44.99169] DEBUG[24876] chan_sip.c: SIP TIMER: Not rescheduling id #424:OPTIONS (Method 3) (No timer T1) [2017-04-04 00:35:44.99169] DEBUG[29878][C-00116155] pbx_variables.c: Function CALLERID(num) result is '89127600023' [2017-04-04 00:35:44.99171] DEBUG[29878][C-00116155] pbx_variables.c: Result of 'EXTEN' is '970227' [2017-04-04 00:35:44.99170] VERBOSE[24876] chan_sip.c: Retransmitting #1 (NAT) to 192.168.12.107:5061: OPTIONS sip:70000@192.168.12.107:5061 SIP/2.0 Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK732e6bc4;rport Max-Forwards: 70 From: "MarkTEL" ;tag=as2113841d To: Contact: Call-ID: 0c2e94f623442f89179ff02c77e8f179@217.14.196.29:5060 CSeq: 102 OPTIONS User-Agent: MarkTEL Date: Mon, 03 Apr 2017 20:35:43 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 --- [2017-04-04 00:35:44.99171] DEBUG[29878][C-00116155] pbx.c: Launching 'NoOp' [2017-04-04 00:35:44.99171] DEBUG[24876] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.12.107:5061 [2017-04-04 00:35:44.99174] DEBUG[24876] chan_sip.c: Auto destroying SIP dialog '11a041b01317be7c3d60f95a0af3b0fa@92.55.59.39:5060' [2017-04-04 00:35:44.99177] DEBUG[24876] chan_sip.c: Destroying SIP dialog 11a041b01317be7c3d60f95a0af3b0fa@92.55.59.39:5060 [2017-04-04 00:35:44.99177] DEBUG[5169] manager.c: Examining AMI event: Event: Newexten Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: ConnectedLineName: Language: ru AccountCode: Context: incomming Exten: 970227 Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 Extension: 970227 Application: NoOp AppData: INCOMMING CALL FROM 89127600023 TO 970227 [2017-04-04 00:35:44.99178] VERBOSE[24876] chan_sip.c: Really destroying SIP dialog '11a041b01317be7c3d60f95a0af3b0fa@92.55.59.39:5060' Method: OPTIONS [2017-04-04 00:35:44.99180] VERBOSE[24876] chan_sip.c: <--- SIP read from UDP:192.168.37.31:5061 ---> NOTIFY sip:softswitch.mark-itt.ru SIP/2.0 Via: SIP/2.0/UDP 192.168.37.31:5061;branch=z9hG4bK-8112a23b From: ;tag=a0e8dc3b76de1928o1 To: Call-ID: f3fd1a1b-3833f4c8@192.168.37.31 CSeq: 43587 NOTIFY Max-Forwards: 70 Contact: Event: keep-alive User-Agent: Cisco/SPA122-1.1.0(011) Content-Length: 0 <-------------> [2017-04-04 00:35:44.99181] DEBUG[24876] chan_sip.c: Header 0 [ 41]: NOTIFY sip:softswitch.mark-itt.ru SIP/2.0 [2017-04-04 00:35:44.99182] DEBUG[24876] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 192.168.37.31:5061;branch=z9hG4bK-8112a23b [2017-04-04 00:35:44.99182] DEBUG[24876] chan_sip.c: Header 2 [ 57]: From: ;tag=a0e8dc3b76de1928o1 [2017-04-04 00:35:44.99182] DEBUG[24876] chan_sip.c: Header 3 [ 32]: To: [2017-04-04 00:35:44.99182] DEBUG[24876] chan_sip.c: Header 4 [ 40]: Call-ID: f3fd1a1b-3833f4c8@192.168.37.31 [2017-04-04 00:35:44.99182] DEBUG[24876] chan_sip.c: Header 5 [ 18]: CSeq: 43587 NOTIFY [2017-04-04 00:35:44.99182] DEBUG[24876] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [2017-04-04 00:35:44.99183] DEBUG[24876] chan_sip.c: Header 7 [ 38]: Contact: [2017-04-04 00:35:44.99183] DEBUG[24876] chan_sip.c: Header 8 [ 17]: Event: keep-alive [2017-04-04 00:35:44.99183] DEBUG[24876] chan_sip.c: Header 9 [ 35]: User-Agent: Cisco/SPA122-1.1.0(011) [2017-04-04 00:35:44.99183] DEBUG[24876] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [2017-04-04 00:35:44.99183] VERBOSE[24876] chan_sip.c: --- (11 headers 0 lines) --- [2017-04-04 00:35:44.99184] DEBUG[24876] chan_sip.c: = Looking for Call ID: f3fd1a1b-3833f4c8@192.168.37.31 (Checking From) --From tag a0e8dc3b76de1928o1 --To-tag [2017-04-04 00:35:44.99184] DEBUG[29878][C-00116155] pbx_variables.c: Result of 'EXTEN' is '970227' [2017-04-04 00:35:44.99185] DEBUG[29878][C-00116155] pbx.c: Launching 'Gosub' [2017-04-04 00:35:44.99185] DEBUG[24876] chan_sip.c: **** Received NOTIFY (4) - Command in SIP NOTIFY [2017-04-04 00:35:44.99186] DEBUG[24876] chan_sip.c: Got NOTIFY Event: keep-alive [2017-04-04 00:35:44.99191] VERBOSE[24876] chan_sip.c: <--- Transmitting (no NAT) to 192.168.37.31:5061 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.37.31:5061;branch=z9hG4bK-8112a23b;received=192.168.37.31 From: ;tag=a0e8dc3b76de1928o1 To: ;tag=as36fbb4b9 Call-ID: f3fd1a1b-3833f4c8@192.168.37.31 CSeq: 43587 NOTIFY Server: MarkTEL Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 <------------> [2017-04-04 00:35:44.99192] DEBUG[24876] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.37.31:5061 [2017-04-04 00:35:44.99194] VERBOSE[24876] chan_sip.c: Scheduling destruction of SIP dialog 'f3fd1a1b-3833f4c8@192.168.37.31' in 32000 ms (Method: NOTIFY) [2017-04-04 00:35:44.99193] DEBUG[5169] manager.c: Examining AMI event: Event: Newexten Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: ConnectedLineName: Language: ru AccountCode: Context: incomming Exten: 970227 Priority: 2 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 Extension: 970227 Application: Gosub AppData: Modificators_mod_1_sub,970227,1 [2017-04-04 00:35:44.99193] DEBUG[29878][C-00116155] app_stack.c: Channel SIP/sw1_to_smg2016-001f9631 has no datastore, so we're allocating one. [2017-04-04 00:35:44.99201] DEBUG[29878][C-00116155] pbx.c: Launching 'Return' [2017-04-04 00:35:44.99206] DEBUG[5169] manager.c: Examining AMI event: Event: Newexten Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: ConnectedLineName: Language: ru AccountCode: Context: Modificators_mod_1_sub Exten: 970227 Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 Extension: 970227 Application: Return AppData: [2017-04-04 00:35:44.99214] DEBUG[29878][C-00116155] pbx_variables.c: Result of 'EXTEN' is '970227' [2017-04-04 00:35:44.99214] DEBUG[29878][C-00116155] pbx.c: Launching 'Gosub' [2017-04-04 00:35:44.99219] DEBUG[5169] manager.c: Examining AMI event: Event: Newexten Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: ConnectedLineName: Language: ru AccountCode: Context: incomming Exten: 970227 Priority: 3 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 Extension: 970227 Application: Gosub AppData: Dial_in_SIX-check_sub,970227,1 [2017-04-04 00:35:44.99222] DEBUG[29878][C-00116155] pbx_variables.c: Result of 'EXTEN' is '970227' [2017-04-04 00:35:44.99228] DEBUG[29878][C-00116155] pbx_variables.c: Function DIALPLAN_EXISTS(forwardotboi,970227,1) result is '0' [2017-04-04 00:35:44.99230] DEBUG[29878][C-00116155] pbx_variables.c: Expression result is '0' [2017-04-04 00:35:44.99231] DEBUG[29878][C-00116155] pbx.c: Launching 'GotoIf' [2017-04-04 00:35:44.99237] DEBUG[29878][C-00116155] pbx_variables.c: Result of 'EXTEN' is '970227' [2017-04-04 00:35:44.99237] DEBUG[5169] manager.c: Examining AMI event: Event: Newexten Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: ConnectedLineName: Language: ru AccountCode: Context: Dial_in_SIX-check_sub Exten: 970227 Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 Extension: 970227 Application: GotoIf AppData: 0?600:2 [2017-04-04 00:35:44.99240] DEBUG[29878][C-00116155] pbx_variables.c: Function DIALPLAN_EXISTS(Dial_in_SIX-call_redirect,970227,2) result is '0' [2017-04-04 00:35:44.99241] DEBUG[29878][C-00116155] pbx_variables.c: Expression result is '0' [2017-04-04 00:35:44.99241] DEBUG[29878][C-00116155] pbx.c: Launching 'GotoIf' [2017-04-04 00:35:44.99247] DEBUG[29878][C-00116155] pbx_variables.c: Result of 'EXTEN' is '970227' [2017-04-04 00:35:44.99246] DEBUG[5169] manager.c: Examining AMI event: Event: Newexten Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: ConnectedLineName: Language: ru AccountCode: Context: Dial_in_SIX-check_sub Exten: 970227 Priority: 2 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 Extension: 970227 Application: GotoIf AppData: 0?100:3 [2017-04-04 00:35:44.99248] DEBUG[29878][C-00116155] pbx_variables.c: Function DIALPLAN_EXISTS(Dial_in_SIX-call_ivr,970227,1) result is '0' [2017-04-04 00:35:44.99249] DEBUG[29878][C-00116155] pbx_variables.c: Expression result is '0' [2017-04-04 00:35:44.99249] DEBUG[29878][C-00116155] pbx.c: Launching 'GotoIf' [2017-04-04 00:35:44.99254] DEBUG[29878][C-00116155] pbx_variables.c: Result of 'EXTEN' is '970227' [2017-04-04 00:35:44.99254] DEBUG[5169] manager.c: Examining AMI event: Event: Newexten Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: ConnectedLineName: Language: ru AccountCode: Context: Dial_in_SIX-check_sub Exten: 970227 Priority: 3 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 Extension: 970227 Application: GotoIf AppData: 0?200:4 [2017-04-04 00:35:44.99257] DEBUG[29878][C-00116155] pbx_variables.c: Function DIALPLAN_EXISTS(mark_company,970227,1) result is '0' [2017-04-04 00:35:44.99258] DEBUG[29878][C-00116155] pbx_variables.c: Expression result is '0' [2017-04-04 00:35:44.99258] DEBUG[29878][C-00116155] pbx.c: Launching 'GotoIf' [2017-04-04 00:35:44.99263] DEBUG[5169] manager.c: Examining AMI event: Event: Newexten Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: ConnectedLineName: Language: ru AccountCode: Context: Dial_in_SIX-check_sub Exten: 970227 Priority: 4 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 Extension: 970227 Application: GotoIf AppData: 0?500:5 [2017-04-04 00:35:44.99268] DEBUG[29878][C-00116155] pbx_variables.c: Result of 'EXTEN' is '970227' [2017-04-04 00:35:44.99272] DEBUG[29878][C-00116155] pbx_variables.c: Function DIALPLAN_EXISTS(Dial_in_SIX-call_gw,970227,1) result is '0' [2017-04-04 00:35:44.99273] DEBUG[29878][C-00116155] pbx_variables.c: Expression result is '0' [2017-04-04 00:35:44.99273] DEBUG[29878][C-00116155] pbx.c: Launching 'GotoIf' [2017-04-04 00:35:44.99279] DEBUG[29878][C-00116155] pbx_variables.c: Result of 'EXTEN' is '970227' [2017-04-04 00:35:44.99282] DEBUG[5169] manager.c: Examining AMI event: Event: Newexten Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: ConnectedLineName: Language: ru AccountCode: Context: Dial_in_SIX-check_sub Exten: 970227 Priority: 5 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 Extension: 970227 Application: GotoIf AppData: 0?300:6 [2017-04-04 00:35:44.99319] DEBUG[29878][C-00116155] pbx_variables.c: Function DIALPLAN_EXISTS(Dial_in_SIX-call_direct,970227,1) result is '1' [2017-04-04 00:35:44.99321] DEBUG[29878][C-00116155] pbx_variables.c: Expression result is '1' [2017-04-04 00:35:44.99321] DEBUG[29878][C-00116155] pbx.c: Launching 'GotoIf' [2017-04-04 00:35:44.99326] DEBUG[5169] manager.c: Examining AMI event: Event: Newexten Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: ConnectedLineName: Language: ru AccountCode: Context: Dial_in_SIX-check_sub Exten: 970227 Priority: 6 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 Extension: 970227 Application: GotoIf AppData: 1?400:900 [2017-04-04 00:35:44.99329] DEBUG[29878][C-00116155] pbx_variables.c: Result of 'EXTEN' is '970227' [2017-04-04 00:35:44.99329] DEBUG[29878][C-00116155] pbx.c: Launching 'Goto' [2017-04-04 00:35:44.99332] DEBUG[24876] chan_sip.c: Allocating new SIP dialog for 76d0265c52390bb7240c5ddd277b3673@217.14.196.29:5060 - OPTIONS (No RTP) [2017-04-04 00:35:44.99334] DEBUG[24876] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2017-04-04 00:35:44.99335] DEBUG[5169] manager.c: Examining AMI event: Event: Newexten Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: ConnectedLineName: Language: ru AccountCode: Context: Dial_in_SIX-check_sub Exten: 970227 Priority: 400 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 Extension: 970227 Application: Goto AppData: Dial_in_SIX-call_direct,970227,1 [2017-04-04 00:35:44.99336] DEBUG[24876] acl.c: For destination '192.168.117.172', our source address is '217.14.196.29'. [2017-04-04 00:35:44.99336] DEBUG[24876] chan_sip.c: Setting AST_TRANSPORT_UDP with address 217.14.196.29:5060 [2017-04-04 00:35:44.99338] DEBUG[24876] chan_sip.c: SIP call-id changed from '76d0265c52390bb7240c5ddd277b3673@217.14.196.29:5060' to '55ff2dcf0d85efc94b562ec6737b8114@217.14.196.29:5060' [2017-04-04 00:35:44.99340] DEBUG[24876] chan_sip.c: Initializing initreq for method OPTIONS - callid 55ff2dcf0d85efc94b562ec6737b8114@217.14.196.29:5060 [2017-04-04 00:35:44.99340] DEBUG[24876] chan_sip.c: Header 0 [ 46]: OPTIONS sip:35913@192.168.117.172:5060 SIP/2.0 [2017-04-04 00:35:44.99340] DEBUG[24876] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK2b65cdb1;rport [2017-04-04 00:35:44.99341] DEBUG[24876] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2017-04-04 00:35:44.99341] DEBUG[24876] chan_sip.c: Header 3 [ 58]: From: "MarkTEL" ;tag=as73f2bb59 [2017-04-04 00:35:44.99341] DEBUG[24876] chan_sip.c: Header 4 [ 36]: To: [2017-04-04 00:35:44.99341] DEBUG[24876] chan_sip.c: Header 5 [ 41]: Contact: [2017-04-04 00:35:44.99341] DEBUG[24876] chan_sip.c: Header 6 [ 60]: Call-ID: 55ff2dcf0d85efc94b562ec6737b8114@217.14.196.29:5060 [2017-04-04 00:35:44.99342] DEBUG[24876] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [2017-04-04 00:35:44.99342] DEBUG[24876] chan_sip.c: Header 8 [ 19]: User-Agent: MarkTEL [2017-04-04 00:35:44.99342] DEBUG[24876] chan_sip.c: Header 9 [ 35]: Date: Mon, 03 Apr 2017 20:35:44 GMT [2017-04-04 00:35:44.99342] DEBUG[24876] chan_sip.c: Header 10 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [2017-04-04 00:35:44.99342] DEBUG[24876] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2017-04-04 00:35:44.99343] VERBOSE[24876] chan_sip.c: Reliably Transmitting (NAT) to 192.168.117.172:5060: OPTIONS sip:35913@192.168.117.172:5060 SIP/2.0 Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK2b65cdb1;rport Max-Forwards: 70 From: "MarkTEL" ;tag=as73f2bb59 To: Contact: Call-ID: 55ff2dcf0d85efc94b562ec6737b8114@217.14.196.29:5060 CSeq: 102 OPTIONS User-Agent: MarkTEL Date: Mon, 03 Apr 2017 20:35:44 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 --- [2017-04-04 00:35:44.99344] DEBUG[24876] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18544 [2017-04-04 00:35:44.99344] DEBUG[24876] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.117.172:5060 [2017-04-04 00:35:44.99344] DEBUG[29878][C-00116155] pbx.c: Launching 'Dial' [2017-04-04 00:35:44.99352] DEBUG[5169] manager.c: Examining AMI event: Event: Newexten Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: ConnectedLineName: Language: ru AccountCode: Context: Dial_in_SIX-call_direct Exten: 970227 Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 Extension: 970227 Application: Dial AppData: SIP/55909&SIP/34673 [2017-04-04 00:35:44.99404] DEBUG[29878][C-00116155] chan_sip.c: Asked to create a SIP channel with formats: (ulaw) [2017-04-04 00:35:44.99408] DEBUG[29878][C-00116155] chan_sip.c: Allocating new SIP dialog for 630b7239264aee70156c7e1e4f944235@217.14.196.29:5060 - INVITE (No RTP) [2017-04-04 00:35:44.99411] DEBUG[29878][C-00116155] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f344121f320' [2017-04-04 00:35:44.99413] DEBUG[29878][C-00116155] res_rtp_asterisk.c: Allocated port 24790 for RTP instance '0x7f344121f320' [2017-04-04 00:35:44.99414] DEBUG[29878][C-00116155] res_rtp_asterisk.c: Creating ICE session 217.14.196.29:24790 (24790) for RTP instance '0x7f344121f320' [2017-04-04 00:35:44.99420] VERBOSE[24876] chan_sip.c: <--- SIP read from UDP:192.168.114.174:5061 ---> NOTIFY sip:softswitch.mark-itt.ru SIP/2.0 Via: SIP/2.0/UDP 192.168.114.174:5061;branch=z9hG4bK-a4a5a342 From: ;tag=6ae93a8d639fffb8o1 To: Call-ID: 66181dad-8f797718@192.168.114.174 CSeq: 36675 NOTIFY Max-Forwards: 70 Contact: Event: keep-alive User-Agent: Cisco/SPA122-1.1.0(011) Content-Length: 0 <-------------> [2017-04-04 00:35:44.99421] DEBUG[24876] chan_sip.c: Header 0 [ 41]: NOTIFY sip:softswitch.mark-itt.ru SIP/2.0 [2017-04-04 00:35:44.99421] DEBUG[24876] chan_sip.c: Header 1 [ 61]: Via: SIP/2.0/UDP 192.168.114.174:5061;branch=z9hG4bK-a4a5a342 [2017-04-04 00:35:44.99422] DEBUG[24876] chan_sip.c: Header 2 [ 57]: From: ;tag=6ae93a8d639fffb8o1 [2017-04-04 00:35:44.99422] DEBUG[24876] chan_sip.c: Header 3 [ 32]: To: [2017-04-04 00:35:44.99422] DEBUG[24876] chan_sip.c: Header 4 [ 42]: Call-ID: 66181dad-8f797718@192.168.114.174 [2017-04-04 00:35:44.99422] DEBUG[24876] chan_sip.c: Header 5 [ 18]: CSeq: 36675 NOTIFY [2017-04-04 00:35:44.99423] DEBUG[24876] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [2017-04-04 00:35:44.99423] DEBUG[24876] chan_sip.c: Header 7 [ 40]: Contact: [2017-04-04 00:35:44.99423] DEBUG[24876] chan_sip.c: Header 8 [ 17]: Event: keep-alive [2017-04-04 00:35:44.99423] DEBUG[24876] chan_sip.c: Header 9 [ 35]: User-Agent: Cisco/SPA122-1.1.0(011) [2017-04-04 00:35:44.99423] DEBUG[24876] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [2017-04-04 00:35:44.99424] VERBOSE[24876] chan_sip.c: --- (11 headers 0 lines) --- [2017-04-04 00:35:44.99424] DEBUG[24876] chan_sip.c: = Looking for Call ID: 66181dad-8f797718@192.168.114.174 (Checking From) --From tag 6ae93a8d639fffb8o1 --To-tag [2017-04-04 00:35:44.99425] DEBUG[24876] chan_sip.c: **** Received NOTIFY (4) - Command in SIP NOTIFY [2017-04-04 00:35:44.99426] DEBUG[24876] chan_sip.c: Got NOTIFY Event: keep-alive [2017-04-04 00:35:44.99428] VERBOSE[24876] chan_sip.c: <--- Transmitting (no NAT) to 192.168.114.174:5061 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.114.174:5061;branch=z9hG4bK-a4a5a342;received=192.168.114.174 From: ;tag=6ae93a8d639fffb8o1 To: ;tag=as602dcdac Call-ID: 66181dad-8f797718@192.168.114.174 CSeq: 36675 NOTIFY Server: MarkTEL Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 <------------> [2017-04-04 00:35:44.99428] DEBUG[24876] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.114.174:5061 [2017-04-04 00:35:44.99428] DEBUG[29878][C-00116155] netsock2.c: Splitting '192.168.10.77' into... [2017-04-04 00:35:44.99429] DEBUG[29878][C-00116155] netsock2.c: ...host '192.168.10.77' and port ''. [2017-04-04 00:35:44.99430] DEBUG[29878][C-00116155] netsock2.c: Splitting '192.168.10.77' into... [2017-04-04 00:35:44.99430] DEBUG[29878][C-00116155] netsock2.c: ...host '192.168.10.77' and port ''. [2017-04-04 00:35:44.99431] DEBUG[29878][C-00116155] netsock2.c: Splitting '217.14.196.29' into... [2017-04-04 00:35:44.99431] VERBOSE[24876] chan_sip.c: Scheduling destruction of SIP dialog '66181dad-8f797718@192.168.114.174' in 32000 ms (Method: NOTIFY) [2017-04-04 00:35:44.99431] DEBUG[29878][C-00116155] netsock2.c: ...host '217.14.196.29' and port ''. [2017-04-04 00:35:44.99431] DEBUG[29878][C-00116155] netsock2.c: Splitting '217.14.196.29' into... [2017-04-04 00:35:44.99432] DEBUG[29878][C-00116155] netsock2.c: ...host '217.14.196.29' and port ''. [2017-04-04 00:35:44.99432] DEBUG[29878][C-00116155] rtp_engine.c: RTP instance '0x7f344121f320' is setup and ready to go [2017-04-04 00:35:44.99433] DEBUG[29878][C-00116155] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [2017-04-04 00:35:44.99433] DEBUG[29878][C-00116155] acl.c: Attached to given IP address [2017-04-04 00:35:44.99434] DEBUG[29878][C-00116155] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f344121f320' [2017-04-04 00:35:44.99435] DEBUG[29878][C-00116155] chan_sip.c: Setting NAT on RTP to On [2017-04-04 00:35:44.99436] DEBUG[29878][C-00116155] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2017-04-04 00:35:44.99437] DEBUG[29878][C-00116155] acl.c: For destination '148.251.118.84', our source address is '217.14.196.29'. [2017-04-04 00:35:44.99438] DEBUG[29878][C-00116155] chan_sip.c: Setting AST_TRANSPORT_UDP with address 217.14.196.29:5060 [2017-04-04 00:35:44.99438] DEBUG[29878][C-00116155] chan_sip.c: Setting NAT on RTP to On [2017-04-04 00:35:44.99439] DEBUG[29878][C-00116155] chan_sip.c: SIP call-id changed from '630b7239264aee70156c7e1e4f944235@217.14.196.29:5060' to '44e287f043a7561c4122ee7f31c20510@217.14.196.29:5060' [2017-04-04 00:35:44.99453] DEBUG[29878][C-00116155] chan_sip.c: *** Our native formats are (ulaw) [2017-04-04 00:35:44.99453] DEBUG[29878][C-00116155] chan_sip.c: *** Joint capabilities are (ulaw) [2017-04-04 00:35:44.99453] DEBUG[29878][C-00116155] chan_sip.c: *** Our capabilities are (ulaw|alaw|gsm|g729) [2017-04-04 00:35:44.99453] DEBUG[29878][C-00116155] chan_sip.c: *** AST_CODEC_CHOOSE formats are ulaw [2017-04-04 00:35:44.99454] DEBUG[29878][C-00116155] chan_sip.c: *** Our preferred formats from the incoming channel are (ulaw) [2017-04-04 00:35:44.99454] DEBUG[29878][C-00116155] chan_sip.c: This channel will not be able to handle video. [2017-04-04 00:35:44.99455] DEBUG[5169] manager.c: Examining AMI event: Event: Newchannel Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/55909-001f9632 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: 55909 CallerIDName: ConnectedLineNum: ConnectedLineName: Language: en AccountCode: outgoing Context: tolkogorod+zona+mg8+mn8+mg7+mn7 Exten: s Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082321 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 [2017-04-04 00:35:44.99462] DEBUG[29878][C-00116155] channel_internal_api.c: Channel Call ID changing from [C-00116155] to [C-00116155] [2017-04-04 00:35:44.99468] DEBUG[29878][C-00116155] chan_sip.c: Asked to create a SIP channel with formats: (ulaw) [2017-04-04 00:35:44.99470] DEBUG[5169] manager.c: Examining AMI event: Event: Newexten Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/55909-001f9632 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: 55909 CallerIDName: ConnectedLineNum: 89127600023 ConnectedLineName: 89127600023 Language: ru AccountCode: outgoing Context: tolkogorod+zona+mg8+mn8+mg7+mn7 Exten: 970227 Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082321 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 Extension: 970227 Application: AppDial AppData: (Outgoing Line) [2017-04-04 00:35:44.99471] DEBUG[29878][C-00116155] chan_sip.c: Allocating new SIP dialog for 6d32bd9a6bfaa6754559fc757f1870e4@217.14.196.29:5060 - INVITE (No RTP) [2017-04-04 00:35:44.99472] DEBUG[29878][C-00116155] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f334510b680' [2017-04-04 00:35:44.99473] DEBUG[5169] manager.c: Examining AMI event: Event: NewConnectedLine Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/55909-001f9632 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: 55909 CallerIDName: ConnectedLineNum: 89127600023 ConnectedLineName: 89127600023 Language: ru AccountCode: outgoing Context: tolkogorod+zona+mg8+mn8+mg7+mn7 Exten: 970227 Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082321 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 [2017-04-04 00:35:44.99475] DEBUG[29878][C-00116155] res_rtp_asterisk.c: Allocated port 17778 for RTP instance '0x7f334510b680' [2017-04-04 00:35:44.99476] DEBUG[29878][C-00116155] res_rtp_asterisk.c: Creating ICE session 217.14.196.29:17778 (17778) for RTP instance '0x7f334510b680' [2017-04-04 00:35:44.99485] DEBUG[29878][C-00116155] netsock2.c: Splitting '192.168.10.77' into... [2017-04-04 00:35:44.99485] DEBUG[29878][C-00116155] netsock2.c: ...host '192.168.10.77' and port ''. [2017-04-04 00:35:44.99486] DEBUG[29878][C-00116155] netsock2.c: Splitting '192.168.10.77' into... [2017-04-04 00:35:44.99486] DEBUG[29878][C-00116155] netsock2.c: ...host '192.168.10.77' and port ''. [2017-04-04 00:35:44.99486] DEBUG[29878][C-00116155] netsock2.c: Splitting '217.14.196.29' into... [2017-04-04 00:35:44.99487] DEBUG[29878][C-00116155] netsock2.c: ...host '217.14.196.29' and port ''. [2017-04-04 00:35:44.99487] DEBUG[29878][C-00116155] netsock2.c: Splitting '217.14.196.29' into... [2017-04-04 00:35:44.99487] DEBUG[29878][C-00116155] netsock2.c: ...host '217.14.196.29' and port ''. [2017-04-04 00:35:44.99487] DEBUG[29878][C-00116155] rtp_engine.c: RTP instance '0x7f334510b680' is setup and ready to go [2017-04-04 00:35:44.99488] DEBUG[29878][C-00116155] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [2017-04-04 00:35:44.99489] DEBUG[29878][C-00116155] acl.c: Attached to given IP address [2017-04-04 00:35:44.99489] DEBUG[29878][C-00116155] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f334510b680' [2017-04-04 00:35:44.99490] DEBUG[29878][C-00116155] chan_sip.c: Setting NAT on RTP to On [2017-04-04 00:35:44.99490] DEBUG[29878][C-00116155] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2017-04-04 00:35:44.99492] DEBUG[29878][C-00116155] acl.c: For destination '148.251.118.84', our source address is '217.14.196.29'. [2017-04-04 00:35:44.99492] DEBUG[29878][C-00116155] chan_sip.c: Setting AST_TRANSPORT_UDP with address 217.14.196.29:5060 [2017-04-04 00:35:44.99493] DEBUG[29878][C-00116155] chan_sip.c: Setting NAT on RTP to On [2017-04-04 00:35:44.99494] DEBUG[29878][C-00116155] chan_sip.c: SIP call-id changed from '6d32bd9a6bfaa6754559fc757f1870e4@217.14.196.29:5060' to '1752376e588916d0368a8e9255f6a7df@217.14.196.29:5060' [2017-04-04 00:35:44.99506] DEBUG[29878][C-00116155] chan_sip.c: *** Our native formats are (ulaw) [2017-04-04 00:35:44.99507] DEBUG[29878][C-00116155] chan_sip.c: *** Joint capabilities are (ulaw) [2017-04-04 00:35:44.99507] DEBUG[29878][C-00116155] chan_sip.c: *** Our capabilities are (ulaw|alaw|gsm|g729) [2017-04-04 00:35:44.99506] DEBUG[5169] manager.c: Examining AMI event: Event: Newchannel Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/34673-001f9633 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: 34673 CallerIDName: ConnectedLineNum: ConnectedLineName: Language: en AccountCode: outgoing Context: tolkogorod+zona+mg8+mn8+mg7+mn7 Exten: s Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082322 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 [2017-04-04 00:35:44.99507] DEBUG[29878][C-00116155] chan_sip.c: *** AST_CODEC_CHOOSE formats are ulaw [2017-04-04 00:35:44.99509] DEBUG[29878][C-00116155] chan_sip.c: *** Our preferred formats from the incoming channel are (ulaw) [2017-04-04 00:35:44.99509] DEBUG[29878][C-00116155] chan_sip.c: This channel will not be able to handle video. [2017-04-04 00:35:44.99518] DEBUG[29878][C-00116155] channel_internal_api.c: Channel Call ID changing from [C-00116155] to [C-00116155] [2017-04-04 00:35:44.99524] DEBUG[29878][C-00116155] chan_sip.c: Outgoing Call for 55909 [2017-04-04 00:35:44.99525] DEBUG[29878][C-00116155] chan_sip.c: Updating call counter for outgoing call [2017-04-04 00:35:44.99525] DEBUG[29878][C-00116155] chan_sip.c: Call to peer '55909' is 1 out of 1 [2017-04-04 00:35:44.99527] DEBUG[24815] devicestate.c: No provider found, checking channel drivers for SIP - 55909 [2017-04-04 00:35:44.99528] DEBUG[24815] chan_sip.c: Checking device state for peer 55909 [2017-04-04 00:35:44.99528] DEBUG[24815] devicestate.c: Changing state for SIP/55909 - state 6 (Ringing) [2017-04-04 00:35:44.99536] DEBUG[29878][C-00116155] chan_sip.c: ** Our capability: (ulaw|alaw|gsm|g729) Video flag: False Text flag: False [2017-04-04 00:35:44.99537] DEBUG[29878][C-00116155] chan_sip.c: ** Our prefcodec: (ulaw) [2017-04-04 00:35:44.99538] VERBOSE[29878][C-00116155] chan_sip.c: Audio is at 24790 [2017-04-04 00:35:44.99539] VERBOSE[29878][C-00116155] chan_sip.c: Adding codec ulaw to SDP [2017-04-04 00:35:44.99539] VERBOSE[29878][C-00116155] chan_sip.c: Adding codec alaw to SDP [2017-04-04 00:35:44.99540] VERBOSE[29878][C-00116155] chan_sip.c: Adding codec gsm to SDP [2017-04-04 00:35:44.99540] VERBOSE[29878][C-00116155] chan_sip.c: Adding codec g729 to SDP [2017-04-04 00:35:44.99541] VERBOSE[29878][C-00116155] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [2017-04-04 00:35:44.99541] DEBUG[29878][C-00116155] chan_sip.c: -- Done with adding codecs to SDP [2017-04-04 00:35:44.99542] DEBUG[29878][C-00116155] chan_sip.c: Done building SDP. Settling with this capability: (ulaw|alaw|gsm|g729) [2017-04-04 00:35:44.99542] DEBUG[29878][C-00116155] chan_sip.c: Initializing initreq for method INVITE - callid 44e287f043a7561c4122ee7f31c20510@217.14.196.29:5060 [2017-04-04 00:35:44.99542] DEBUG[29878][C-00116155] chan_sip.c: Header 0 [ 48]: INVITE sip:disp_pechka@192.168.99.3:5060 SIP/2.0 [2017-04-04 00:35:44.99543] DEBUG[29878][C-00116155] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK21689878;rport [2017-04-04 00:35:44.99543] DEBUG[29878][C-00116155] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2017-04-04 00:35:44.99543] DEBUG[29878][C-00116155] chan_sip.c: Header 3 [ 66]: From: "89127600023" ;tag=as2a1d86fe [2017-04-04 00:35:44.99543] DEBUG[29878][C-00116155] chan_sip.c: Header 4 [ 39]: To: [2017-04-04 00:35:44.99544] DEBUG[29878][C-00116155] chan_sip.c: Header 5 [ 45]: Contact: [2017-04-04 00:35:44.99544] DEBUG[29878][C-00116155] chan_sip.c: Header 6 [ 60]: Call-ID: 44e287f043a7561c4122ee7f31c20510@217.14.196.29:5060 [2017-04-04 00:35:44.99544] DEBUG[29878][C-00116155] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [2017-04-04 00:35:44.99544] DEBUG[29878][C-00116155] chan_sip.c: Header 8 [ 19]: User-Agent: MarkTEL [2017-04-04 00:35:44.99545] DEBUG[29878][C-00116155] chan_sip.c: Header 9 [ 35]: Date: Mon, 03 Apr 2017 20:35:44 GMT [2017-04-04 00:35:44.99545] DEBUG[29878][C-00116155] chan_sip.c: Header 10 [ 21]: Session-Expires: 1800 [2017-04-04 00:35:44.99545] DEBUG[29878][C-00116155] chan_sip.c: Header 11 [ 10]: Min-SE: 90 [2017-04-04 00:35:44.99545] DEBUG[29878][C-00116155] chan_sip.c: Header 12 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [2017-04-04 00:35:44.99545] DEBUG[29878][C-00116155] chan_sip.c: Header 13 [ 26]: Supported: replaces, timer [2017-04-04 00:35:44.99546] DEBUG[29878][C-00116155] chan_sip.c: Header 14 [ 98]: Remote-Party-ID: "89127600023" ;party=calling;privacy=off;screen=no [2017-04-04 00:35:44.99546] DEBUG[29878][C-00116155] chan_sip.c: Header 15 [ 29]: Content-Type: application/sdp [2017-04-04 00:35:44.99549] VERBOSE[29878][C-00116155] chan_sip.c: Reliably Transmitting (NAT) to 148.251.118.84:5060: INVITE sip:disp_pechka@192.168.99.3:5060 SIP/2.0 Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK21689878;rport Max-Forwards: 70 From: "89127600023" ;tag=as2a1d86fe To: Contact: Call-ID: 44e287f043a7561c4122ee7f31c20510@217.14.196.29:5060 CSeq: 102 INVITE User-Agent: MarkTEL Date: Mon, 03 Apr 2017 20:35:44 GMT Session-Expires: 1800 Min-SE: 90 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Remote-Party-ID: "89127600023" ;party=calling;privacy=off;screen=no Content-Type: application/sdp Content-Length: 342 v=0 o=root 1441677126 1441677126 IN IP4 217.14.196.29 s=MarkTEL Server c=IN IP4 217.14.196.29 t=0 0 m=audio 24790 RTP/AVP 0 8 3 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=maxptime:150 a=sendrecv --- [2017-04-04 00:35:44.99551] DEBUG[29878][C-00116155] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #15209 [2017-04-04 00:35:44.99551] DEBUG[29878][C-00116155] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 148.251.118.84:5060 [2017-04-04 00:35:44.99579] DEBUG[24886] app_queue.c: Device 'SIP/55909' changed to state '6' (Ringing) [2017-04-04 00:35:44.99581] DEBUG[5169] manager.c: Examining AMI event: Event: Newexten Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/34673-001f9633 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: 34673 CallerIDName: ConnectedLineNum: 89127600023 ConnectedLineName: 89127600023 Language: ru AccountCode: outgoing Context: tolkogorod+zona+mg8+mn8+mg7+mn7 Exten: 970227 Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082322 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 Extension: 970227 Application: AppDial AppData: (Outgoing Line) [2017-04-04 00:35:44.99586] DEBUG[5169] manager.c: Examining AMI event: Event: NewConnectedLine Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/34673-001f9633 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: 34673 CallerIDName: ConnectedLineNum: 89127600023 ConnectedLineName: 89127600023 Language: ru AccountCode: outgoing Context: tolkogorod+zona+mg8+mn8+mg7+mn7 Exten: 970227 Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082322 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 [2017-04-04 00:35:44.99590] DEBUG[5169] manager.c: Examining AMI event: Event: DeviceStateChange Privilege: call,all SystemName: sw-new.mark-itt.ru Device: SIP/55909 State: RINGING [2017-04-04 00:35:44.99618] DEBUG[29878][C-00116155] chan_sip.c: Outgoing Call for 34673 [2017-04-04 00:35:44.99619] DEBUG[29878][C-00116155] chan_sip.c: Updating call counter for outgoing call [2017-04-04 00:35:44.99619] DEBUG[29878][C-00116155] chan_sip.c: Call to peer '34673' is 1 out of 1 [2017-04-04 00:35:44.99619] DEBUG[5169] manager.c: Examining AMI event: Event: DialBegin Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: ConnectedLineName: Language: ru AccountCode: Context: Dial_in_SIX-call_direct Exten: 970227 Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 DestChannel: SIP/55909-001f9632 DestChannelState: 0 DestChannelStateDesc: Down DestCallerIDNum: 55909 DestCallerIDName: DestConnectedLineNum: 89127600023 DestConnectedLineName: 89127600023 DestLanguage: ru DestAccountCode: outgoing DestContext: tolkogorod+zona+mg8+mn8+mg7+mn7 DestExten: 970227 DestPriority: 1 DestUniqueid: sw-new.mark-itt.ru-1491251744.3082321 DestLinkedid: sw-new.mark-itt.ru-1491251744.3082320 DialString: 55909 [2017-04-04 00:35:44.99620] DEBUG[24815] devicestate.c: No provider found, checking channel drivers for SIP - 34673 [2017-04-04 00:35:44.99621] DEBUG[24815] chan_sip.c: Checking device state for peer 34673 [2017-04-04 00:35:44.99622] DEBUG[24815] devicestate.c: Changing state for SIP/34673 - state 6 (Ringing) [2017-04-04 00:35:44.99630] DEBUG[29878][C-00116155] chan_sip.c: ** Our capability: (ulaw|alaw|gsm|g729) Video flag: False Text flag: False [2017-04-04 00:35:44.99630] DEBUG[29878][C-00116155] chan_sip.c: ** Our prefcodec: (ulaw) [2017-04-04 00:35:44.99631] VERBOSE[29878][C-00116155] chan_sip.c: Audio is at 17778 [2017-04-04 00:35:44.99631] VERBOSE[29878][C-00116155] chan_sip.c: Adding codec ulaw to SDP [2017-04-04 00:35:44.99632] VERBOSE[29878][C-00116155] chan_sip.c: Adding codec alaw to SDP [2017-04-04 00:35:44.99632] VERBOSE[29878][C-00116155] chan_sip.c: Adding codec gsm to SDP [2017-04-04 00:35:44.99633] VERBOSE[29878][C-00116155] chan_sip.c: Adding codec g729 to SDP [2017-04-04 00:35:44.99634] VERBOSE[29878][C-00116155] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [2017-04-04 00:35:44.99634] DEBUG[29878][C-00116155] chan_sip.c: -- Done with adding codecs to SDP [2017-04-04 00:35:44.99635] DEBUG[29878][C-00116155] chan_sip.c: Done building SDP. Settling with this capability: (ulaw|alaw|gsm|g729) [2017-04-04 00:35:44.99635] DEBUG[29878][C-00116155] chan_sip.c: Initializing initreq for method INVITE - callid 1752376e588916d0368a8e9255f6a7df@217.14.196.29:5060 [2017-04-04 00:35:44.99635] DEBUG[29878][C-00116155] chan_sip.c: Header 0 [ 48]: INVITE sip:disp_pechka@192.168.99.3:5060 SIP/2.0 [2017-04-04 00:35:44.99636] DEBUG[29878][C-00116155] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK19ca9856;rport [2017-04-04 00:35:44.99636] DEBUG[29878][C-00116155] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2017-04-04 00:35:44.99636] DEBUG[29878][C-00116155] chan_sip.c: Header 3 [ 66]: From: "89127600023" ;tag=as4cbcba37 [2017-04-04 00:35:44.99636] DEBUG[29878][C-00116155] chan_sip.c: Header 4 [ 39]: To: [2017-04-04 00:35:44.99637] DEBUG[29878][C-00116155] chan_sip.c: Header 5 [ 45]: Contact: [2017-04-04 00:35:44.99637] DEBUG[29878][C-00116155] chan_sip.c: Header 6 [ 60]: Call-ID: 1752376e588916d0368a8e9255f6a7df@217.14.196.29:5060 [2017-04-04 00:35:44.99637] DEBUG[29878][C-00116155] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [2017-04-04 00:35:44.99637] DEBUG[29878][C-00116155] chan_sip.c: Header 8 [ 19]: User-Agent: MarkTEL [2017-04-04 00:35:44.99637] DEBUG[29878][C-00116155] chan_sip.c: Header 9 [ 35]: Date: Mon, 03 Apr 2017 20:35:44 GMT [2017-04-04 00:35:44.99638] DEBUG[29878][C-00116155] chan_sip.c: Header 10 [ 21]: Session-Expires: 1800 [2017-04-04 00:35:44.99638] DEBUG[29878][C-00116155] chan_sip.c: Header 11 [ 10]: Min-SE: 90 [2017-04-04 00:35:44.99638] DEBUG[29878][C-00116155] chan_sip.c: Header 12 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [2017-04-04 00:35:44.99638] DEBUG[29878][C-00116155] chan_sip.c: Header 13 [ 26]: Supported: replaces, timer [2017-04-04 00:35:44.99638] DEBUG[29878][C-00116155] chan_sip.c: Header 14 [ 98]: Remote-Party-ID: "89127600023" ;party=calling;privacy=off;screen=no [2017-04-04 00:35:44.99639] DEBUG[29878][C-00116155] chan_sip.c: Header 15 [ 29]: Content-Type: application/sdp [2017-04-04 00:35:44.99640] VERBOSE[29878][C-00116155] chan_sip.c: Reliably Transmitting (NAT) to 148.251.118.84:5060: INVITE sip:disp_pechka@192.168.99.3:5060 SIP/2.0 Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK19ca9856;rport Max-Forwards: 70 From: "89127600023" ;tag=as4cbcba37 To: Contact: Call-ID: 1752376e588916d0368a8e9255f6a7df@217.14.196.29:5060 CSeq: 102 INVITE User-Agent: MarkTEL Date: Mon, 03 Apr 2017 20:35:44 GMT Session-Expires: 1800 Min-SE: 90 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Remote-Party-ID: "89127600023" ;party=calling;privacy=off;screen=no Content-Type: application/sdp Content-Length: 334 v=0 o=root 879197 879197 IN IP4 217.14.196.29 s=MarkTEL Server c=IN IP4 217.14.196.29 t=0 0 m=audio 17778 RTP/AVP 0 8 3 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=maxptime:150 a=sendrecv --- [2017-04-04 00:35:44.99641] DEBUG[29878][C-00116155] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #17046 [2017-04-04 00:35:44.99642] DEBUG[29878][C-00116155] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 148.251.118.84:5060 [2017-04-04 00:35:44.99645] DEBUG[24886] app_queue.c: Device 'SIP/34673' changed to state '6' (Ringing) [2017-04-04 00:35:44.99658] DEBUG[24886] app_queue.c: Device 'Queue:970227_ringgroup_avail' changed to state '2' (In use) but we don't care because they're not a member of any queue. [2017-04-04 00:35:44.99660] DEBUG[5169] manager.c: Examining AMI event: Event: DeviceStateChange Privilege: call,all SystemName: sw-new.mark-itt.ru Device: SIP/34673 State: RINGING [2017-04-04 00:35:44.99663] DEBUG[5169] manager.c: Examining AMI event: Event: DeviceStateChange Privilege: call,all SystemName: sw-new.mark-itt.ru Device: Queue:970227_ringgroup_avail State: INUSE [2017-04-04 00:35:44.99707] DEBUG[5169] manager.c: Examining AMI event: Event: DialBegin Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: ConnectedLineName: Language: ru AccountCode: Context: Dial_in_SIX-call_direct Exten: 970227 Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 DestChannel: SIP/34673-001f9633 DestChannelState: 0 DestChannelStateDesc: Down DestCallerIDNum: 34673 DestCallerIDName: DestConnectedLineNum: 89127600023 DestConnectedLineName: 89127600023 DestLanguage: ru DestAccountCode: outgoing DestContext: tolkogorod+zona+mg8+mn8+mg7+mn7 DestExten: 970227 DestPriority: 1 DestUniqueid: sw-new.mark-itt.ru-1491251744.3082322 DestLinkedid: sw-new.mark-itt.ru-1491251744.3082320 DialString: 34673 [2017-04-04 00:35:44.99915] VERBOSE[24876] chan_sip.c: <--- SIP read from UDP:192.168.116.90:5060 ---> [2017-04-04 00:35:45.06908] DEBUG[24876] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.116.186:5060 [2017-04-04 00:35:45.06911] VERBOSE[24876] chan_sip.c: Scheduling destruction of SIP dialog 'e12978cf-e36a05de@192.168.116.186' in 32000 ms (Method: NOTIFY) [2017-04-04 00:35:45.07010] VERBOSE[24876] chan_sip.c: <--- SIP read from UDP:192.168.118.81:5060 ---> SIP/2.0 200 OK From: "MarkTEL";tag=as2d7a4570 To: ;tag=5176a8c0-13c4-3926418b-d29fbf8e-39c2430e Call-ID: 46fc1d13045df4c509d900dd6f3573ac@217.14.196.29:5060 CSeq: 102 OPTIONS Via: SIP/2.0/UDP 217.14.196.29:5060;received=217.14.196.29;branch=z9hG4bK30ef3a7d;rport Supported: 100rel,replaces,timer Allow: ACK,BYE,CANCEL,OPTIONS,INVITE,MESSAGE,NOTIFY,SUBSCRIBE,REFER,INFO,UPDATE Content-Length:0 <-------------> [2017-04-04 00:35:45.07011] DEBUG[24876] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2017-04-04 00:35:45.07012] DEBUG[24876] chan_sip.c: Header 1 [ 57]: From: "MarkTEL";tag=as2d7a4570 [2017-04-04 00:35:45.07012] DEBUG[24876] chan_sip.c: Header 2 [ 80]: To: ;tag=5176a8c0-13c4-3926418b-d29fbf8e-39c2430e [2017-04-04 00:35:45.07012] DEBUG[24876] chan_sip.c: Header 3 [ 60]: Call-ID: 46fc1d13045df4c509d900dd6f3573ac@217.14.196.29:5060 [2017-04-04 00:35:45.07012] DEBUG[24876] chan_sip.c: Header 4 [ 17]: CSeq: 102 OPTIONS [2017-04-04 00:35:45.07012] DEBUG[24876] chan_sip.c: Header 5 [ 87]: Via: SIP/2.0/UDP 217.14.196.29:5060;received=217.14.196.29;branch=z9hG4bK30ef3a7d;rport [2017-04-04 00:35:45.07013] DEBUG[24876] chan_sip.c: Header 6 [ 32]: Supported: 100rel,replaces,timer [2017-04-04 00:35:45.07013] DEBUG[24876] chan_sip.c: Header 7 [ 79]: Allow: ACK,BYE,CANCEL,OPTIONS,INVITE,MESSAGE,NOTIFY,SUBSCRIBE,REFER,INFO,UPDATE [2017-04-04 00:35:45.07013] DEBUG[24876] chan_sip.c: Header 8 [ 16]: Content-Length:0 [2017-04-04 00:35:45.07013] VERBOSE[24876] chan_sip.c: --- (9 headers 0 lines) --- [2017-04-04 00:35:45.07014] DEBUG[24876] chan_sip.c: = Looking for Call ID: 46fc1d13045df4c509d900dd6f3573ac@217.14.196.29:5060 (Checking To) --From tag as2d7a4570 --To-tag 5176a8c0-13c4-3926418b-d29fbf8e-39c2430e [2017-04-04 00:35:45.07015] DEBUG[24876] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #3131 [2017-04-04 00:35:45.07016] DEBUG[24876] chan_sip.c: Stopping retransmission on '46fc1d13045df4c509d900dd6f3573ac@217.14.196.29:5060' of Request 102: Match Found [2017-04-04 00:35:45.07141] DEBUG[24876] chan_sip.c: Allocating new SIP dialog for 20215bdb350dcca54e85d72510d1ea0e@217.14.196.29:5060 - OPTIONS (No RTP) [2017-04-04 00:35:45.07142] DEBUG[24876] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2017-04-04 00:35:45.07143] DEBUG[24876] acl.c: For destination '192.168.117.93', our source address is '217.14.196.29'. [2017-04-04 00:35:45.07144] DEBUG[24876] chan_sip.c: Setting AST_TRANSPORT_UDP with address 217.14.196.29:5060 [2017-04-04 00:35:45.07145] DEBUG[24876] chan_sip.c: SIP call-id changed from '20215bdb350dcca54e85d72510d1ea0e@217.14.196.29:5060' to '0fd7e34c03d663585fa5199a2a2f9518@217.14.196.29:5060' [2017-04-04 00:35:45.07147] DEBUG[24876] chan_sip.c: Initializing initreq for method OPTIONS - callid 0fd7e34c03d663585fa5199a2a2f9518@217.14.196.29:5060 [2017-04-04 00:35:45.07147] DEBUG[24876] chan_sip.c: Header 0 [ 45]: OPTIONS sip:28260@192.168.117.93:5060 SIP/2.0 [2017-04-04 00:35:45.07148] DEBUG[24876] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK36b719f5;rport [2017-04-04 00:35:45.07148] DEBUG[24876] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2017-04-04 00:35:45.07148] DEBUG[24876] chan_sip.c: Header 3 [ 58]: From: "MarkTEL" ;tag=as4a961858 [2017-04-04 00:35:45.07148] DEBUG[24876] chan_sip.c: Header 4 [ 35]: To: [2017-04-04 00:35:45.07148] DEBUG[24876] chan_sip.c: Header 5 [ 41]: Contact: [2017-04-04 00:35:45.07148] DEBUG[24876] chan_sip.c: Header 6 [ 60]: Call-ID: 0fd7e34c03d663585fa5199a2a2f9518@217.14.196.29:5060 [2017-04-04 00:35:45.07149] DEBUG[24876] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [2017-04-04 00:35:45.07149] DEBUG[24876] chan_sip.c: Header 8 [ 19]: User-Agent: MarkTEL [2017-04-04 00:35:45.07149] DEBUG[24876] chan_sip.c: Header 9 [ 35]: Date: Mon, 03 Apr 2017 20:35:45 GMT [2017-04-04 00:35:45.07149] DEBUG[24876] chan_sip.c: Header 10 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [2017-04-04 00:35:45.07149] DEBUG[24876] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2017-04-04 00:35:45.07150] VERBOSE[24876] chan_sip.c: Reliably Transmitting (NAT) to 192.168.117.93:5060: OPTIONS sip:28260@192.168.117.93:5060 SIP/2.0 Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK36b719f5;rport Max-Forwards: 70 From: "MarkTEL" ;tag=as4a961858 To: Contact: Call-ID: 0fd7e34c03d663585fa5199a2a2f9518@217.14.196.29:5060 CSeq: 102 OPTIONS User-Agent: MarkTEL Date: Mon, 03 Apr 2017 20:35:45 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 --- [2017-04-04 00:35:45.07151] DEBUG[24876] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #3902 [2017-04-04 00:35:45.07151] DEBUG[24876] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.117.93:5060 [2017-04-04 00:35:45.07208] VERBOSE[24876] chan_sip.c: <--- SIP read from UDP:192.168.118.116:5060 ---> SIP/2.0 200 OK From: "MarkTEL";tag=as511a8a2b To: ;tag=7476a8c0-13c4-3950d696-78f5fa23-8ec2f0a Call-ID: 7be5e58d1314ef864a7417230ee0b45d@217.14.196.29:5060 CSeq: 102 OPTIONS Via: SIP/2.0/UDP 217.14.196.29:5060;received=217.14.196.29;branch=z9hG4bK43b41a78;rport Supported: 100rel,replaces,timer Allow: ACK,BYE,CANCEL,OPTIONS,INVITE,MESSAGE,NOTIFY,SUBSCRIBE,REFER,INFO,UPDATE Content-Length:0 <-------------> [2017-04-04 00:35:45.07209] DEBUG[24876] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2017-04-04 00:35:45.07210] DEBUG[24876] chan_sip.c: Header 1 [ 57]: From: "MarkTEL";tag=as511a8a2b [2017-04-04 00:35:45.07210] DEBUG[24876] chan_sip.c: Header 2 [ 80]: To: ;tag=7476a8c0-13c4-3950d696-78f5fa23-8ec2f0a [2017-04-04 00:35:45.07210] DEBUG[24876] chan_sip.c: Header 3 [ 60]: Call-ID: 7be5e58d1314ef864a7417230ee0b45d@217.14.196.29:5060 [2017-04-04 00:35:45.07210] DEBUG[24876] chan_sip.c: Header 4 [ 17]: CSeq: 102 OPTIONS [2017-04-04 00:35:45.07210] DEBUG[24876] chan_sip.c: Header 5 [ 87]: Via: SIP/2.0/UDP 217.14.196.29:5060;received=217.14.196.29;branch=z9hG4bK43b41a78;rport [2017-04-04 00:35:45.07211] DEBUG[24876] chan_sip.c: Header 6 [ 32]: Supported: 100rel,replaces,timer [2017-04-04 00:35:45.07211] DEBUG[24876] chan_sip.c: Header 7 [ 79]: Allow: ACK,BYE,CANCEL,OPTIONS,INVITE,MESSAGE,NOTIFY,SUBSCRIBE,REFER,INFO,UPDATE [2017-04-04 00:35:45.07211] DEBUG[24876] chan_sip.c: Header 8 [ 16]: Content-Length:0 [2017-04-04 00:35:45.07211] VERBOSE[24876] chan_sip.c: --- (9 headers 0 lines) --- [2017-04-04 00:35:45.07212] DEBUG[24876] chan_sip.c: = Looking for Call ID: 7be5e58d1314ef864a7417230ee0b45d@217.14.196.29:5060 (Checking To) --From tag as511a8a2b --To-tag 7476a8c0-13c4-3950d696-78f5fa23-8ec2f0a [2017-04-04 00:35:45.07213] DEBUG[24876] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #3206 [2017-04-04 00:35:45.07213] DEBUG[24876] chan_sip.c: Stopping retransmission on '7be5e58d1314ef864a7417230ee0b45d@217.14.196.29:5060' of Request 102: Match Found [2017-04-04 00:35:45.07220] DEBUG[24876] chan_sip.c: Destroying SIP dialog 46fc1d13045df4c509d900dd6f3573ac@217.14.196.29:5060 [2017-04-04 00:35:45.07221] VERBOSE[24876] chan_sip.c: Really destroying SIP dialog '46fc1d13045df4c509d900dd6f3573ac@217.14.196.29:5060' Method: OPTIONS [2017-04-04 00:35:45.07252] VERBOSE[24876] chan_sip.c: <--- SIP read from UDP:192.168.115.170:5061 ---> NOTIFY sip:softswitch.mark-itt.ru SIP/2.0 Via: SIP/2.0/UDP 192.168.115.170:5061;branch=z9hG4bK-464fd3a9 From: ;tag=d3136b8c5de7f30eo1 To: Call-ID: abf86e4c-6a28cf4e@0.0.0.0 CSeq: 105874 NOTIFY Max-Forwards: 70 Contact: Event: keep-alive User-Agent: Cisco/SPA122-1.1.0(011) Content-Length: 0 <-------------> [2017-04-04 00:35:45.07254] DEBUG[24876] chan_sip.c: Header 0 [ 41]: NOTIFY sip:softswitch.mark-itt.ru SIP/2.0 [2017-04-04 00:35:45.07254] DEBUG[24876] chan_sip.c: Header 1 [ 61]: Via: SIP/2.0/UDP 192.168.115.170:5061;branch=z9hG4bK-464fd3a9 [2017-04-04 00:35:45.07254] DEBUG[24876] chan_sip.c: Header 2 [ 57]: From: ;tag=d3136b8c5de7f30eo1 [2017-04-04 00:35:45.07254] DEBUG[24876] chan_sip.c: Header 3 [ 32]: To: [2017-04-04 00:35:45.07254] DEBUG[24876] chan_sip.c: Header 4 [ 34]: Call-ID: abf86e4c-6a28cf4e@0.0.0.0 [2017-04-04 00:35:45.07255] DEBUG[24876] chan_sip.c: Header 5 [ 19]: CSeq: 105874 NOTIFY [2017-04-04 00:35:45.07255] DEBUG[24876] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [2017-04-04 00:35:45.07255] DEBUG[24876] chan_sip.c: Header 7 [ 40]: Contact: [2017-04-04 00:35:45.07255] DEBUG[24876] chan_sip.c: Header 8 [ 17]: Event: keep-alive [2017-04-04 00:35:45.07255] DEBUG[24876] chan_sip.c: Header 9 [ 35]: User-Agent: Cisco/SPA122-1.1.0(011) [2017-04-04 00:35:45.07256] DEBUG[24876] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [2017-04-04 00:35:45.07256] VERBOSE[24876] chan_sip.c: --- (11 headers 0 lines) --- [2017-04-04 00:35:45.07257] DEBUG[24876] chan_sip.c: = Looking for Call ID: abf86e4c-6a28cf4e@0.0.0.0 (Checking From) --From tag d3136b8c5de7f30eo1 --To-tag [2017-04-04 00:35:45.07258] DEBUG[24876] chan_sip.c: **** Received NOTIFY (4) - Command in SIP NOTIFY [2017-04-04 00:35:45.07258] DEBUG[24876] chan_sip.c: Got NOTIFY Event: keep-alive [2017-04-04 00:35:45.07260] VERBOSE[24876] chan_sip.c: <--- Transmitting (no NAT) to 192.168.115.170:5061 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.115.170:5061;branch=z9hG4bK-464fd3a9;received=192.168.115.170 From: ;tag=d3136b8c5de7f30eo1 To: ;tag=as05a28c67 Call-ID: abf86e4c-6a28cf4e@0.0.0.0 CSeq: 105874 NOTIFY Server: MarkTEL Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 <------------> [2017-04-04 00:35:45.07261] DEBUG[24876] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.115.170:5061 [2017-04-04 00:35:45.07263] VERBOSE[24876] chan_sip.c: Scheduling destruction of SIP dialog 'abf86e4c-6a28cf4e@0.0.0.0' in 32000 ms (Method: NOTIFY) [2017-04-04 00:35:45.07264] DEBUG[24876] chan_sip.c: Destroying SIP dialog 7be5e58d1314ef864a7417230ee0b45d@217.14.196.29:5060 [2017-04-04 00:35:45.07264] VERBOSE[24876] chan_sip.c: Really destroying SIP dialog '7be5e58d1314ef864a7417230ee0b45d@217.14.196.29:5060' Method: OPTIONS [2017-04-04 00:35:45.07304] VERBOSE[24876] chan_sip.c: <--- SIP read from UDP:148.251.118.84:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK19ca9856;received=217.14.196.29;rport=5060 From: "89127600023" ;tag=as4cbcba37 To: ;tag=as7be8874c Call-ID: 1752376e588916d0368a8e9255f6a7df@217.14.196.29:5060 CSeq: 102 INVITE Server: Asterisk PBX 13.8.0~dfsg-0~ppa2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Session-Expires: 1800;refresher=uas Contact: Content-Type: application/sdp Require: timer Content-Length: 320 v=0 o=root 893359798 893359798 IN IP4 192.168.99.3 s=Asterisk PBX 13.8.0~dfsg-0~ppa2 c=IN IP4 192.168.99.3 t=0 0 m=audio 41148 RTP/AVP 0 8 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=maxptime:150 a=sendrecv <-------------> [2017-04-04 00:35:45.07306] DEBUG[24876] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2017-04-04 00:35:45.07306] DEBUG[24876] chan_sip.c: Header 1 [ 92]: Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK19ca9856;received=217.14.196.29;rport=5060 [2017-04-04 00:35:45.07306] DEBUG[24876] chan_sip.c: Header 2 [ 66]: From: "89127600023" ;tag=as4cbcba37 [2017-04-04 00:35:45.07306] DEBUG[24876] chan_sip.c: Header 3 [ 54]: To: ;tag=as7be8874c [2017-04-04 00:35:45.07307] DEBUG[24876] chan_sip.c: Header 4 [ 60]: Call-ID: 1752376e588916d0368a8e9255f6a7df@217.14.196.29:5060 [2017-04-04 00:35:45.07307] DEBUG[24876] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [2017-04-04 00:35:45.07307] DEBUG[24876] chan_sip.c: Header 6 [ 39]: Server: Asterisk PBX 13.8.0~dfsg-0~ppa2 [2017-04-04 00:35:45.07307] DEBUG[24876] chan_sip.c: Header 7 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [2017-04-04 00:35:45.07307] DEBUG[24876] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [2017-04-04 00:35:45.07307] DEBUG[24876] chan_sip.c: Header 9 [ 35]: Session-Expires: 1800;refresher=uas [2017-04-04 00:35:45.07308] DEBUG[24876] chan_sip.c: Header 10 [ 44]: Contact: [2017-04-04 00:35:45.07308] DEBUG[24876] chan_sip.c: Header 11 [ 29]: Content-Type: application/sdp [2017-04-04 00:35:45.07308] DEBUG[24876] chan_sip.c: Header 12 [ 14]: Require: timer [2017-04-04 00:35:45.07308] DEBUG[24876] chan_sip.c: Header 13 [ 19]: Content-Length: 320 [2017-04-04 00:35:45.07308] DEBUG[24876] chan_sip.c: Header 14 [ 0]: [2017-04-04 00:35:45.07309] DEBUG[24876] chan_sip.c: Body 0 [ 3]: v=0 [2017-04-04 00:35:45.07309] DEBUG[24876] chan_sip.c: Body 1 [ 46]: o=root 893359798 893359798 IN IP4 192.168.99.3 [2017-04-04 00:35:45.07309] DEBUG[24876] chan_sip.c: Body 2 [ 33]: s=Asterisk PBX 13.8.0~dfsg-0~ppa2 [2017-04-04 00:35:45.07309] DEBUG[24876] chan_sip.c: Body 3 [ 21]: c=IN IP4 192.168.99.3 [2017-04-04 00:35:45.07309] DEBUG[24876] chan_sip.c: Body 4 [ 5]: t=0 0 [2017-04-04 00:35:45.07309] DEBUG[24876] chan_sip.c: Body 5 [ 32]: m=audio 41148 RTP/AVP 0 8 18 101 [2017-04-04 00:35:45.07310] DEBUG[24876] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [2017-04-04 00:35:45.07310] DEBUG[24876] chan_sip.c: Body 7 [ 20]: a=rtpmap:8 PCMA/8000 [2017-04-04 00:35:45.07310] DEBUG[24876] chan_sip.c: Body 8 [ 21]: a=rtpmap:18 G729/8000 [2017-04-04 00:35:45.07310] DEBUG[24876] chan_sip.c: Body 9 [ 19]: a=fmtp:18 annexb=no [2017-04-04 00:35:45.07310] DEBUG[24876] chan_sip.c: Body 10 [ 33]: a=rtpmap:101 telephone-event/8000 [2017-04-04 00:35:45.07310] DEBUG[24876] chan_sip.c: Body 11 [ 15]: a=fmtp:101 0-16 [2017-04-04 00:35:45.07311] DEBUG[24876] chan_sip.c: Body 12 [ 14]: a=maxptime:150 [2017-04-04 00:35:45.07311] DEBUG[24876] chan_sip.c: Body 13 [ 10]: a=sendrecv [2017-04-04 00:35:45.07311] VERBOSE[24876] chan_sip.c: --- (14 headers 14 lines) --- [2017-04-04 00:35:45.07312] DEBUG[24876] chan_sip.c: = Looking for Call ID: 1752376e588916d0368a8e9255f6a7df@217.14.196.29:5060 (Checking To) --From tag as4cbcba37 --To-tag as7be8874c [2017-04-04 00:35:45.07314] DEBUG[24876][C-00116155] chan_sip.c: Acked pending invite 102 [2017-04-04 00:35:45.07315] DEBUG[24876][C-00116155] chan_sip.c: Stopping retransmission on '1752376e588916d0368a8e9255f6a7df@217.14.196.29:5060' of Request 102: Match Found [2017-04-04 00:35:45.07315] DEBUG[24876][C-00116155] chan_sip.c: SIP response 200 to standard invite [2017-04-04 00:35:45.07317] DEBUG[24876][C-00116155] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [2017-04-04 00:35:45.07317] DEBUG[24876][C-00116155] chan_sip.c: Processing session-level SDP o=root 893359798 893359798 IN IP4 192.168.99.3... OK. [2017-04-04 00:35:45.07317] DEBUG[24876][C-00116155] chan_sip.c: Processing session-level SDP s=Asterisk PBX 13.8.0~dfsg-0~ppa2... UNSUPPORTED OR FAILED. [2017-04-04 00:35:45.07317] DEBUG[24876][C-00116155] netsock2.c: Splitting '192.168.99.3' into... [2017-04-04 00:35:45.07318] DEBUG[24876][C-00116155] netsock2.c: ...host '192.168.99.3' and port ''. [2017-04-04 00:35:45.07318] DEBUG[24876][C-00116155] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.99.3... OK. [2017-04-04 00:35:45.07318] DEBUG[24876][C-00116155] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [2017-04-04 00:35:45.07319] VERBOSE[24876][C-00116155] chan_sip.c: Found RTP audio format 0 [2017-04-04 00:35:45.07319] DEBUG[24876][C-00116155] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7f336c3d86f0 [2017-04-04 00:35:45.07319] VERBOSE[24876][C-00116155] chan_sip.c: Found RTP audio format 8 [2017-04-04 00:35:45.07320] DEBUG[24876][C-00116155] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7f336c3d86f0 [2017-04-04 00:35:45.07320] VERBOSE[24876][C-00116155] chan_sip.c: Found RTP audio format 18 [2017-04-04 00:35:45.07320] DEBUG[24876][C-00116155] rtp_engine.c: Setting tx payload type 18 based on m type on 0x7f336c3d86f0 [2017-04-04 00:35:45.07320] VERBOSE[24876][C-00116155] chan_sip.c: Found RTP audio format 101 [2017-04-04 00:35:45.07320] DEBUG[24876][C-00116155] rtp_engine.c: Setting tx payload type 101 based on m type on 0x7f336c3d86f0 [2017-04-04 00:35:45.07321] VERBOSE[24876][C-00116155] chan_sip.c: Found audio description format PCMU for ID 0 [2017-04-04 00:35:45.07321] DEBUG[24876][C-00116155] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [2017-04-04 00:35:45.07322] VERBOSE[24876][C-00116155] chan_sip.c: Found audio description format PCMA for ID 8 [2017-04-04 00:35:45.07322] DEBUG[24876][C-00116155] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [2017-04-04 00:35:45.07322] VERBOSE[24876][C-00116155] chan_sip.c: Found audio description format G729 for ID 18 [2017-04-04 00:35:45.07323] DEBUG[24876][C-00116155] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK. [2017-04-04 00:35:45.07323] DEBUG[24876][C-00116155] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=no... OK. [2017-04-04 00:35:45.07323] VERBOSE[24876][C-00116155] chan_sip.c: Found audio description format telephone-event for ID 101 [2017-04-04 00:35:45.07324] DEBUG[24876][C-00116155] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [2017-04-04 00:35:45.07324] DEBUG[24876][C-00116155] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-16... UNSUPPORTED OR FAILED. [2017-04-04 00:35:45.07324] DEBUG[24876][C-00116155] chan_sip.c: Processing media-level (audio) SDP a=maxptime:150... UNSUPPORTED OR FAILED. [2017-04-04 00:35:45.07324] DEBUG[24876][C-00116155] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [2017-04-04 00:35:45.07326] VERBOSE[24876][C-00116155] chan_sip.c: Capabilities: us - (ulaw|alaw|gsm|g729), peer - audio=(ulaw|alaw|g729)/video=(nothing)/text=(nothing), combined - (ulaw|alaw|g729) [2017-04-04 00:35:45.07326] VERBOSE[24876][C-00116155] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [2017-04-04 00:35:45.07327] DEBUG[24876][C-00116155] res_rtp_asterisk.c: Set role to CONTROLLING (0x7f334510b680) [2017-04-04 00:35:45.07327] DEBUG[24876][C-00116155] res_rtp_asterisk.c: Set role failed; no ice instance (0x7f334510b680) [2017-04-04 00:35:45.07327] DEBUG[24876][C-00116155] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [2017-04-04 00:35:45.07330] DEBUG[24876][C-00116155] acl.c: For destination '192.168.99.3', our source address is '217.14.196.29'. [2017-04-04 00:35:45.07330] DEBUG[24876][C-00116155] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f334510b680' [2017-04-04 00:35:45.07331] VERBOSE[24876][C-00116155] chan_sip.c: Peer audio RTP is at port 192.168.99.3:41148 [2017-04-04 00:35:45.07331] DEBUG[24876][C-00116155] rtp_engine.c: Copying payload 0 (0x7f338910b718) from 0x7f336c3d86f0 to 0x7f334510b848 [2017-04-04 00:35:45.07331] DEBUG[24876][C-00116155] rtp_engine.c: Copying payload 8 (0x7f338b6032f8) from 0x7f336c3d86f0 to 0x7f334510b848 [2017-04-04 00:35:45.07332] DEBUG[24876][C-00116155] rtp_engine.c: Copying payload 18 (0x7f3388c87058) from 0x7f336c3d86f0 to 0x7f334510b848 [2017-04-04 00:35:45.07332] DEBUG[24876][C-00116155] rtp_engine.c: Copying payload 101 (0x7f338b8f8aa8) from 0x7f336c3d86f0 to 0x7f334510b848 [2017-04-04 00:35:45.07332] DEBUG[24876][C-00116155] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7f334510b680' [2017-04-04 00:35:45.07332] DEBUG[24876][C-00116155] chan_sip.c: We're settling with these formats: (ulaw|alaw|g729) [2017-04-04 00:35:45.07333] DEBUG[24876][C-00116155] chan_sip.c: We have an owner, now see if we need to change this call [2017-04-04 00:35:45.07337] DEBUG[24876][C-00116155] chan_sip.c: Setting native formats after processing SDP. peer joint formats (ulaw|alaw|g729), old nativeformats (ulaw) [2017-04-04 00:35:45.07339] DEBUG[24876][C-00116155] chan_sip.c: Updating call counter for outgoing call [2017-04-04 00:35:45.07341] VERBOSE[24876][C-00116155] sip/route.c: sip_route_dump: route/path hop: [2017-04-04 00:35:45.07342] DEBUG[24876][C-00116155] chan_sip.c: Session-Expires: 1800 [2017-04-04 00:35:45.07342] DEBUG[24876][C-00116155] chan_sip.c: Refresher: UAS [2017-04-04 00:35:45.07343] DEBUG[24876][C-00116155] chan_sip.c: Strict routing enforced for session 1752376e588916d0368a8e9255f6a7df@217.14.196.29:5060 [2017-04-04 00:35:45.07345] VERBOSE[24876][C-00116155] chan_sip.c: Transmitting (NAT) to 148.251.118.84:5060: ACK sip:disp_pechka@192.168.99.3:5060 SIP/2.0 Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK174042e1;rport Max-Forwards: 70 From: "89127600023" ;tag=as4cbcba37 To: ;tag=as7be8874c Contact: Call-ID: 1752376e588916d0368a8e9255f6a7df@217.14.196.29:5060 CSeq: 102 ACK User-Agent: MarkTEL Content-Length: 0 --- [2017-04-04 00:35:45.07345] DEBUG[24876][C-00116155] chan_sip.c: Trying to put 'ACK sip:dis' onto UDP socket destined for 148.251.118.84:5060 [2017-04-04 00:35:45.07345] DEBUG[24815] devicestate.c: No provider found, checking channel drivers for SIP - 34673 [2017-04-04 00:35:45.07347] DEBUG[24815] chan_sip.c: Checking device state for peer 34673 [2017-04-04 00:35:45.07347] DEBUG[24815] devicestate.c: Changing state for SIP/34673 - state 3 (Busy) [2017-04-04 00:35:45.07349] DEBUG[24876] chan_sip.c: Session timer started: 10319 - 1752376e588916d0368a8e9255f6a7df@217.14.196.29:5060 1768000ms [2017-04-04 00:35:45.07358] DEBUG[5169] manager.c: Examining AMI event: Event: DeviceStateChange Privilege: call,all SystemName: sw-new.mark-itt.ru Device: SIP/34673 State: BUSY [2017-04-04 00:35:45.07362] DEBUG[5169] manager.c: Examining AMI event: Event: Newstate Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/34673-001f9633 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 34673 CallerIDName: ConnectedLineNum: 89127600023 ConnectedLineName: 89127600023 Language: ru AccountCode: outgoing Context: tolkogorod+zona+mg8+mn8+mg7+mn7 Exten: 970227 Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082322 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 [2017-04-04 00:35:45.07388] DEBUG[24886] app_queue.c: Device 'SIP/34673' changed to state '3' (Busy) [2017-04-04 00:35:45.07393] VERBOSE[24876] chan_sip.c: <--- SIP read from UDP:148.251.118.84:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK21689878;received=217.14.196.29;rport=5060 From: "89127600023" ;tag=as2a1d86fe To: ;tag=as63f34887 Call-ID: 44e287f043a7561c4122ee7f31c20510@217.14.196.29:5060 CSeq: 102 INVITE Server: Asterisk PBX 13.8.0~dfsg-0~ppa2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Session-Expires: 1800;refresher=uas Contact: Content-Type: application/sdp Require: timer Content-Length: 322 v=0 o=root 1834154926 1834154926 IN IP4 192.168.99.3 s=Asterisk PBX 13.8.0~dfsg-0~ppa2 c=IN IP4 192.168.99.3 t=0 0 m=audio 45412 RTP/AVP 0 8 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=maxptime:150 a=sendrecv <-------------> [2017-04-04 00:35:45.07394] DEBUG[24876] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2017-04-04 00:35:45.07395] DEBUG[24876] chan_sip.c: Header 1 [ 92]: Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK21689878;received=217.14.196.29;rport=5060 [2017-04-04 00:35:45.07395] DEBUG[24876] chan_sip.c: Header 2 [ 66]: From: "89127600023" ;tag=as2a1d86fe [2017-04-04 00:35:45.07395] DEBUG[24876] chan_sip.c: Header 3 [ 54]: To: ;tag=as63f34887 [2017-04-04 00:35:45.07395] DEBUG[24876] chan_sip.c: Header 4 [ 60]: Call-ID: 44e287f043a7561c4122ee7f31c20510@217.14.196.29:5060 [2017-04-04 00:35:45.07395] DEBUG[24876] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [2017-04-04 00:35:45.07396] DEBUG[24876] chan_sip.c: Header 6 [ 39]: Server: Asterisk PBX 13.8.0~dfsg-0~ppa2 [2017-04-04 00:35:45.07396] DEBUG[24876] chan_sip.c: Header 7 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [2017-04-04 00:35:45.07396] DEBUG[24876] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [2017-04-04 00:35:45.07396] DEBUG[24876] chan_sip.c: Header 9 [ 35]: Session-Expires: 1800;refresher=uas [2017-04-04 00:35:45.07396] DEBUG[24876] chan_sip.c: Header 10 [ 44]: Contact: [2017-04-04 00:35:45.07396] DEBUG[24876] chan_sip.c: Header 11 [ 29]: Content-Type: application/sdp [2017-04-04 00:35:45.07397] DEBUG[24876] chan_sip.c: Header 12 [ 14]: Require: timer [2017-04-04 00:35:45.07397] DEBUG[24876] chan_sip.c: Header 13 [ 19]: Content-Length: 322 [2017-04-04 00:35:45.07397] DEBUG[24876] chan_sip.c: Header 14 [ 0]: [2017-04-04 00:35:45.07397] DEBUG[24876] chan_sip.c: Body 0 [ 3]: v=0 [2017-04-04 00:35:45.07397] DEBUG[24876] chan_sip.c: Body 1 [ 48]: o=root 1834154926 1834154926 IN IP4 192.168.99.3 [2017-04-04 00:35:45.07398] DEBUG[24876] chan_sip.c: Body 2 [ 33]: s=Asterisk PBX 13.8.0~dfsg-0~ppa2 [2017-04-04 00:35:45.07398] DEBUG[24876] chan_sip.c: Body 3 [ 21]: c=IN IP4 192.168.99.3 [2017-04-04 00:35:45.07398] DEBUG[24876] chan_sip.c: Body 4 [ 5]: t=0 0 [2017-04-04 00:35:45.07398] DEBUG[24876] chan_sip.c: Body 5 [ 32]: m=audio 45412 RTP/AVP 0 8 18 101 [2017-04-04 00:35:45.07398] DEBUG[24876] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [2017-04-04 00:35:45.07398] DEBUG[24876] chan_sip.c: Body 7 [ 20]: a=rtpmap:8 PCMA/8000 [2017-04-04 00:35:45.07399] DEBUG[24876] chan_sip.c: Body 8 [ 21]: a=rtpmap:18 G729/8000 [2017-04-04 00:35:45.07399] DEBUG[24876] chan_sip.c: Body 9 [ 19]: a=fmtp:18 annexb=no [2017-04-04 00:35:45.07399] DEBUG[24876] chan_sip.c: Body 10 [ 33]: a=rtpmap:101 telephone-event/8000 [2017-04-04 00:35:45.07399] DEBUG[24876] chan_sip.c: Body 11 [ 15]: a=fmtp:101 0-16 [2017-04-04 00:35:45.07399] DEBUG[24876] chan_sip.c: Body 12 [ 14]: a=maxptime:150 [2017-04-04 00:35:45.07400] DEBUG[24876] chan_sip.c: Body 13 [ 10]: a=sendrecv [2017-04-04 00:35:45.07400] VERBOSE[24876] chan_sip.c: --- (14 headers 14 lines) --- [2017-04-04 00:35:45.07400] DEBUG[24876] chan_sip.c: = Looking for Call ID: 44e287f043a7561c4122ee7f31c20510@217.14.196.29:5060 (Checking To) --From tag as2a1d86fe --To-tag as63f34887 [2017-04-04 00:35:45.07403] DEBUG[24876][C-00116155] chan_sip.c: Acked pending invite 102 [2017-04-04 00:35:45.07403] DEBUG[24876][C-00116155] chan_sip.c: Stopping retransmission on '44e287f043a7561c4122ee7f31c20510@217.14.196.29:5060' of Request 102: Match Found [2017-04-04 00:35:45.07404] DEBUG[24876][C-00116155] chan_sip.c: SIP response 200 to standard invite [2017-04-04 00:35:45.07405] DEBUG[24876][C-00116155] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [2017-04-04 00:35:45.07405] DEBUG[24876][C-00116155] chan_sip.c: Processing session-level SDP o=root 1834154926 1834154926 IN IP4 192.168.99.3... OK. [2017-04-04 00:35:45.07405] DEBUG[24876][C-00116155] chan_sip.c: Processing session-level SDP s=Asterisk PBX 13.8.0~dfsg-0~ppa2... UNSUPPORTED OR FAILED. [2017-04-04 00:35:45.07406] DEBUG[24876][C-00116155] netsock2.c: Splitting '192.168.99.3' into... [2017-04-04 00:35:45.07406] DEBUG[24876][C-00116155] netsock2.c: ...host '192.168.99.3' and port ''. [2017-04-04 00:35:45.07406] DEBUG[24876][C-00116155] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.99.3... OK. [2017-04-04 00:35:45.07406] DEBUG[24876][C-00116155] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [2017-04-04 00:35:45.07407] VERBOSE[24876][C-00116155] chan_sip.c: Found RTP audio format 0 [2017-04-04 00:35:45.07407] DEBUG[24876][C-00116155] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7f336c3d86f0 [2017-04-04 00:35:45.07407] VERBOSE[24876][C-00116155] chan_sip.c: Found RTP audio format 8 [2017-04-04 00:35:45.07407] DEBUG[24876][C-00116155] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7f336c3d86f0 [2017-04-04 00:35:45.07408] VERBOSE[24876][C-00116155] chan_sip.c: Found RTP audio format 18 [2017-04-04 00:35:45.07408] DEBUG[24876][C-00116155] rtp_engine.c: Setting tx payload type 18 based on m type on 0x7f336c3d86f0 [2017-04-04 00:35:45.07408] VERBOSE[24876][C-00116155] chan_sip.c: Found RTP audio format 101 [2017-04-04 00:35:45.07408] DEBUG[24876][C-00116155] rtp_engine.c: Setting tx payload type 101 based on m type on 0x7f336c3d86f0 [2017-04-04 00:35:45.07409] VERBOSE[24876][C-00116155] chan_sip.c: Found audio description format PCMU for ID 0 [2017-04-04 00:35:45.07409] DEBUG[24876][C-00116155] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [2017-04-04 00:35:45.07409] VERBOSE[24876][C-00116155] chan_sip.c: Found audio description format PCMA for ID 8 [2017-04-04 00:35:45.07409] DEBUG[24876][C-00116155] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [2017-04-04 00:35:45.07410] VERBOSE[24876][C-00116155] chan_sip.c: Found audio description format G729 for ID 18 [2017-04-04 00:35:45.07409] DEBUG[24815] devicestate.c: No provider found, checking channel drivers for SIP - 34673 [2017-04-04 00:35:45.07410] DEBUG[24876][C-00116155] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK. [2017-04-04 00:35:45.07410] DEBUG[24815] chan_sip.c: Checking device state for peer 34673 [2017-04-04 00:35:45.07410] DEBUG[24876][C-00116155] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=no... OK. [2017-04-04 00:35:45.07411] DEBUG[24815] devicestate.c: Changing state for SIP/34673 - state 3 (Busy) [2017-04-04 00:35:45.07411] VERBOSE[24876][C-00116155] chan_sip.c: Found audio description format telephone-event for ID 101 [2017-04-04 00:35:45.07411] DEBUG[24876][C-00116155] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [2017-04-04 00:35:45.07411] DEBUG[24876][C-00116155] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-16... UNSUPPORTED OR FAILED. [2017-04-04 00:35:45.07412] DEBUG[24876][C-00116155] chan_sip.c: Processing media-level (audio) SDP a=maxptime:150... UNSUPPORTED OR FAILED. [2017-04-04 00:35:45.07412] DEBUG[24876][C-00116155] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [2017-04-04 00:35:45.07413] VERBOSE[24876][C-00116155] chan_sip.c: Capabilities: us - (ulaw|alaw|gsm|g729), peer - audio=(ulaw|alaw|g729)/video=(nothing)/text=(nothing), combined - (ulaw|alaw|g729) [2017-04-04 00:35:45.07414] VERBOSE[24876][C-00116155] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [2017-04-04 00:35:45.07415] DEBUG[24876][C-00116155] res_rtp_asterisk.c: Set role to CONTROLLING (0x7f344121f320) [2017-04-04 00:35:45.07415] DEBUG[24876][C-00116155] res_rtp_asterisk.c: Set role failed; no ice instance (0x7f344121f320) [2017-04-04 00:35:45.07415] DEBUG[24876][C-00116155] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [2017-04-04 00:35:45.07417] DEBUG[24876][C-00116155] acl.c: For destination '192.168.99.3', our source address is '217.14.196.29'. [2017-04-04 00:35:45.07417] DEBUG[24876][C-00116155] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f344121f320' [2017-04-04 00:35:45.07418] VERBOSE[24876][C-00116155] chan_sip.c: Peer audio RTP is at port 192.168.99.3:45412 [2017-04-04 00:35:45.07418] DEBUG[24876][C-00116155] rtp_engine.c: Copying payload 0 (0x7f338a549808) from 0x7f336c3d86f0 to 0x7f344121f4e8 [2017-04-04 00:35:45.07418] DEBUG[24876][C-00116155] rtp_engine.c: Copying payload 8 (0x7f3388423238) from 0x7f336c3d86f0 to 0x7f344121f4e8 [2017-04-04 00:35:45.07418] DEBUG[24876][C-00116155] rtp_engine.c: Copying payload 18 (0x7f335412e798) from 0x7f336c3d86f0 to 0x7f344121f4e8 [2017-04-04 00:35:45.07418] DEBUG[24876][C-00116155] rtp_engine.c: Copying payload 101 (0x7f338a89a5e8) from 0x7f336c3d86f0 to 0x7f344121f4e8 [2017-04-04 00:35:45.07419] DEBUG[24876][C-00116155] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7f344121f320' [2017-04-04 00:35:45.07419] DEBUG[24876][C-00116155] chan_sip.c: We're settling with these formats: (ulaw|alaw|g729) [2017-04-04 00:35:45.07419] DEBUG[24876][C-00116155] chan_sip.c: We have an owner, now see if we need to change this call [2017-04-04 00:35:45.07419] DEBUG[24876][C-00116155] chan_sip.c: Setting native formats after processing SDP. peer joint formats (ulaw|alaw|g729), old nativeformats (ulaw) [2017-04-04 00:35:45.07419] DEBUG[5169] manager.c: Examining AMI event: Event: NewConnectedLine Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: 34673 ConnectedLineName: Language: ru AccountCode: Context: Dial_in_SIX-call_direct Exten: 970227 Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 [2017-04-04 00:35:45.07421] DEBUG[24876][C-00116155] chan_sip.c: Updating call counter for outgoing call [2017-04-04 00:35:45.07422] VERBOSE[24876][C-00116155] sip/route.c: sip_route_dump: route/path hop: [2017-04-04 00:35:45.07422] DEBUG[24876][C-00116155] chan_sip.c: Session-Expires: 1800 [2017-04-04 00:35:45.07423] DEBUG[24876][C-00116155] chan_sip.c: Refresher: UAS [2017-04-04 00:35:45.07423] DEBUG[24815] devicestate.c: No provider found, checking channel drivers for SIP - 55909 [2017-04-04 00:35:45.07423] DEBUG[24876][C-00116155] chan_sip.c: Strict routing enforced for session 44e287f043a7561c4122ee7f31c20510@217.14.196.29:5060 [2017-04-04 00:35:45.07424] DEBUG[24815] chan_sip.c: Checking device state for peer 55909 [2017-04-04 00:35:45.07424] DEBUG[24815] devicestate.c: Changing state for SIP/55909 - state 3 (Busy) [2017-04-04 00:35:45.07425] VERBOSE[24876][C-00116155] chan_sip.c: Transmitting (NAT) to 148.251.118.84:5060: ACK sip:disp_pechka@192.168.99.3:5060 SIP/2.0 Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK7cdf2623;rport Max-Forwards: 70 From: "89127600023" ;tag=as2a1d86fe To: ;tag=as63f34887 Contact: Call-ID: 44e287f043a7561c4122ee7f31c20510@217.14.196.29:5060 CSeq: 102 ACK User-Agent: MarkTEL Content-Length: 0 --- [2017-04-04 00:35:45.07425] DEBUG[24876][C-00116155] chan_sip.c: Trying to put 'ACK sip:dis' onto UDP socket destined for 148.251.118.84:5060 [2017-04-04 00:35:45.07428] DEBUG[24876] chan_sip.c: Session timer started: 14749 - 44e287f043a7561c4122ee7f31c20510@217.14.196.29:5060 1768000ms [2017-04-04 00:35:45.07431] DEBUG[5169] manager.c: Examining AMI event: Event: DeviceStateChange Privilege: call,all SystemName: sw-new.mark-itt.ru Device: SIP/55909 State: BUSY [2017-04-04 00:35:45.07446] DEBUG[24886] app_queue.c: Device 'SIP/55909' changed to state '3' (Busy) [2017-04-04 00:35:45.07460] VERBOSE[24876] chan_sip.c: <--- SIP read from UDP:192.168.38.233:5060 ---> NOTIFY sip:softswitch.mark-itt.ru SIP/2.0 Via: SIP/2.0/UDP 192.168.38.233:5060;branch=z9hG4bK-14a90e8e From: "971049" ;tag=dea3284bf041bbb1o0 To: Call-ID: 786a15c3-454eec99@192.168.38.233 CSeq: 55435 NOTIFY Max-Forwards: 70 Contact: "971049" Event: keep-alive User-Agent: Cisco/SPA122-1.1.0(011) Content-Length: 0 <-------------> [2017-04-04 00:35:45.07461] DEBUG[24876] chan_sip.c: Header 0 [ 41]: NOTIFY sip:softswitch.mark-itt.ru SIP/2.0 [2017-04-04 00:35:45.07461] DEBUG[24876] chan_sip.c: Header 1 [ 60]: Via: SIP/2.0/UDP 192.168.38.233:5060;branch=z9hG4bK-14a90e8e [2017-04-04 00:35:45.07461] DEBUG[24876] chan_sip.c: Header 2 [ 72]: From: "971049" ;tag=dea3284bf041bbb1o0 [2017-04-04 00:35:45.07461] DEBUG[24876] chan_sip.c: Header 3 [ 32]: To: [2017-04-04 00:35:45.07462] DEBUG[24876] chan_sip.c: Header 4 [ 41]: Call-ID: 786a15c3-454eec99@192.168.38.233 [2017-04-04 00:35:45.07462] DEBUG[24876] chan_sip.c: Header 5 [ 18]: CSeq: 55435 NOTIFY [2017-04-04 00:35:45.07462] DEBUG[24876] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [2017-04-04 00:35:45.07462] DEBUG[24876] chan_sip.c: Header 7 [ 59]: Contact: "971049" [2017-04-04 00:35:45.07462] DEBUG[24876] chan_sip.c: Header 8 [ 17]: Event: keep-alive [2017-04-04 00:35:45.07463] DEBUG[24876] chan_sip.c: Header 9 [ 35]: User-Agent: Cisco/SPA122-1.1.0(011) [2017-04-04 00:35:45.07463] DEBUG[24876] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [2017-04-04 00:35:45.07463] VERBOSE[24876] chan_sip.c: --- (11 headers 0 lines) --- [2017-04-04 00:35:45.07464] DEBUG[24876] chan_sip.c: = Looking for Call ID: 786a15c3-454eec99@192.168.38.233 (Checking From) --From tag dea3284bf041bbb1o0 --To-tag [2017-04-04 00:35:45.07463] DEBUG[29878][C-00116155] rtp_engine.c: Setting early bridge SDP of 'SIP/sw1_to_smg2016-001f9631' with that of 'SIP/34673-001f9633' [2017-04-04 00:35:45.07463] DEBUG[24819] cdr.c: Finalized CDR for SIP/sw1_to_smg2016-001f9631 - start 1491251744.991376 answer 0.000000 end 1491251745.074637 dispo NO ANSWER [2017-04-04 00:35:45.07465] DEBUG[24876] chan_sip.c: **** Received NOTIFY (4) - Command in SIP NOTIFY [2017-04-04 00:35:45.07465] DEBUG[24876] chan_sip.c: Got NOTIFY Event: keep-alive [2017-04-04 00:35:45.07466] DEBUG[5169] manager.c: Examining AMI event: Event: DialEnd Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: 34673 ConnectedLineName: Language: ru AccountCode: Context: Dial_in_SIX-call_direct Exten: 970227 Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 DestChannel: SIP/55909-001f9632 DestChannelState: 0 DestChannelStateDesc: Down DestCallerIDNum: 55909 DestCallerIDName: DestConnectedLineNum: 89127600023 DestConnectedLineName: 89127600023 DestLanguage: ru DestAccountCode: outgoing DestContext: tolkogorod+zona+mg8+mn8+mg7+mn7 DestExten: 970227 DestPriority: 1 DestUniqueid: sw-new.mark-itt.ru-1491251744.3082321 DestLinkedid: sw-new.mark-itt.ru-1491251744.3082320 DialStatus: CANCEL [2017-04-04 00:35:45.07467] VERBOSE[24876] chan_sip.c: <--- Transmitting (no NAT) to 192.168.38.233:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.38.233:5060;branch=z9hG4bK-14a90e8e;received=192.168.38.233 From: "971049" ;tag=dea3284bf041bbb1o0 To: ;tag=as195e7524 Call-ID: 786a15c3-454eec99@192.168.38.233 CSeq: 55435 NOTIFY Server: MarkTEL Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 <------------> [2017-04-04 00:35:45.07467] DEBUG[24876] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.38.233:5060 [2017-04-04 00:35:45.07470] VERBOSE[24876] chan_sip.c: Scheduling destruction of SIP dialog '786a15c3-454eec99@192.168.38.233' in 32000 ms (Method: NOTIFY) [2017-04-04 00:35:45.07468] DEBUG[29878][C-00116155] channel.c: Hanging up channel 'SIP/55909-001f9632' [2017-04-04 00:35:45.07489] DEBUG[29878][C-00116155] chan_sip.c: This call was answered elsewhere [2017-04-04 00:35:45.07490] DEBUG[29878][C-00116155] chan_sip.c: Hangup call SIP/55909-001f9632, SIP callid 44e287f043a7561c4122ee7f31c20510@217.14.196.29:5060 [2017-04-04 00:35:45.07490] DEBUG[29878][C-00116155] chan_sip.c: update_call_counter(55909) - decrement call limit counter on hangup [2017-04-04 00:35:45.07490] DEBUG[29878][C-00116155] chan_sip.c: Updating call counter for outgoing call [2017-04-04 00:35:45.07491] DEBUG[29878][C-00116155] chan_sip.c: Call to peer '55909' removed from call limit 1 [2017-04-04 00:35:45.07492] DEBUG[29878][C-00116155] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f344121f320' [2017-04-04 00:35:45.07492] VERBOSE[29878][C-00116155] chan_sip.c: Scheduling destruction of SIP dialog '44e287f043a7561c4122ee7f31c20510@217.14.196.29:5060' in 6400 ms (Method: INVITE) [2017-04-04 00:35:45.07494] DEBUG[24815] devicestate.c: No provider found, checking channel drivers for SIP - 55909 [2017-04-04 00:35:45.07495] DEBUG[24815] chan_sip.c: Checking device state for peer 55909 [2017-04-04 00:35:45.07496] DEBUG[24815] devicestate.c: Changing state for SIP/55909 - state 1 (Not in use) [2017-04-04 00:35:45.07501] DEBUG[5169] manager.c: Examining AMI event: Event: DeviceStateChange Privilege: call,all SystemName: sw-new.mark-itt.ru Device: SIP/55909 State: NOT_INUSE [2017-04-04 00:35:45.07514] DEBUG[5169] manager.c: Examining AMI event: Event: DeviceStateChange Privilege: call,all SystemName: sw-new.mark-itt.ru Device: Queue:970227_ringgroup_avail State: NOT_INUSE [2017-04-04 00:35:45.07517] DEBUG[24886] app_queue.c: Device 'SIP/55909' changed to state '1' (Not in use) [2017-04-04 00:35:45.07527] DEBUG[24886] app_queue.c: Device 'Queue:970227_ringgroup_avail' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [2017-04-04 00:35:45.07579] DEBUG[24819] cdr.c: Finalized CDR for SIP/55909-001f9632 - start 1491251744.994527 answer 0.000000 end 1491251745.075794 dispo NO ANSWER [2017-04-04 00:35:45.07581] DEBUG[5169] manager.c: Examining AMI event: Event: Hangup Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/55909-001f9632 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: 55909 CallerIDName: ConnectedLineNum: 89127600023 ConnectedLineName: 89127600023 Language: ru AccountCode: outgoing Context: tolkogorod+zona+mg8+mn8+mg7+mn7 Exten: 970227 Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082321 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 Cause: 26 Cause-txt: Answered elsewhere [2017-04-04 00:35:45.07583] DEBUG[24819] cdr.c: CDR for SIP/55909-001f9632 is dialed and has no Party B; discarding [2017-04-04 00:35:45.07594] DEBUG[24815] devicestate.c: No provider found, checking channel drivers for SIP - 55909 [2017-04-04 00:35:45.07595] DEBUG[24815] chan_sip.c: Checking device state for peer 55909 [2017-04-04 00:35:45.07596] DEBUG[24815] devicestate.c: Changing state for SIP/55909 - state 1 (Not in use) [2017-04-04 00:35:45.07620] DEBUG[5169] manager.c: Examining AMI event: Event: DialEnd Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: 34673 ConnectedLineName: Language: ru AccountCode: Context: Dial_in_SIX-call_direct Exten: 970227 Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 DestChannel: SIP/34673-001f9633 DestChannelState: 6 DestChannelStateDesc: Up DestCallerIDNum: 34673 DestCallerIDName: DestConnectedLineNum: 89127600023 DestConnectedLineName: 89127600023 DestLanguage: ru DestAccountCode: outgoing DestContext: tolkogorod+zona+mg8+mn8+mg7+mn7 DestExten: DestPriority: 1 DestUniqueid: sw-new.mark-itt.ru-1491251744.3082322 DestLinkedid: sw-new.mark-itt.ru-1491251744.3082320 DialStatus: ANSWER [2017-04-04 00:35:45.07624] DEBUG[29878][C-00116155] chan_sip.c: SIP answering channel: SIP/sw1_to_smg2016-001f9631 [2017-04-04 00:35:45.07625] DEBUG[24815] devicestate.c: No provider found, checking channel drivers for SIP - sw1_to_smg2016 [2017-04-04 00:35:45.07625] DEBUG[29878][C-00116155] res_rtp_asterisk.c: Setting the marker bit due to a source update [2017-04-04 00:35:45.07625] DEBUG[24815] chan_sip.c: Checking device state for peer sw1_to_smg2016 [2017-04-04 00:35:45.07626] DEBUG[24815] devicestate.c: Changing state for SIP/sw1_to_smg2016 - state 2 (In use) [2017-04-04 00:35:45.07630] DEBUG[29878][C-00116155] chan_sip.c: ** Our capability: (ulaw|alaw|g729) Video flag: True Text flag: True [2017-04-04 00:35:45.07630] DEBUG[29878][C-00116155] chan_sip.c: ** Our prefcodec: (nothing) [2017-04-04 00:35:45.07631] DEBUG[5169] manager.c: Examining AMI event: Event: Newstate Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: 34673 ConnectedLineName: Language: ru AccountCode: Context: Dial_in_SIX-call_direct Exten: 970227 Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 [2017-04-04 00:35:45.07631] VERBOSE[29878][C-00116155] chan_sip.c: Audio is at 48676 [2017-04-04 00:35:45.07632] VERBOSE[29878][C-00116155] chan_sip.c: Adding codec ulaw to SDP [2017-04-04 00:35:45.07633] VERBOSE[29878][C-00116155] chan_sip.c: Adding codec alaw to SDP [2017-04-04 00:35:45.07633] VERBOSE[29878][C-00116155] chan_sip.c: Adding codec g729 to SDP [2017-04-04 00:35:45.07634] DEBUG[29878][C-00116155] chan_sip.c: -- Done with adding codecs to SDP [2017-04-04 00:35:45.07634] DEBUG[29878][C-00116155] chan_sip.c: Setting framing on incoming call: 20 [2017-04-04 00:35:45.07635] DEBUG[29878][C-00116155] chan_sip.c: Done building SDP. Settling with this capability: (ulaw|alaw|g729) [2017-04-04 00:35:45.07636] VERBOSE[29878][C-00116155] chan_sip.c: <--- Reliably Transmitting (no NAT) to 217.14.196.30:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 217.14.196.30:5060;branch=z9hG4bK-oS1s-314234-1655;received=217.14.196.30;rport=5060 From: "89127600023" ;tag=314167dOr1655p0D1793D0t6 To: ;tag=as67c9245d Call-ID: 1491-251858-314155 CSeq: 2 INVITE Server: MarkTEL Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Session-Expires: 1800;refresher=uas Contact: Remote-Party-ID: "34673" ;party=called;privacy=off;screen=no Content-Type: application/sdp Content-Length: 263 v=0 o=root 1661500754 1661500754 IN IP4 217.14.196.29 s=MarkTEL Server c=IN IP4 217.14.196.29 t=0 0 m=audio 48676 RTP/AVP 0 8 18 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=ptime:20 a=maxptime:150 a=sendrecv <------------> [2017-04-04 00:35:45.07637] DEBUG[29878][C-00116155] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #16730 [2017-04-04 00:35:45.07638] DEBUG[29878][C-00116155] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 217.14.196.30:5060 [2017-04-04 00:35:45.07644] DEBUG[24876] chan_sip.c: Session timer stopped: 14749 - 44e287f043a7561c4122ee7f31c20510@217.14.196.29:5060 [2017-04-04 00:35:45.07648] DEBUG[29878][C-00116155] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [2017-04-04 00:35:45.07649] DEBUG[29878][C-00116155] bridge_native_rtp.c: Bridge '16d4b0cd-d22c-4b65-9cbf-a84f864f5285' can not use native RTP bridge as two channels are required [2017-04-04 00:35:45.07649] DEBUG[29878][C-00116155] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [2017-04-04 00:35:45.07649] DEBUG[29878][C-00116155] bridge.c: Bridge technology softmix has less preference than simple_bridge (10 <= 50). Skipping. [2017-04-04 00:35:45.07649] DEBUG[29878][C-00116155] bridge.c: Chose bridge technology simple_bridge [2017-04-04 00:35:45.07650] DEBUG[29878][C-00116155] bridge.c: Bridge 16d4b0cd-d22c-4b65-9cbf-a84f864f5285: calling simple_bridge technology constructor [2017-04-04 00:35:45.07650] DEBUG[29878][C-00116155] bridge.c: Bridge 16d4b0cd-d22c-4b65-9cbf-a84f864f5285: calling simple_bridge technology start [2017-04-04 00:35:45.07658] DEBUG[5169] manager.c: Examining AMI event: Event: BridgeCreate Privilege: call,all SystemName: sw-new.mark-itt.ru BridgeUniqueid: 16d4b0cd-d22c-4b65-9cbf-a84f864f5285 BridgeType: basic BridgeTechnology: simple_bridge BridgeCreator: BridgeName: BridgeNumChannels: 0 BridgeVideoSourceMode: none [2017-04-04 00:35:45.07658] DEBUG[29879][C-00116155] bridge_channel.c: Bridge 16d4b0cd-d22c-4b65-9cbf-a84f864f5285: 0x7f3344cef550(SIP/34673-001f9633) is joining [2017-04-04 00:35:45.07664] DEBUG[5169] manager.c: Examining AMI event: Event: Newexten Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/34673-001f9633 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 34673 CallerIDName: ConnectedLineNum: 89127600023 ConnectedLineName: 89127600023 Language: ru AccountCode: outgoing Context: tolkogorod+zona+mg8+mn8+mg7+mn7 Exten: Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082322 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 Extension: Application: AppDial AppData: (Outgoing Line) [2017-04-04 00:35:45.07666] DEBUG[29879][C-00116155] bridge_channel.c: Bridge 16d4b0cd-d22c-4b65-9cbf-a84f864f5285: pushing 0x7f3344cef550(SIP/34673-001f9633) [2017-04-04 00:35:45.07672] DEBUG[5169] manager.c: Examining AMI event: Event: BridgeEnter Privilege: call,all SystemName: sw-new.mark-itt.ru BridgeUniqueid: 16d4b0cd-d22c-4b65-9cbf-a84f864f5285 BridgeType: basic BridgeTechnology: simple_bridge BridgeCreator: BridgeName: BridgeNumChannels: 1 BridgeVideoSourceMode: none Channel: SIP/34673-001f9633 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 34673 CallerIDName: ConnectedLineNum: 89127600023 ConnectedLineName: 89127600023 Language: ru AccountCode: outgoing Context: tolkogorod+zona+mg8+mn8+mg7+mn7 Exten: Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082322 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 [2017-04-04 00:35:45.07683] DEBUG[29879][C-00116155] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [2017-04-04 00:35:45.07684] DEBUG[29879][C-00116155] bridge_native_rtp.c: Bridge '16d4b0cd-d22c-4b65-9cbf-a84f864f5285' can not use native RTP bridge as two channels are required [2017-04-04 00:35:45.07685] DEBUG[29879][C-00116155] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [2017-04-04 00:35:45.07685] DEBUG[29879][C-00116155] bridge.c: Bridge technology softmix does not have any capabilities we want. [2017-04-04 00:35:45.07685] DEBUG[29879][C-00116155] bridge.c: Chose bridge technology simple_bridge [2017-04-04 00:35:45.07685] DEBUG[29879][C-00116155] bridge.c: Bridge 16d4b0cd-d22c-4b65-9cbf-a84f864f5285 is already using the new technology. [2017-04-04 00:35:45.07686] DEBUG[29879][C-00116155] bridge.c: Bridge 16d4b0cd-d22c-4b65-9cbf-a84f864f5285: 0x7f3344cef550(SIP/34673-001f9633) is joining simple_bridge technology [2017-04-04 00:35:45.07688] DEBUG[29879][C-00116155] res_rtp_asterisk.c: Not changing SSRC since we haven't sent any RTP yet [2017-04-04 00:35:45.07691] DEBUG[29878][C-00116155] bridge_channel.c: Bridge 16d4b0cd-d22c-4b65-9cbf-a84f864f5285: 0x7f34406ae280(SIP/sw1_to_smg2016-001f9631) is joining [2017-04-04 00:35:45.07695] DEBUG[29878][C-00116155] bridge_channel.c: Bridge 16d4b0cd-d22c-4b65-9cbf-a84f864f5285: pushing 0x7f34406ae280(SIP/sw1_to_smg2016-001f9631) [2017-04-04 00:35:45.07696] DEBUG[29878][C-00116155] bridge_channel.c: Setting channel SIP/sw1_to_smg2016-001f9631 peeraccount with channel SIP/34673-001f9633 accountcode 'outgoing'. [2017-04-04 00:35:45.07703] DEBUG[29878][C-00116155] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [2017-04-04 00:35:45.07702] DEBUG[24819] cdr.c: Finalized CDR for SIP/34673-001f9633 - start 1491251744.995053 answer 1491251745.073638 end 1491251745.077027 dispo ANSWERED [2017-04-04 00:35:45.07704] DEBUG[29878][C-00116155] bridge_native_rtp.c: Bridge '16d4b0cd-d22c-4b65-9cbf-a84f864f5285' can not use local native RTP bridge as local bridge or DTMF is not compatible [2017-04-04 00:35:45.07704] DEBUG[29878][C-00116155] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [2017-04-04 00:35:45.07704] DEBUG[29878][C-00116155] bridge.c: Bridge technology softmix does not have any capabilities we want. [2017-04-04 00:35:45.07704] DEBUG[29878][C-00116155] bridge.c: Chose bridge technology simple_bridge [2017-04-04 00:35:45.07704] DEBUG[29878][C-00116155] bridge.c: Bridge 16d4b0cd-d22c-4b65-9cbf-a84f864f5285 is already using the new technology. [2017-04-04 00:35:45.07705] DEBUG[29878][C-00116155] bridge.c: Bridge 16d4b0cd-d22c-4b65-9cbf-a84f864f5285: 0x7f34406ae280(SIP/sw1_to_smg2016-001f9631) is joining simple_bridge technology [2017-04-04 00:35:45.07718] DEBUG[29878][C-00116155] res_rtp_asterisk.c: Not changing SSRC since we haven't sent any RTP yet [2017-04-04 00:35:45.07737] DEBUG[5169] manager.c: Examining AMI event: Event: BridgeEnter Privilege: call,all SystemName: sw-new.mark-itt.ru BridgeUniqueid: 16d4b0cd-d22c-4b65-9cbf-a84f864f5285 BridgeType: basic BridgeTechnology: simple_bridge BridgeCreator: BridgeName: BridgeNumChannels: 2 BridgeVideoSourceMode: none Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: 34673 ConnectedLineName: Language: ru AccountCode: Context: Dial_in_SIX-call_direct Exten: 970227 Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 <-------------> [ --- [2017-04-04 00:35:47.39073] DEBUG[24876] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #7015 [2017-04-04 00:35:47.39073] DEBUG[24876] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.117.141:5061 [2017-04-04 00:35:47.39521] VERBOSE[24876] chan_sip.c: <--- SIP read from UDP:217.14.196.30:5060 ---> BYE sip:970227@217.14.196.29:5060 SIP/2.0 Via: SIP/2.0/UDP 217.14.196.30:5060;rport;branch=z9hG4bK-oS1c-720681-1655 From: "89127600023" ;tag=314167dOr1655p0D1793D0t6 To: ;tag=as67c9245d Call-ID: 1491-251858-314155 CSeq: 3 BYE User-Agent: Eltex smg_pa_sip smg_pa_sip-3.7.0.20 Max-Forwards: 70 Contact: Allow: INVITE, ACK, BYE, CANCEL, PRACK, REGISTER, INFO, REFER, NOTIFY, OPTIONS, UPDATE Supported: replaces Reason: Q.850;cause=16;text="Normal call clearing" Content-Length: 0 <-------------> [2017-04-04 00:35:47.39523] DEBUG[24876] chan_sip.c: Header 0 [ 41]: BYE sip:970227@217.14.196.29:5060 SIP/2.0 [2017-04-04 00:35:47.39523] DEBUG[24876] chan_sip.c: Header 1 [ 73]: Via: SIP/2.0/UDP 217.14.196.30:5060;rport;branch=z9hG4bK-oS1c-720681-1655 [2017-04-04 00:35:47.39523] DEBUG[24876] chan_sip.c: Header 2 [ 91]: From: "89127600023" ;tag=314167dOr1655p0D1793D0t6 [2017-04-04 00:35:47.39524] DEBUG[24876] chan_sip.c: Header 3 [ 56]: To: ;tag=as67c9245d [2017-04-04 00:35:47.39524] DEBUG[24876] chan_sip.c: Header 4 [ 27]: Call-ID: 1491-251858-314155 [2017-04-04 00:35:47.39524] DEBUG[24876] chan_sip.c: Header 5 [ 11]: CSeq: 3 BYE [2017-04-04 00:35:47.39524] DEBUG[24876] chan_sip.c: Header 6 [ 48]: User-Agent: Eltex smg_pa_sip smg_pa_sip-3.7.0.20 [2017-04-04 00:35:47.39524] DEBUG[24876] chan_sip.c: Header 7 [ 16]: Max-Forwards: 70 [2017-04-04 00:35:47.39524] DEBUG[24876] chan_sip.c: Header 8 [ 45]: Contact: [2017-04-04 00:35:47.39525] DEBUG[24876] chan_sip.c: Header 9 [ 86]: Allow: INVITE, ACK, BYE, CANCEL, PRACK, REGISTER, INFO, REFER, NOTIFY, OPTIONS, UPDATE [2017-04-04 00:35:47.39525] DEBUG[24876] chan_sip.c: Header 10 [ 19]: Supported: replaces [2017-04-04 00:35:47.39525] DEBUG[24876] chan_sip.c: Header 11 [ 51]: Reason: Q.850;cause=16;text="Normal call clearing" [2017-04-04 00:35:47.39525] DEBUG[24876] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [2017-04-04 00:35:47.39525] VERBOSE[24876] chan_sip.c: --- (13 headers 0 lines) --- [2017-04-04 00:35:47.39526] DEBUG[24876] chan_sip.c: = Looking for Call ID: 1491-251858-314155 (Checking From) --From tag 314167dOr1655p0D1793D0t6 --To-tag as67c9245d [2017-04-04 00:35:47.39527] DEBUG[24876][C-00116155] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [2017-04-04 00:35:47.39528] DEBUG[24876][C-00116155] chan_sip.c: Initializing initreq for method BYE - callid 1491-251858-314155 [2017-04-04 00:35:47.39528] DEBUG[24876][C-00116155] netsock2.c: Splitting '217.14.196.30:5060' into... [2017-04-04 00:35:47.39528] DEBUG[24876][C-00116155] netsock2.c: ...host '217.14.196.30' and port '5060'. [2017-04-04 00:35:47.39529] VERBOSE[24876][C-00116155] chan_sip.c: Sending to 217.14.196.30:5060 (no NAT) [2017-04-04 00:35:47.39529] DEBUG[24876][C-00116155] chan_sip.c: Setting SIP_ALREADYGONE on dialog 1491-251858-314155 [2017-04-04 00:35:47.39593] DEBUG[24876][C-00116155] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f338a1fba20' [2017-04-04 00:35:47.39599] VERBOSE[24876][C-00116155] chan_sip.c: Scheduling destruction of SIP dialog '1491-251858-314155' in 6400 ms (Method: BYE) [2017-04-04 00:35:47.39600] DEBUG[24876][C-00116155] chan_sip.c: Received bye, issuing owner hangup [2017-04-04 00:35:47.39599] DEBUG[5169] manager.c: Examining AMI event: Event: HangupRequest Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: 34673 ConnectedLineName: Language: ru AccountCode: Context: Dial_in_SIX-call_direct Exten: 970227 Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 [2017-04-04 00:35:47.39602] VERBOSE[24876][C-00116155] chan_sip.c: <--- Transmitting (no NAT) to 217.14.196.30:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 217.14.196.30:5060;branch=z9hG4bK-oS1c-720681-1655;received=217.14.196.30;rport=5060 From: "89127600023" ;tag=314167dOr1655p0D1793D0t6 To: ;tag=as67c9245d Call-ID: 1491-251858-314155 CSeq: 3 BYE Server: MarkTEL Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 <------------> [2017-04-04 00:35:47.39603] DEBUG[24876][C-00116155] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 217.14.196.30:5060 [2017-04-04 00:35:47.39606] DEBUG[24876] chan_sip.c: Session timer stopped: 3562 - 1491-251858-314155 [2017-04-04 00:35:47.39628] DEBUG[29878][C-00116155] bridge_channel.c: Setting 0x7f34406ae280(SIP/sw1_to_smg2016-001f9631) state from:0 to:1 [2017-04-04 00:35:47.39638] DEBUG[29878][C-00116155] bridge_channel.c: Bridge 16d4b0cd-d22c-4b65-9cbf-a84f864f5285: pulling 0x7f34406ae280(SIP/sw1_to_smg2016-001f9631) [2017-04-04 00:35:47.39639] DEBUG[29878][C-00116155] bridge_channel.c: Bridge 16d4b0cd-d22c-4b65-9cbf-a84f864f5285: 0x7f34406ae280(SIP/sw1_to_smg2016-001f9631) is leaving simple_bridge technology [2017-04-04 00:35:47.39639] DEBUG[29878][C-00116155] bridge.c: Bridge 16d4b0cd-d22c-4b65-9cbf-a84f864f5285: dissolving bridge with cause 16(Normal Clearing) [2017-04-04 00:35:47.39640] DEBUG[29878][C-00116155] bridge_channel.c: Setting 0x7f3344cef550(SIP/34673-001f9633) state from:0 to:2 [2017-04-04 00:35:47.39652] DEBUG[29878][C-00116155] bridge.c: Bridge 16d4b0cd-d22c-4b65-9cbf-a84f864f5285: queueing action type:13 sub:1001 [2017-04-04 00:35:47.39657] DEBUG[29878][C-00116155] bridge.c: Bridge 16d4b0cd-d22c-4b65-9cbf-a84f864f5285 is dissolved, not performing smart bridge operation. [2017-04-04 00:35:47.39657] DEBUG[24819] cdr.c: Finalized CDR for SIP/sw1_to_smg2016-001f9631 - start 1491251744.997042 answer 1491251745.076243 end 1491251747.396572 dispo ANSWERED [2017-04-04 00:35:47.39659] DEBUG[5169] manager.c: Examining AMI event: Event: BridgeLeave Privilege: call,all SystemName: sw-new.mark-itt.ru BridgeUniqueid: 16d4b0cd-d22c-4b65-9cbf-a84f864f5285 BridgeType: basic BridgeTechnology: simple_bridge BridgeCreator: BridgeName: BridgeNumChannels: 1 BridgeVideoSourceMode: none Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: 34673 ConnectedLineName: Language: ru AccountCode: Context: Dial_in_SIX-call_direct Exten: 970227 Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 [2017-04-04 00:35:47.39659] DEBUG[29879][C-00116155] bridge_channel.c: Bridge 16d4b0cd-d22c-4b65-9cbf-a84f864f5285: pulling 0x7f3344cef550(SIP/34673-001f9633) [2017-04-04 00:35:47.39663] DEBUG[29879][C-00116155] bridge_channel.c: Bridge 16d4b0cd-d22c-4b65-9cbf-a84f864f5285: 0x7f3344cef550(SIP/34673-001f9633) is leaving simple_bridge technology [2017-04-04 00:35:47.39666] DEBUG[29879][C-00116155] bridge.c: Bridge 16d4b0cd-d22c-4b65-9cbf-a84f864f5285 is dissolved, not performing smart bridge operation. [2017-04-04 00:35:47.39668] DEBUG[29879][C-00116155] res_rtp_asterisk.c: Changing ssrc from 1494273211 to 1460682001 due to a source change [2017-04-04 00:35:47.39673] DEBUG[5169] manager.c: Examining AMI event: Event: BridgeLeave Privilege: call,all SystemName: sw-new.mark-itt.ru BridgeUniqueid: 16d4b0cd-d22c-4b65-9cbf-a84f864f5285 BridgeType: basic BridgeTechnology: simple_bridge BridgeCreator: BridgeName: BridgeNumChannels: 0 BridgeVideoSourceMode: none Channel: SIP/34673-001f9633 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 34673 CallerIDName: ConnectedLineNum: 89127600023 ConnectedLineName: 89127600023 Language: ru AccountCode: outgoing Context: tolkogorod+zona+mg8+mn8+mg7+mn7 Exten: Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082322 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 [2017-04-04 00:35:47.39675] DEBUG[29879][C-00116155] bridge.c: Bridge 16d4b0cd-d22c-4b65-9cbf-a84f864f5285: actually destroying basic bridge, nobody wants it anymore [2017-04-04 00:35:47.39678] DEBUG[29879][C-00116155] bridge.c: Bridge 16d4b0cd-d22c-4b65-9cbf-a84f864f5285: calling basic bridge destructor [2017-04-04 00:35:47.39678] DEBUG[29879][C-00116155] bridge.c: Bridge 16d4b0cd-d22c-4b65-9cbf-a84f864f5285: calling simple_bridge technology stop [2017-04-04 00:35:47.39679] DEBUG[29879][C-00116155] bridge.c: Bridge 16d4b0cd-d22c-4b65-9cbf-a84f864f5285: calling simple_bridge technology destructor [2017-04-04 00:35:47.39681] DEBUG[5169] manager.c: Examining AMI event: Event: BridgeDestroy Privilege: call,all SystemName: sw-new.mark-itt.ru BridgeUniqueid: 16d4b0cd-d22c-4b65-9cbf-a84f864f5285 BridgeType: basic BridgeTechnology: simple_bridge BridgeCreator: BridgeName: BridgeNumChannels: 0 BridgeVideoSourceMode: none [2017-04-04 00:35:47.39689] DEBUG[29878][C-00116155] app_dial.c: Exiting with DIALSTATUS=ANSWER. [2017-04-04 00:35:47.39690] DEBUG[29878][C-00116155] pbx.c: Spawn extension (Dial_in_SIX-call_direct,970227,1) exited non-zero on 'SIP/sw1_to_smg2016-001f9631' [2017-04-04 00:35:47.39689] DEBUG[29879][C-00116155] channel.c: Hanging up channel 'SIP/34673-001f9633' [2017-04-04 00:35:47.39691] DEBUG[29879][C-00116155] chan_sip.c: Hangup call SIP/34673-001f9633, SIP callid 1752376e588916d0368a8e9255f6a7df@217.14.196.29:5060 [2017-04-04 00:35:47.39691] DEBUG[29879][C-00116155] chan_sip.c: update_call_counter(34673) - decrement call limit counter on hangup [2017-04-04 00:35:47.39691] DEBUG[29878][C-00116155] channel.c: Soft-Hanging (0x10) up channel 'SIP/sw1_to_smg2016-001f9631' [2017-04-04 00:35:47.39692] DEBUG[29879][C-00116155] chan_sip.c: Updating call counter for outgoing call [2017-04-04 00:35:47.39692] DEBUG[29879][C-00116155] chan_sip.c: Call to peer '34673' removed from call limit 1 [2017-04-04 00:35:47.39696] DEBUG[24815] devicestate.c: No provider found, checking channel drivers for SIP - 34673 [2017-04-04 00:35:47.39696] DEBUG[24815] chan_sip.c: Checking device state for peer 34673 [2017-04-04 00:35:47.39697] DEBUG[24815] devicestate.c: Changing state for SIP/34673 - state 1 (Not in use) [2017-04-04 00:35:47.39697] DEBUG[29879][C-00116155] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f334510b680' [2017-04-04 00:35:47.39697] VERBOSE[29879][C-00116155] chan_sip.c: Scheduling destruction of SIP dialog '1752376e588916d0368a8e9255f6a7df@217.14.196.29:5060' in 6400 ms (Method: INVITE) [2017-04-04 00:35:47.39709] DEBUG[29879][C-00116155] chan_sip.c: Strict routing enforced for session 1752376e588916d0368a8e9255f6a7df@217.14.196.29:5060 [2017-04-04 00:35:47.39712] VERBOSE[29879][C-00116155] chan_sip.c: Reliably Transmitting (NAT) to 148.251.118.84:5060: BYE sip:disp_pechka@192.168.99.3:5060 SIP/2.0 Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK6008855c;rport Max-Forwards: 70 From: "89127600023" ;tag=as4cbcba37 To: ;tag=as7be8874c Call-ID: 1752376e588916d0368a8e9255f6a7df@217.14.196.29:5060 CSeq: 103 BYE User-Agent: MarkTEL X-Asterisk-HangupCause: Normal Clearing X-Asterisk-HangupCauseCode: 16 Content-Length: 0 --- [2017-04-04 00:35:47.39714] DEBUG[29879][C-00116155] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #9725 [2017-04-04 00:35:47.39714] DEBUG[29879][C-00116155] chan_sip.c: Trying to put 'BYE sip:dis' onto UDP socket destined for 148.251.118.84:5060 [2017-04-04 00:35:47.39721] DEBUG[24819] cdr.c: CDR for SIP/34673-001f9633 is dialed and has no Party B; discarding [2017-04-04 00:35:47.39723] DEBUG[24876] chan_sip.c: Session timer stopped: 10319 - 1752376e588916d0368a8e9255f6a7df@217.14.196.29:5060 [2017-04-04 00:35:47.39725] DEBUG[24815] devicestate.c: No provider found, checking channel drivers for SIP - 34673 [2017-04-04 00:35:47.39725] DEBUG[24815] chan_sip.c: Checking device state for peer 34673 [2017-04-04 00:35:47.39725] DEBUG[24815] devicestate.c: Changing state for SIP/34673 - state 1 (Not in use) [2017-04-04 00:35:47.39731] DEBUG[5169] manager.c: Examining AMI event: Event: SoftHangupRequest Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: 34673 ConnectedLineName: Language: ru AccountCode: Context: Dial_in_SIX-call_direct Exten: 970227 Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 Cause: 16 [2017-04-04 00:35:47.39735] DEBUG[5169] manager.c: Examining AMI event: Event: DeviceStateChange Privilege: call,all SystemName: sw-new.mark-itt.ru Device: SIP/34673 State: NOT_INUSE [2017-04-04 00:35:47.39737] DEBUG[5169] manager.c: Examining AMI event: Event: Hangup Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/34673-001f9633 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 34673 CallerIDName: ConnectedLineNum: 89127600023 ConnectedLineName: 89127600023 Language: ru AccountCode: outgoing Context: tolkogorod+zona+mg8+mn8+mg7+mn7 Exten: Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082322 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 Cause: 16 Cause-txt: Normal Clearing [2017-04-04 00:35:47.39738] DEBUG[24886] app_queue.c: Device 'SIP/34673' changed to state '1' (Not in use) [2017-04-04 00:35:47.39741] DEBUG[29878][C-00116155] channel.c: Hanging up channel 'SIP/sw1_to_smg2016-001f9631' [2017-04-04 00:35:47.39742] DEBUG[29878][C-00116155] chan_sip.c: Hangup call SIP/sw1_to_smg2016-001f9631, SIP callid 1491-251858-314155 [2017-04-04 00:35:47.39743] DEBUG[29878][C-00116155] chan_sip.c: update_call_counter() - decrement call limit counter on hangup [2017-04-04 00:35:47.39743] DEBUG[29878][C-00116155] chan_sip.c: Updating call counter for incoming call [2017-04-04 00:35:47.39743] DEBUG[29878][C-00116155] chan_sip.c: Call from peer 'sw1_to_smg2016' removed from call limit 2147483647 [2017-04-04 00:35:47.39744] DEBUG[29878][C-00116155] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f338a1fba20' [2017-04-04 00:35:47.39745] DEBUG[24815] devicestate.c: No provider found, checking channel drivers for SIP - sw1_to_smg2016 [2017-04-04 00:35:47.39745] DEBUG[24815] chan_sip.c: Checking device state for peer sw1_to_smg2016 [2017-04-04 00:35:47.39745] DEBUG[24815] devicestate.c: Changing state for SIP/sw1_to_smg2016 - state 1 (Not in use) [2017-04-04 00:35:47.39749] DEBUG[5169] manager.c: Examining AMI event: Event: Hangup Privilege: call,all SystemName: sw-new.mark-itt.ru Channel: SIP/sw1_to_smg2016-001f9631 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 89127600023 CallerIDName: 89127600023 ConnectedLineNum: 34673 ConnectedLineName: Language: ru AccountCode: Context: Dial_in_SIX-call_direct Exten: 970227 Priority: 1 Uniqueid: sw-new.mark-itt.ru-1491251744.3082320 Linkedid: sw-new.mark-itt.ru-1491251744.3082320 Cause: 16 Cause-txt: Normal Clearing [2017-04-04 00:35:47.39752] DEBUG[5169] manager.c: Examining AMI event: Event: DeviceStateChange Privilege: call,all SystemName: sw-new.mark-itt.ru Device: SIP/sw1_to_smg2016 State: NOT_INUSE [2017-04-04 00:35:47.39756] DEBUG[24815] devicestate.c: No provider found, checking channel drivers for SIP - sw1_to_smg2016 [2017-04-04 00:35:47.39756] DEBUG[24815] chan_sip.c: Checking device state for peer sw1_to_smg2016 [2017-04-04 00:35:47.39757] DEBUG[24815] devicestate.c: Changing state for SIP/sw1_to_smg2016 - state 1 (Not in use) [2017-04-04 00:35:47.39758] DEBUG[24819] pbx_variables.c: Evaluating 'CDR(src)' (from 'CDR(src)}","${CDR(dst)}","${CDR(start)}","${CDR(answer)}","${CDR(billsec)}","${CDR(disposition)}","${CDR(accountcode)}","${CDR(dstchannel)}","${CDR(amaflags)}","${CDR(uniqueid)}","${CDR(remote_ip)}" ' len 8) [2017-04-04 00:35:47.39760] DEBUG[24819] pbx_variables.c: Function CDR(src) result is '89127600023' [2017-04-04 00:35:47.39761] DEBUG[24819] pbx_variables.c: Evaluating 'CDR(dst)' (from 'CDR(dst)}","${CDR(start)}","${CDR(answer)}","${CDR(billsec)}","${CDR(disposition)}","${CDR(accountcode)}","${CDR(dstchannel)}","${CDR(amaflags)}","${CDR(uniqueid)}","${CDR(remote_ip)}" ' len 8) [2017-04-04 00:35:47.39761] DEBUG[24819] pbx_variables.c: Function CDR(dst) result is '970227' [2017-04-04 00:35:47.39761] DEBUG[24819] pbx_variables.c: Evaluating 'CDR(start)' (from 'CDR(start)}","${CDR(answer)}","${CDR(billsec)}","${CDR(disposition)}","${CDR(accountcode)}","${CDR(dstchannel)}","${CDR(amaflags)}","${CDR(uniqueid)}","${CDR(remote_ip)}" ' len 10) [2017-04-04 00:35:47.39762] DEBUG[24819] pbx_variables.c: Function CDR(start) result is '2017-04-04 00:35:44' [2017-04-04 00:35:47.39762] DEBUG[24819] pbx_variables.c: Evaluating 'CDR(answer)' (from 'CDR(answer)}","${CDR(billsec)}","${CDR(disposition)}","${CDR(accountcode)}","${CDR(dstchannel)}","${CDR(amaflags)}","${CDR(uniqueid)}","${CDR(remote_ip)}" ' len 11) [2017-04-04 00:35:47.39763] DEBUG[24819] pbx_variables.c: Function CDR(answer) result is '' [2017-04-04 00:35:47.39763] DEBUG[24819] pbx_variables.c: Evaluating 'CDR(billsec)' (from 'CDR(billsec)}","${CDR(disposition)}","${CDR(accountcode)}","${CDR(dstchannel)}","${CDR(amaflags)}","${CDR(uniqueid)}","${CDR(remote_ip)}" ' len 12) [2017-04-04 00:35:47.39763] DEBUG[24819] pbx_variables.c: Function CDR(billsec) result is '0' [2017-04-04 00:35:47.39763] DEBUG[24819] pbx_variables.c: Evaluating 'CDR(disposition)' (from 'CDR(disposition)}","${CDR(accountcode)}","${CDR(dstchannel)}","${CDR(amaflags)}","${CDR(uniqueid)}","${CDR(remote_ip)}" ' len 16) [2017-04-04 00:35:47.39764] DEBUG[24819] pbx_variables.c: Function CDR(disposition) result is 'NO ANSWER' [2017-04-04 00:35:47.39764] DEBUG[24819] pbx_variables.c: Evaluating 'CDR(accountcode)' (from 'CDR(accountcode)}","${CDR(dstchannel)}","${CDR(amaflags)}","${CDR(uniqueid)}","${CDR(remote_ip)}" ' len 16) [2017-04-04 00:35:47.39764] DEBUG[24819] pbx_variables.c: Function CDR(accountcode) result is '' [2017-04-04 00:35:47.39765] DEBUG[24819] pbx_variables.c: Evaluating 'CDR(dstchannel)' (from 'CDR(dstchannel)}","${CDR(amaflags)}","${CDR(uniqueid)}","${CDR(remote_ip)}" ' len 15) [2017-04-04 00:35:47.39765] DEBUG[24819] pbx_variables.c: Function CDR(dstchannel) result is 'SIP/55909-001f9632' [2017-04-04 00:35:47.39765] DEBUG[24819] pbx_variables.c: Evaluating 'CDR(amaflags)' (from 'CDR(amaflags)}","${CDR(uniqueid)}","${CDR(remote_ip)}" ' len 13) [2017-04-04 00:35:47.39765] DEBUG[24819] pbx_variables.c: Function CDR(amaflags) result is 'DOCUMENTATION' [2017-04-04 00:35:47.39766] DEBUG[24819] pbx_variables.c: Evaluating 'CDR(uniqueid)' (from 'CDR(uniqueid)}","${CDR(remote_ip)}" ' len 13) [2017-04-04 00:35:47.39766] DEBUG[24819] pbx_variables.c: Function CDR(uniqueid) result is 'sw-new.mark-itt.ru-1491251744.3082320' [2017-04-04 00:35:47.39766] DEBUG[24819] pbx_variables.c: Evaluating 'CDR(remote_ip)' (from 'CDR(remote_ip)}" ' len 14) [2017-04-04 00:35:47.39767] DEBUG[24819] pbx_variables.c: Function CDR(remote_ip) result is '' [2017-04-04 00:35:47.39790] DEBUG[24886] app_queue.c: Device 'SIP/sw1_to_smg2016' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [2017-04-04 00:35:47.40233] DEBUG[24819] pbx_variables.c: Evaluating 'CDR(src)' (from 'CDR(src)}","${CDR(dst)}","${CDR(start)}","${CDR(answer)}","${CDR(billsec)}","${CDR(disposition)}","${CDR(accountcode)}","${CDR(dstchannel)}","${CDR(amaflags)}","${CDR(uniqueid)}","${CDR(remote_ip)}" ' len 8) [2017-04-04 00:35:47.40235] DEBUG[24819] pbx_variables.c: Function CDR(src) result is '89127600023' [2017-04-04 00:35:47.40235] DEBUG[24819] pbx_variables.c: Evaluating 'CDR(dst)' (from 'CDR(dst)}","${CDR(start)}","${CDR(answer)}","${CDR(billsec)}","${CDR(disposition)}","${CDR(accountcode)}","${CDR(dstchannel)}","${CDR(amaflags)}","${CDR(uniqueid)}","${CDR(remote_ip)}" ' len 8) [2017-04-04 00:35:47.40236] DEBUG[24819] pbx_variables.c: Function CDR(dst) result is '970227' [2017-04-04 00:35:47.40236] DEBUG[24819] pbx_variables.c: Evaluating 'CDR(start)' (from 'CDR(start)}","${CDR(answer)}","${CDR(billsec)}","${CDR(disposition)}","${CDR(accountcode)}","${CDR(dstchannel)}","${CDR(amaflags)}","${CDR(uniqueid)}","${CDR(remote_ip)}" ' len 10) [2017-04-04 00:35:47.40237] DEBUG[24819] pbx_variables.c: Function CDR(start) result is '2017-04-04 00:35:44' [2017-04-04 00:35:47.40237] DEBUG[24819] pbx_variables.c: Evaluating 'CDR(answer)' (from 'CDR(answer)}","${CDR(billsec)}","${CDR(disposition)}","${CDR(accountcode)}","${CDR(dstchannel)}","${CDR(amaflags)}","${CDR(uniqueid)}","${CDR(remote_ip)}" ' len 11) [2017-04-04 00:35:47.40237] DEBUG[24819] pbx_variables.c: Function CDR(answer) result is '2017-04-04 00:35:45' [2017-04-04 00:35:47.40237] DEBUG[24819] pbx_variables.c: Evaluating 'CDR(billsec)' (from 'CDR(billsec)}","${CDR(disposition)}","${CDR(accountcode)}","${CDR(dstchannel)}","${CDR(amaflags)}","${CDR(uniqueid)}","${CDR(remote_ip)}" ' len 12) [2017-04-04 00:35:47.40238] DEBUG[24819] pbx_variables.c: Function CDR(billsec) result is '2' [2017-04-04 00:35:47.40238] DEBUG[24819] pbx_variables.c: Evaluating 'CDR(disposition)' (from 'CDR(disposition)}","${CDR(accountcode)}","${CDR(dstchannel)}","${CDR(amaflags)}","${CDR(uniqueid)}","${CDR(remote_ip)}" ' len 16) [2017-04-04 00:35:47.40238] DEBUG[24819] pbx_variables.c: Function CDR(disposition) result is 'ANSWERED' [2017-04-04 00:35:47.40238] DEBUG[24819] pbx_variables.c: Evaluating 'CDR(accountcode)' (from 'CDR(accountcode)}","${CDR(dstchannel)}","${CDR(amaflags)}","${CDR(uniqueid)}","${CDR(remote_ip)}" ' len 16) [2017-04-04 00:35:47.40239] DEBUG[24819] pbx_variables.c: Function CDR(accountcode) result is '' [2017-04-04 00:35:47.40239] DEBUG[24819] pbx_variables.c: Evaluating 'CDR(dstchannel)' (from 'CDR(dstchannel)}","${CDR(amaflags)}","${CDR(uniqueid)}","${CDR(remote_ip)}" ' len 15) [2017-04-04 00:35:47.40239] DEBUG[24819] pbx_variables.c: Function CDR(dstchannel) result is 'SIP/34673-001f9633' [2017-04-04 00:35:47.40239] DEBUG[24819] pbx_variables.c: Evaluating 'CDR(amaflags)' (from 'CDR(amaflags)}","${CDR(uniqueid)}","${CDR(remote_ip)}" ' len 13) [2017-04-04 00:35:47.40240] DEBUG[24819] pbx_variables.c: Function CDR(amaflags) result is 'DOCUMENTATION' [2017-04-04 00:35:47.40240] DEBUG[24819] pbx_variables.c: Evaluating 'CDR(uniqueid)' (from 'CDR(uniqueid)}","${CDR(remote_ip)}" ' len 13) [2017-04-04 00:35:47.40240] DEBUG[24819] pbx_variables.c: Function CDR(uniqueid) result is 'sw-new.mark-itt.ru-1491251744.3082320' [2017-04-04 00:35:47.40240] DEBUG[24819] pbx_variables.c: Evaluating 'CDR(remote_ip)' (from 'CDR(remote_ip)}" ' len 14) [2017-04-04 00:35:47.40241] DEBUG[24819] pbx_variables.c: Function CDR(remote_ip) result is '' [2017-04-04 00:35:47.40584] VERBOSE[24876] chan_sip.c: <--- SIP read from UDP:192.168.117.141:5061 ---> SIP/2.0 200 OK To: ;tag=f385a0db90871084i1 From: "MarkTEL" ;tag=as3e542134 Call-ID: 01a70fea6104a5045ebdb8c47cb5f149@217.14.196.29:5060 CSeq: 102 OPTIONS Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK44affb05 Server: Linksys/PAP2T-5.1.3(LS) Content-Length: 0 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura, replaces <-------------> [2017-04-04 00:35:47.40586] DEBUG[24876] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2017-04-04 00:35:47.40586] DEBUG[24876] chan_sip.c: Header 1 [ 59]: To: ;tag=f385a0db90871084i1 [2017-04-04 00:35:47.40586] DEBUG[24876] chan_sip.c: Header 2 [ 58]: From: "MarkTEL" ;tag=as3e542134 [2017-04-04 00:35:47.40586] DEBUG[24876] chan_sip.c: Header 3 [ 60]: Call-ID: 01a70fea6104a5045ebdb8c47cb5f149@217.14.196.29:5060 [2017-04-04 00:35:47.40587] DEBUG[24876] chan_sip.c: Header 4 [ 17]: CSeq: 102 OPTIONS [2017-04-04 00:35:47.40587] DEBUG[24876] chan_sip.c: Header 5 [ 58]: Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK44affb05 [2017-04-04 00:35:47.40587] DEBUG[24876] chan_sip.c: Header 6 [ 31]: Server: Linksys/PAP2T-5.1.3(LS) [2017-04-04 00:35:47.40587] DEBUG[24876] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [2017-04-04 00:35:47.40587] DEBUG[24876] chan_sip.c: Header 8 [ 61]: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER [2017-04-04 00:35:47.40588] DEBUG[24876] chan_sip.c: Header 9 [ 29]: Supported: x-sipura, replaces [2017-04-04 00:35:47.40588] VERBOSE[24876] chan_sip.c: --- (10 headers 0 lines) --- [2017-04-04 00:35:47.40589] DEBUG[24876] chan_sip.c: = Looking for Call ID: 01a70fea6104a5045ebdb8c47cb5f149@217.14.196.29:5060 (Checking To) --From tag as3e542134 --To-tag f385a0db90871084i1 [2017-04-04 00:35:47.40590] DEBUG[24876] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #7015 [2017-04-04 00:35:47.40591] DEBUG[24876] chan_sip.c: Stopping retransmission on '01a70fea6104a5045ebdb8c47cb5f149@217.14.196.29:5060' of Request 102: Match Found [2017-04-04 00:35:47.40652] DEBUG[24876] chan_sip.c: Destroying SIP dialog 01a70fea6104a5045ebdb8c47cb5f149@217.14.196.29:5060 [2017-04-04 00:35:47.40654] VERBOSE[24876] chan_sip.c: Really destroying SIP dialog '01a70fea6104a5045ebdb8c47cb5f149@217.14.196.29:5060' Method: OPTIONS [2017-04-04 00:35:47.40655] DEBUG[24876] chan_sip.c: SIP TIMER: Not rescheduling id #5734:OPTIONS (Method 3) (No timer T1) [2017-04-04 00:35:47.40656] VERBOSE[24876] chan_sip.c: Retransmitting #4 (NAT) to 78.85.84.54:5060: OPTIONS sip:61756@78.85.84.54:5060 SIP/2.0 Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK1560c255;rport Max-Forwards: 70 From: "MarkTEL" ;tag=as644740ee To: Contact: Call-ID: 77219edf4ceadebc10988da16df4649b@217.14.196.29:5060 CSeq: 102 OPTIONS User-Agent: MarkTEL Date: Mon, 03 Apr 2017 20:35:43 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 --- [2017-04-04 00:35:47.40658] DEBUG[24876] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 78.85.84.54:5060 [2017-04-04 00:35:47.40859] DEBUG[24876] chan_sip.c: Destroying SIP dialog 77219edf4ceadebc10988da16df4649b@217.14.196.29:5060 [2017-04-04 00:35:47.40861] VERBOSE[24876] chan_sip.c: Really destroying SIP dialog '77219edf4ceadebc10988da16df4649b@217.14.196.29:5060' Method: OPTIONS [2017-04-04 00:35:47.41070] DEBUG[24876] chan_sip.c: Auto destroying SIP dialog 'd14a8c0-13c4-386d43ac-d0b-5bb6@192.168.39.70' [2017-04-04 00:35:47.41073] DEBUG[24876] chan_sip.c: Destroying SIP dialog d14a8c0-13c4-386d43ac-d0b-5bb6@192.168.39.70 [2017-04-04 00:35:47.41073] VERBOSE[24876] chan_sip.c: Really destroying SIP dialog 'd14a8c0-13c4-386d43ac-d0b-5bb6@192.168.39.70' Method: REGISTER [2017-04-04 00:35:47.41074] DEBUG[24876] chan_sip.c: Auto destroying SIP dialog '4a5c9cef-6aa42f73@192.168.112.4' [2017-04-04 00:35:47.41075] DEBUG[24876] chan_sip.c: Destroying SIP dialog 4a5c9cef-6aa42f73@192.168.112.4 [2017-04-04 00:35:47.41075] VERBOSE[24876] chan_sip.c: Really destroying SIP dialog '4a5c9cef-6aa42f73@192.168.112.4' Method: NOTIFY [2017-04-04 00:35:47.41291] DEBUG[24876] chan_sip.c: Auto destroying SIP dialog 'b02c1ebf-9a1e17e3@192.168.112.4' [2017-04-04 00:35:47.41293] DEBUG[24876] chan_sip.c: Destroying SIP dialog b02c1ebf-9a1e17e3@192.168.112.4 [2017-04-04 00:35:47.41293] VERBOSE[24876] chan_sip.c: Really destroying SIP dialog 'b02c1ebf-9a1e17e3@192.168.112.4' Method: NOTIFY [2017-04-04 00:35:47.41359] VERBOSE[24876] chan_sip.c: <--- SIP read from UDP:92.55.55.12:28422 ---> REGISTER sip:softswitch.mark-itt.ru SIP/2.0 Via: SIP/2.0/UDP 192.168.170.253:5060;branch=z9hG4bK2f72c451;rport Max-Forwards: 70 From: ;tag=as0b06ab9f To: Call-ID: 60fb9b6053a5740b1af0e7b062fe0c80@127.0.0.1 CSeq: 56689 REGISTER User-Agent: Asterisk PBX 1.8.12.0 Authorization: Digest username="92743", realm="sw-new.mark-itt.ru", algorithm=MD5, uri="sip:softswitch.mark-itt.ru", nonce="37db3309", response="922d2560fc6d3f864776a7a092274ccd" Expires: 120 Contact: Content-Length: 0 <-------------> [2017-04-04 00:35:47.41360] DEBUG[24876] chan_sip.c: Header 0 [ 43]: REGISTER sip:softswitch.mark-itt.ru SIP/2.0 [2017-04-04 00:35:47.41360] DEBUG[24876] chan_sip.c: Header 1 [ 66]: Via: SIP/2.0/UDP 192.168.170.253:5060;branch=z9hG4bK2f72c451;rport [2017-04-04 00:35:47.41361] DEBUG[24876] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2017-04-04 00:35:47.41361] DEBUG[24876] chan_sip.c: Header 3 [ 55]: From: ;tag=as0b06ab9f [2017-04-04 00:35:47.41361] DEBUG[24876] chan_sip.c: Header 4 [ 38]: To: [2017-04-04 00:35:47.41361] DEBUG[24876] chan_sip.c: Header 5 [ 51]: Call-ID: 60fb9b6053a5740b1af0e7b062fe0c80@127.0.0.1 [2017-04-04 00:35:47.41362] DEBUG[24876] chan_sip.c: Header 6 [ 20]: CSeq: 56689 REGISTER [2017-04-04 00:35:47.41362] DEBUG[24876] chan_sip.c: Header 7 [ 33]: User-Agent: Asterisk PBX 1.8.12.0 [2017-04-04 00:35:47.41362] DEBUG[24876] chan_sip.c: Header 8 [178]: Authorization: Digest username="92743", realm="sw-new.mark-itt.ru", algorithm=MD5, uri="sip:softswitch.mark-itt.ru", nonce="37db3309", response="922d2560fc6d3f864776a7a092274ccd" [2017-04-04 00:35:47.41362] DEBUG[24876] chan_sip.c: Header 9 [ 12]: Expires: 120 [2017-04-04 00:35:47.41363] DEBUG[24876] chan_sip.c: Header 10 [ 42]: Contact: [2017-04-04 00:35:47.41363] DEBUG[24876] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [2017-04-04 00:35:47.41363] VERBOSE[24876] chan_sip.c: --- (12 headers 0 lines) --- [2017-04-04 00:35:47.41364] DEBUG[24876] chan_sip.c: = Looking for Call ID: 60fb9b6053a5740b1af0e7b062fe0c80@127.0.0.1 (Checking From) --From tag as0b06ab9f --To-tag [2017-04-04 00:35:47.41364] DEBUG[24876] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [2017-04-04 00:35:47.41365] DEBUG[24876] chan_sip.c: Initializing initreq for method REGISTER - callid 60fb9b6053a5740b1af0e7b062fe0c80@127.0.0.1 [2017-04-04 00:35:47.41365] DEBUG[24876] netsock2.c: Splitting '192.168.170.253:5060' into... [2017-04-04 00:35:47.41365] DEBUG[24876] netsock2.c: ...host '192.168.170.253' and port '5060'. [2017-04-04 00:35:47.41366] DEBUG[24876] chan_sip.c: NAT detected for 192.168.170.253 / 92.55.55.12 [2017-04-04 00:35:47.41366] VERBOSE[24876] chan_sip.c: Sending to 92.55.55.12:28422 (NAT) [2017-04-04 00:35:47.41367] DEBUG[24876] netsock2.c: Splitting 'softswitch.mark-itt.ru' into... [2017-04-04 00:35:47.41367] DEBUG[24876] netsock2.c: ...host 'softswitch.mark-itt.ru' and port ''. [2017-04-04 00:35:47.41370] DEBUG[24876] chan_sip.c: Store REGISTER's src-IP:port for call routing. [2017-04-04 00:35:47.41400] DEBUG[24876] chan_sip.c: build_path: do not use Path headers [2017-04-04 00:35:47.41420] DEBUG[24876] chan_sip.c: Allocating new SIP dialog for 6925e15534d53273574489221293e406@217.14.196.29:5060 - OPTIONS (No RTP) [2017-04-04 00:35:47.41421] DEBUG[24876] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2017-04-04 00:35:47.41423] DEBUG[24876] acl.c: For destination '92.55.55.12', our source address is '217.14.196.29'. [2017-04-04 00:35:47.41422] DEBUG[5169] manager.c: Examining AMI event: Event: PeerStatus Privilege: system,all SystemName: sw-new.mark-itt.ru ChannelType: SIP Peer: SIP/92743 PeerStatus: Registered Address: 92.55.55.12:28422 [2017-04-04 00:35:47.41423] DEBUG[24876] chan_sip.c: Setting AST_TRANSPORT_UDP with address 217.14.196.29:5060 [2017-04-04 00:35:47.41424] DEBUG[24876] chan_sip.c: SIP call-id changed from '6925e15534d53273574489221293e406@217.14.196.29:5060' to '2d7760e439b2d7fc3a4050e56a9f84c1@217.14.196.29:5060' [2017-04-04 00:35:47.41427] DEBUG[24876] chan_sip.c: Initializing initreq for method OPTIONS - callid 2d7760e439b2d7fc3a4050e56a9f84c1@217.14.196.29:5060 [2017-04-04 00:35:47.41427] DEBUG[24876] chan_sip.c: Header 0 [ 47]: OPTIONS sip:972743@192.168.170.253:5060 SIP/2.0 [2017-04-04 00:35:47.41427] DEBUG[24876] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK6b05bbdc;rport [2017-04-04 00:35:47.41428] DEBUG[24876] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2017-04-04 00:35:47.41428] DEBUG[24876] chan_sip.c: Header 3 [ 58]: From: "MarkTEL" ;tag=as0ee4a2a2 [2017-04-04 00:35:47.41428] DEBUG[24876] chan_sip.c: Header 4 [ 37]: To: [2017-04-04 00:35:47.41428] DEBUG[24876] chan_sip.c: Header 5 [ 41]: Contact: [2017-04-04 00:35:47.41428] DEBUG[24876] chan_sip.c: Header 6 [ 60]: Call-ID: 2d7760e439b2d7fc3a4050e56a9f84c1@217.14.196.29:5060 [2017-04-04 00:35:47.41429] DEBUG[24876] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [2017-04-04 00:35:47.41429] DEBUG[24876] chan_sip.c: Header 8 [ 19]: User-Agent: MarkTEL [2017-04-04 00:35:47.41429] DEBUG[24876] chan_sip.c: Header 9 [ 35]: Date: Mon, 03 Apr 2017 20:35:47 GMT [2017-04-04 00:35:47.41429] DEBUG[24876] chan_sip.c: Header 10 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [2017-04-04 00:35:47.41429] DEBUG[24876] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2017-04-04 00:35:47.41430] VERBOSE[24876] chan_sip.c: Reliably Transmitting (NAT) to 92.55.55.12:28422: OPTIONS sip:972743@192.168.170.253:5060 SIP/2.0 Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK6b05bbdc;rport Max-Forwards: 70 From: "MarkTEL" ;tag=as0ee4a2a2 To: Contact: Call-ID: 2d7760e439b2d7fc3a4050e56a9f84c1@217.14.196.29:5060 CSeq: 102 OPTIONS User-Agent: MarkTEL Date: Mon, 03 Apr 2017 20:35:47 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 --- [2017-04-04 00:35:47.41431] DEBUG[24876] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #5839 [2017-04-04 00:35:47.41431] DEBUG[24876] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 92.55.55.12:28422 [2017-04-04 00:35:47.41486] VERBOSE[24876] chan_sip.c: <--- Transmitting (NAT) to 92.55.55.12:28422 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.170.253:5060;branch=z9hG4bK2f72c451;received=92.55.55.12;rport=28422 From: ;tag=as0b06ab9f To: ;tag=as6e452308 Call-ID: 60fb9b6053a5740b1af0e7b062fe0c80@127.0.0.1 CSeq: 56689 REGISTER Server: MarkTEL Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Expires: 120 Contact: ;expires=120 Date: Mon, 03 Apr 2017 20:35:47 GMT Content-Length: 0 <------------> [2017-04-04 00:35:47.41487] DEBUG[24876] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 92.55.55.12:28422 [2017-04-04 00:35:47.41490] VERBOSE[24876] chan_sip.c: Scheduling destruction of SIP dialog '60fb9b6053a5740b1af0e7b062fe0c80@127.0.0.1' in 32000 ms (Method: REGISTER) [2017-04-04 00:35:47.41491] DEBUG[24815] devicestate.c: No provider found, checking channel drivers for SIP - 92743 [2017-04-04 00:35:47.41492] DEBUG[24815] chan_sip.c: Checking device state for peer 92743 [2017-04-04 00:35:47.41492] DEBUG[24815] devicestate.c: Changing state for SIP/92743 - state 1 (Not in use) [2017-04-04 00:35:47.41523] DEBUG[24876] chan_sip.c: Allocating new SIP dialog for 62dffa2b57b8d27f2fcfe7e63b6953f4@217.14.196.29:5060 - OPTIONS (No RTP) [2017-04-04 00:35:47.41524] DEBUG[24876] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2017-04-04 00:35:47.41525] DEBUG[24876] acl.c: For destination '91.146.36.84', our source address is '217.14.196.29'. [2017-04-04 00:35:47.41525] DEBUG[24876] chan_sip.c: Setting AST_TRANSPORT_UDP with address 217.14.196.29:5060 [2017-04-04 00:35:47.41526] DEBUG[24876] chan_sip.c: SIP call-id changed from '62dffa2b57b8d27f2fcfe7e63b6953f4@217.14.196.29:5060' to '6c63fac3669674d67b41cc9d36353862@217.14.196.29:5060' [2017-04-04 00:35:47.41528] DEBUG[24876] chan_sip.c: Initializing initreq for method OPTIONS - callid 6c63fac3669674d67b41cc9d36353862@217.14.196.29:5060 [2017-04-04 00:35:47.41529] DEBUG[24876] chan_sip.c: Header 0 [ 44]: OPTIONS sip:47387@192.168.0.100:5060 SIP/2.0 [2017-04-04 00:35:47.41529] DEBUG[24876] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK5b79f76d;rport [2017-04-04 00:35:47.41529] DEBUG[24876] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2017-04-04 00:35:47.41529] DEBUG[24876] chan_sip.c: Header 3 [ 58]: From: "MarkTEL" ;tag=as24b36be1 [2017-04-04 00:35:47.41530] DEBUG[24876] chan_sip.c: Header 4 [ 34]: To: [2017-04-04 00:35:47.41530] DEBUG[24876] chan_sip.c: Header 5 [ 41]: Contact: [2017-04-04 00:35:47.41530] DEBUG[24876] chan_sip.c: Header 6 [ 60]: Call-ID: 6c63fac3669674d67b41cc9d36353862@217.14.196.29:5060 [2017-04-04 00:35:47.41530] DEBUG[24876] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [2017-04-04 00:35:47.41530] DEBUG[24876] chan_sip.c: Header 8 [ 19]: User-Agent: MarkTEL [2017-04-04 00:35:47.41531] DEBUG[24876] chan_sip.c: Header 9 [ 35]: Date: Mon, 03 Apr 2017 20:35:47 GMT [2017-04-04 00:35:47.41531] DEBUG[24876] chan_sip.c: Header 10 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [2017-04-04 00:35:47.41531] DEBUG[24876] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2017-04-04 00:35:47.41532] VERBOSE[24876] chan_sip.c: Reliably Transmitting (NAT) to 91.146.36.84:5060: OPTIONS sip:47387@192.168.0.100:5060 SIP/2.0 Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK5b79f76d;rport Max-Forwards: 70 From: "MarkTEL" ;tag=as24b36be1 To: Contact: Call-ID: 6c63fac3669674d67b41cc9d36353862@217.14.196.29:5060 CSeq: 102 OPTIONS User-Agent: MarkTEL Date: Mon, 03 Apr 2017 20:35:47 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 --- [2017-04-04 00:35:47.41533] DEBUG[24876] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #9635 [2017-04-04 00:35:47.41533] DEBUG[24876] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 91.146.36.84:5060 [2017-04-04 00:35:47.41626] VERBOSE[24876] chan_sip.c: <--- SIP read from UDP:92.55.55.12:28422 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK6b05bbdc;received=217.14.196.29;rport=5060 From: "MarkTEL" ;tag=as0ee4a2a2 To: ;tag=as5a9aca41 Call-ID: 2d7760e439b2d7fc3a4050e56a9f84c1@217.14.196.29:5060 CSeq: 102 OPTIONS Server: Asterisk PBX 1.8.12.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Accept: application/sdp Content-Length: 0 <-------------> [2017-04-04 00:35:47.41628] DEBUG[24876] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2017-04-04 00:35:47.41628] DEBUG[24876] chan_sip.c: Header 1 [ 92]: Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK6b05bbdc;received=217.14.196.29;rport=5060 [2017-04-04 00:35:47.41628] DEBUG[24876] chan_sip.c: Header 2 [ 58]: From: "MarkTEL" ;tag=as0ee4a2a2 [2017-04-04 00:35:47.41628] DEBUG[24876] chan_sip.c: Header 3 [ 52]: To: ;tag=as5a9aca41 [2017-04-04 00:35:47.41628] DEBUG[24876] chan_sip.c: Header 4 [ 60]: Call-ID: 2d7760e439b2d7fc3a4050e56a9f84c1@217.14.196.29:5060 [2017-04-04 00:35:47.41629] DEBUG[24876] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [2017-04-04 00:35:47.41629] DEBUG[24876] chan_sip.c: Header 6 [ 29]: Server: Asterisk PBX 1.8.12.0 [2017-04-04 00:35:47.41629] DEBUG[24876] chan_sip.c: Header 7 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [2017-04-04 00:35:47.41629] DEBUG[24876] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [2017-04-04 00:35:47.41629] DEBUG[24876] chan_sip.c: Header 9 [ 35]: Contact: [2017-04-04 00:35:47.41630] DEBUG[24876] chan_sip.c: Header 10 [ 23]: Accept: application/sdp [2017-04-04 00:35:47.41630] DEBUG[24876] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [2017-04-04 00:35:47.41630] VERBOSE[24876] chan_sip.c: --- (12 headers 0 lines) --- [2017-04-04 00:35:47.41631] DEBUG[24876] chan_sip.c: = Looking for Call ID: 2d7760e439b2d7fc3a4050e56a9f84c1@217.14.196.29:5060 (Checking To) --From tag as0ee4a2a2 --To-tag as5a9aca41 [2017-04-04 00:35:47.41632] DEBUG[24876] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #5839 [2017-04-04 00:35:47.41633] DEBUG[24876] chan_sip.c: Stopping retransmission on '2d7760e439b2d7fc3a4050e56a9f84c1@217.14.196.29:5060' of Request 102: Match Found [2017-04-04 00:35:47.41684] VERBOSE[24876] chan_sip.c: <--- SIP read from UDP:192.168.118.152:5060 ---> <-------------> [2017-04-04 00:35:47.41685] DEBUG[24876] chan_sip.c: Header 0 [ 0]: [2017-04-04 00:35:47.41686] DEBUG[24876] chan_sip.c: Destroying SIP dialog 2d7760e439b2d7fc3a4050e56a9f84c1@217.14.196.29:5060 [2017-04-04 00:35:47.41686] VERBOSE[24876] chan_sip.c: Really destroying SIP dialog '2d7760e439b2d7fc3a4050e56a9f84c1@217.14.196.29:5060' Method: OPTIONS [2017-04-04 00:35:47.42797] DEBUG[24876] chan_sip.c: Allocating new SIP dialog for 51041558245395403c93335a2a6584d3@217.14.196.29:5060 - OPTIONS (No RTP) [2017-04-04 00:35:47.42798] DEBUG[24876] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2017-04-04 00:35:47.42800] DEBUG[24876] acl.c: For destination '192.168.112.51', our source address is '217.14.196.29'. [2017-04-04 00:35:47.42800] DEBUG[24876] chan_sip.c: Setting AST_TRANSPORT_UDP with address 217.14.196.29:5060 [2017-04-04 00:35:47.42801] DEBUG[24876] chan_sip.c: SIP call-id changed from '51041558245395403c93335a2a6584d3@217.14.196.29:5060' to '608b91aa6d2f998c56402c77390ac439@217.14.196.29:5060' [2017-04-04 00:35:47.42803] DEBUG[24876] chan_sip.c: Initializing initreq for method OPTIONS - callid 608b91aa6d2f998c56402c77390ac439@217.14.196.29:5060 [2017-04-04 00:35:47.42803] DEBUG[24876] chan_sip.c: Header 0 [ 45]: OPTIONS sip:57576@192.168.112.51:5060 SIP/2.0 [2017-04-04 00:35:47.42804] DEBUG[24876] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK3438f225;rport [2017-04-04 00:35:47.42804] DEBUG[24876] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2017-04-04 00:35:47.42804] DEBUG[24876] chan_sip.c: Header 3 [ 58]: From: "MarkTEL" ;tag=as2fe68ea3 [2017-04-04 00:35:47.42804] DEBUG[24876] chan_sip.c: Header 4 [ 35]: To: [2017-04-04 00:35:47.42804] DEBUG[24876] chan_sip.c: Header 5 [ 41]: Contact: [2017-04-04 00:35:47.42805] DEBUG[24876] chan_sip.c: Header 6 [ 60]: Call-ID: 608b91aa6d2f998c56402c77390ac439@217.14.196.29:5060 [2017-04-04 00:35:47.42805] DEBUG[24876] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [2017-04-04 00:35:47.42805] DEBUG[24876] chan_sip.c: Header 8 [ 19]: User-Agent: MarkTEL [2017-04-04 00:35:47.42805] DEBUG[24876] chan_sip.c: Header 9 [ 35]: Date: Mon, 03 Apr 2017 20:35:47 GMT [2017-04-04 00:35:47.42805] DEBUG[24876] chan_sip.c: Header 10 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [2017-04-04 00:35:47.42805] DEBUG[24876] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2017-04-04 00:35:47.42806] VERBOSE[24876] chan_sip.c: Reliably Transmitting (NAT) to 192.168.112.51:5060: OPTIONS sip:57576@192.168.112.51:5060 SIP/2.0 Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK3438f225;rport Max-Forwards: 70 From: "MarkTEL" ;tag=as2fe68ea3 To: Contact: Call-ID: 608b91aa6d2f998c56402c77390ac439@217.14.196.29:5060 CSeq: 102 OPTIONS User-Agent: MarkTEL Date: Mon, 03 Apr 2017 20:35:47 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 --- [2017-04-04 00:35:47.42807] DEBUG[24876] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #7504 [2017-04-04 00:35:47.42807] DEBUG[24876] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.112.51:5060 [2017-04-04 00:35:47.43171] DEBUG[24876] chan_sip.c: Allocating new SIP dialog for 35d9a7cc1784800f393da52b25230712@217.14.196.29:5060 - OPTIONS (No RTP) [2017-04-04 00:35:47.43173] DEBUG[24876] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2017-04-04 00:35:47.43175] DEBUG[24876] acl.c: For destination '192.168.116.219', our source address is '217.14.196.29'. [2017-04-04 00:35:47.43176] DEBUG[24876] chan_sip.c: Setting AST_TRANSPORT_UDP with address 217.14.196.29:5060 [2017-04-04 00:35:47.43177] DEBUG[24876] chan_sip.c: SIP call-id changed from '35d9a7cc1784800f393da52b25230712@217.14.196.29:5060' to '122f10b42508f04c2b7e952e11a30002@217.14.196.29:5060' [2017-04-04 00:35:47.43180] DEBUG[24876] chan_sip.c: Initializing initreq for method OPTIONS - callid 122f10b42508f04c2b7e952e11a30002@217.14.196.29:5060 [2017-04-04 00:35:47.43181] DEBUG[24876] chan_sip.c: Header 0 [ 46]: OPTIONS sip:34377@192.168.116.219:5060 SIP/2.0 [2017-04-04 00:35:47.43181] DEBUG[24876] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK48b32a7f;rport [2017-04-04 00:35:47.43181] DEBUG[24876] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2017-04-04 00:35:47.43181] DEBUG[24876] chan_sip.c: Header 3 [ 58]: From: "MarkTEL" ;tag=as0cc29c9d [2017-04-04 00:35:47.43182] DEBUG[24876] chan_sip.c: Header 4 [ 36]: To: [2017-04-04 00:35:47.43182] DEBUG[24876] chan_sip.c: Header 5 [ 41]: Contact: [2017-04-04 00:35:47.43182] DEBUG[24876] chan_sip.c: Header 6 [ 60]: Call-ID: 122f10b42508f04c2b7e952e11a30002@217.14.196.29:5060 [2017-04-04 00:35:47.43183] DEBUG[24876] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [2017-04-04 00:35:47.43183] DEBUG[24876] chan_sip.c: Header 8 [ 19]: User-Agent: MarkTEL [2017-04-04 00:35:47.43183] DEBUG[24876] chan_sip.c: Header 9 [ 35]: Date: Mon, 03 Apr 2017 20:35:47 GMT [2017-04-04 00:35:47.43183] DEBUG[24876] chan_sip.c: Header 10 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [2017-04-04 00:35:47.43184] DEBUG[24876] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2017-04-04 00:35:47.43185] VERBOSE[24876] chan_sip.c: Reliably Transmitting (NAT) to 192.168.116.219:5060: OPTIONS sip:34377@192.168.116.219:5060 SIP/2.0 Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK48b32a7f;rport Max-Forwards: 70 From: "MarkTEL" ;tag=as0cc29c9d To: Contact: Call-ID: 122f10b42508f04c2b7e952e11a30002@217.14.196.29:5060 CSeq: 102 OPTIONS User-Agent: MarkTEL Date: Mon, 03 Apr 2017 20:35:47 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 --- [2017-04-04 00:35:47.43187] DEBUG[24876] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #615 [2017-04-04 00:35:47.43187] DEBUG[24876] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.116.219:5060 [2017-04-04 00:35:47.43315] VERBOSE[24876] chan_sip.c: <--- SIP read from UDP:192.168.118.171:5060 ---> <-------------> [2017-04-04 00:35:47.43316] DEBUG[24876] chan_sip.c: Header 0 [ 0]: [2017-04-04 00:35:47.43424] DEBUG[24876] chan_sip.c: SIP TIMER: Not rescheduling id #7359:OPTIONS (Method 3) (No timer T1) [2017-04-04 00:35:47.43426] VERBOSE[24876] chan_sip.c: Retransmitting #4 (NAT) to 91.146.45.26:5060: OPTIONS sip:61654@91.146.45.26:5060 SIP/2.0 Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK20e4ca72;rport Max-Forwards: 70 From: "MarkTEL" ;tag=as72b97bd5 To: Contact: Call-ID: 1501f6d145bcbc0900b42aba45a73725@217.14.196.29:5060 CSeq: 102 OPTIONS User-Agent: MarkTEL Date: Mon, 03 Apr 2017 20:35:43 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 --- [2017-04-04 00:35:47.43426] DEBUG[24876] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 91.146.45.26:5060 [2017-04-04 00:35:47.43429] DEBUG[24876] chan_sip.c: Auto destroying SIP dialog '4562b0f6-3ce651e2@192.168.35.44' [2017-04-04 00:35:47.43430] DEBUG[24876] chan_sip.c: Destroying SIP dialog 4562b0f6-3ce651e2@192.168.35.44 [2017-04-04 00:35:47.43430] VERBOSE[24876] chan_sip.c: Really destroying SIP dialog '4562b0f6-3ce651e2@192.168.35.44' Method: NOTIFY [2017-04-04 00:35:47.43624] DEBUG[24876] chan_sip.c: Destroying SIP dialog 1501f6d145bcbc0900b42aba45a73725@217.14.196.29:5060 [2017-04-04 00:35:47.43626] VERBOSE[24876] chan_sip.c: Really destroying SIP dialog '1501f6d145bcbc0900b42aba45a73725@217.14.196.29:5060' Method: OPTIONS [2017-04-04 00:35:47.43630] VERBOSE[24876] chan_sip.c: <--- SIP read from UDP:192.168.112.51:5060 ---> SIP/2.0 200 OK To: ;tag=8ff9016948d9885ei0 From: "MarkTEL" ;tag=as2fe68ea3 Call-ID: 608b91aa6d2f998c56402c77390ac439@217.14.196.29:5060 CSeq: 102 OPTIONS Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK3438f225 Server: Linksys/SPA2102-3.3.6 Content-Length: 0 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura <-------------> [2017-04-04 00:35:47.43631] DEBUG[24876] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2017-04-04 00:35:47.43631] DEBUG[24876] chan_sip.c: Header 1 [ 58]: To: ;tag=8ff9016948d9885ei0 [2017-04-04 00:35:47.43632] DEBUG[24876] chan_sip.c: Header 2 [ 58]: From: "MarkTEL" ;tag=as2fe68ea3 [2017-04-04 00:35:47.43632] DEBUG[24876] chan_sip.c: Header 3 [ 60]: Call-ID: 608b91aa6d2f998c56402c77390ac439@217.14.196.29:5060 [2017-04-04 00:35:47.43632] DEBUG[24876] chan_sip.c: Header 4 [ 17]: CSeq: 102 OPTIONS [2017-04-04 00:35:47.43633] DEBUG[24876] chan_sip.c: Header 5 [ 58]: Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK3438f225 [2017-04-04 00:35:47.43633] DEBUG[24876] chan_sip.c: Header 6 [ 29]: Server: Linksys/SPA2102-3.3.6 [2017-04-04 00:35:47.43633] DEBUG[24876] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [2017-04-04 00:35:47.43634] DEBUG[24876] chan_sip.c: Header 8 [ 61]: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER [2017-04-04 00:35:47.43634] DEBUG[24876] chan_sip.c: Header 9 [ 19]: Supported: x-sipura [2017-04-04 00:35:47.43634] VERBOSE[24876] chan_sip.c: --- (10 headers 0 lines) --- [2017-04-04 00:35:47.43635] DEBUG[24876] chan_sip.c: = Looking for Call ID: 608b91aa6d2f998c56402c77390ac439@217.14.196.29:5060 (Checking To) --From tag as2fe68ea3 --To-tag 8ff9016948d9885ei0 [2017-04-04 00:35:47.43637] DEBUG[24876] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #7504 [2017-04-04 00:35:47.43638] DEBUG[24876] chan_sip.c: Stopping retransmission on '608b91aa6d2f998c56402c77390ac439@217.14.196.29:5060' of Request 102: Match Found [2017-04-04 00:35:47.43681] DEBUG[24876] chan_sip.c: Destroying SIP dialog 608b91aa6d2f998c56402c77390ac439@217.14.196.29:5060 [2017-04-04 00:35:47.43683] VERBOSE[24876] chan_sip.c: Really destroying SIP dialog '608b91aa6d2f998c56402c77390ac439@217.14.196.29:5060' Method: OPTIONS [2017-04-04 00:35:47.43792] DEBUG[24876] chan_sip.c: SIP TIMER: Not rescheduling id #8129:OPTIONS (Method 3) (No timer T1) [2017-04-04 00:35:47.43794] VERBOSE[24876] chan_sip.c: Retransmitting #3 (NAT) to 192.168.36.17:5060: OPTIONS sip:63618@192.168.36.17:5060 SIP/2.0 Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK527fde46;rport Max-Forwards: 70 From: "MarkTEL" ;tag=as634d1cbe To: Contact: Call-ID: 6d815b07724e6a6528369ca1612db38a@217.14.196.29:5060 CSeq: 102 OPTIONS User-Agent: MarkTEL Date: Mon, 03 Apr 2017 20:35:44 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 --- [2017-04-04 00:35:47.43795] DEBUG[24876] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.36.17:5060 [2017-04-04 00:35:47.43905] VERBOSE[24876] chan_sip.c: <--- SIP read from UDP:132.147.64.70:1024 ---> <-------------> [2017-04-04 00:35:47.45313] DEBUG[24876] chan_sip.c: Auto destroying SIP dialog '7c44907d-f45320b4@192.168.116.56' [2017-04-04 00:35:47.45316] DEBUG[24876] chan_sip.c: Destroying SIP dialog 7c44907d-f45320b4@192.168.116.56 [2017-04-04 00:35:47.45316] VERBOSE[24876] chan_sip.c: Really destroying SIP dialog '7c44907d-f45320b4@192.168.116.56' Method: NOTIFY [2017-04-04 00:35:47.45526] DEBUG[24876] chan_sip.c: Auto destroying SIP dialog 'faf375e9-e0cd9a38@192.168.116.56' [2017-04-04 00:35:47.45528] DEBUG[24876] chan_sip.c: Destroying SIP dialog faf375e9-e0cd9a38@192.168.116.56 [2017-04-04 00:35:47.45528] VERBOSE[24876] chan_sip.c: Really destroying SIP dialog 'faf375e9-e0cd9a38@192.168.116.56' Method: NOTIFY [2017-04-04 00:35:47.45748] VERBOSE[24876] chan_sip.c: <--- SIP read from UDP:192.168.117.109:5061 ---> <-------------> [2017-04-04 00:35:47.45749] DEBUG[24876] chan_sip.c: Header 0 [ 0]: [2017-04-04 00:35:47.46119] VERBOSE[24876] chan_sip.c: <--- SIP read from UDP:148.251.118.84:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK6008855c;received=217.14.196.29;rport=5060 From: "89127600023" ;tag=as4cbcba37 To: ;tag=as7be8874c Call-ID: 1752376e588916d0368a8e9255f6a7df@217.14.196.29:5060 CSeq: 103 BYE Server: Asterisk PBX 13.8.0~dfsg-0~ppa2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 <-------------> [2017-04-04 00:35:47.46120] DEBUG[24876] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2017-04-04 00:35:47.46120] DEBUG[24876] chan_sip.c: Header 1 [ 92]: Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK6008855c;received=217.14.196.29;rport=5060 [2017-04-04 00:35:47.46121] DEBUG[24876] chan_sip.c: Header 2 [ 66]: From: "89127600023" ;tag=as4cbcba37 [2017-04-04 00:35:47.46121] DEBUG[24876] chan_sip.c: Header 3 [ 54]: To: ;tag=as7be8874c [2017-04-04 00:35:47.46121] DEBUG[24876] chan_sip.c: Header 4 [ 60]: Call-ID: 1752376e588916d0368a8e9255f6a7df@217.14.196.29:5060 [2017-04-04 00:35:47.46121] DEBUG[24876] chan_sip.c: Header 5 [ 13]: CSeq: 103 BYE [2017-04-04 00:35:47.46121] DEBUG[24876] chan_sip.c: Header 6 [ 39]: Server: Asterisk PBX 13.8.0~dfsg-0~ppa2 [2017-04-04 00:35:47.46122] DEBUG[24876] chan_sip.c: Header 7 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [2017-04-04 00:35:47.46122] DEBUG[24876] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [2017-04-04 00:35:47.46122] DEBUG[24876] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [2017-04-04 00:35:47.46123] VERBOSE[24876] chan_sip.c: --- (10 headers 0 lines) --- [2017-04-04 00:35:47.46123] DEBUG[24876] chan_sip.c: = Looking for Call ID: 1752376e588916d0368a8e9255f6a7df@217.14.196.29:5060 (Checking To) --From tag as4cbcba37 --To-tag as7be8874c [2017-04-04 00:35:47.46126] DEBUG[24876][C-00116155] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #9725 [2017-04-04 00:35:47.46126] DEBUG[24876][C-00116155] chan_sip.c: Stopping retransmission on '1752376e588916d0368a8e9255f6a7df@217.14.196.29:5060' of Request 103: Match Found [2017-04-04 00:35:47.46144] DEBUG[24876] chan_sip.c: Destroying SIP dialog 1752376e588916d0368a8e9255f6a7df@217.14.196.29:5060 [2017-04-04 00:35:47.46146] VERBOSE[24876] chan_sip.c: Really destroying SIP dialog '1752376e588916d0368a8e9255f6a7df@217.14.196.29:5060' Method: INVITE [2017-04-04 00:35:47.46148] DEBUG[24876] rtp_engine.c: Destroyed RTP instance '0x7f334510b680' [2017-04-04 00:35:47.46360] DEBUG[24876] chan_sip.c: Allocating new SIP dialog for 70d462d0534b469b479388893118a522@217.14.196.29:5060 - OPTIONS (No RTP) [2017-04-04 00:35:47.46361] DEBUG[24876] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2017-04-04 00:35:47.46363] DEBUG[24876] acl.c: For destination '192.168.37.212', our source address is '217.14.196.29'. [2017-04-04 00:35:47.46364] DEBUG[24876] chan_sip.c: Setting AST_TRANSPORT_UDP with address 217.14.196.29:5060 [2017-04-04 00:35:47.46365] DEBUG[24876] chan_sip.c: SIP call-id changed from '70d462d0534b469b479388893118a522@217.14.196.29:5060' to '2d7802bb2271653052de498418734703@217.14.196.29:5060' [2017-04-04 00:35:47.46367] DEBUG[24876] chan_sip.c: Initializing initreq for method OPTIONS - callid 2d7802bb2271653052de498418734703@217.14.196.29:5060 [2017-04-04 00:35:47.46367] DEBUG[24876] chan_sip.c: Header 0 [ 45]: OPTIONS sip:35310@192.168.37.212:5060 SIP/2.0 [2017-04-04 00:35:47.46368] DEBUG[24876] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK316f1cb1;rport [2017-04-04 00:35:47.46368] DEBUG[24876] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2017-04-04 00:35:47.46368] DEBUG[24876] chan_sip.c: Header 3 [ 58]: From: "MarkTEL" ;tag=as74f9468c [2017-04-04 00:35:47.46368] DEBUG[24876] chan_sip.c: Header 4 [ 35]: To: [2017-04-04 00:35:47.46369] DEBUG[24876] chan_sip.c: Header 5 [ 41]: Contact: [2017-04-04 00:35:47.46369] DEBUG[24876] chan_sip.c: Header 6 [ 60]: Call-ID: 2d7802bb2271653052de498418734703@217.14.196.29:5060 [2017-04-04 00:35:47.46369] DEBUG[24876] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [2017-04-04 00:35:47.46369] DEBUG[24876] chan_sip.c: Header 8 [ 19]: User-Agent: MarkTEL [2017-04-04 00:35:47.46369] DEBUG[24876] chan_sip.c: Header 9 [ 35]: Date: Mon, 03 Apr 2017 20:35:47 GMT [2017-04-04 00:35:47.46370] DEBUG[24876] chan_sip.c: Header 10 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [2017-04-04 00:35:47.46370] DEBUG[24876] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2017-04-04 00:35:47.46371] VERBOSE[24876] chan_sip.c: Reliably Transmitting (NAT) to 192.168.37.212:5060: OPTIONS sip:35310@192.168.37.212:5060 SIP/2.0 Via: SIP/2.0/UDP 217.14.196.29:5060;branch=z9hG4bK316f1cb1;rport Max-Forwards: 70 From: "MarkTEL" ;tag=as74f9468c To: Contact: Call-ID: 2d7802bb2271653052de498418734703@217.14.196.29:5060 CSeq: 102 OPTIONS User-Agent: MarkTEL Date: Mon, 03 Apr 2017 20:35:47 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 ---