[Jan 19 00:24:26] Asterisk 13.10.0 built by root @ 58503.simplecloud.club on a x86_64 running Linux on 2017-01-18 19:01:53 UTC [Jan 19 00:25:10] VERBOSE[2245] chan_sip.c: <--- SIP read from UDP:127.0.0.1:5060 ---> INVITE sip:79227707072@85.143.215.192 SIP/2.0 Record-Route: Record-Route: Via: SIP/2.0/UDP 127.0.0.1;branch=z9hG4bK5252.03bd4ab6ce101876fed512f5bdc8e124.0 Via: SIP/2.0/UDP 193.201.229.35:5060;rport=5060;branch=z9hG4bKqik62d30eookug1hrvi0.1 Content-Length: 244 Max-Forwards: 56 Request-Disposition: no-fork Supported: 100rel Content-Type: application/sdp MIME-version: 1.0 User-Agent: multifon.ru Expires: 180 Content-Disposition: session;handling=required From: ;tag=SDf8g6a01-286D324631353641EBCAB801 To: sip:79227707072@multifon.ru:5060 P-Asserted-Identity: sip:79222566747@multifon.ru:5060 Allow: ACK,BYE,CANCEL,INFO,INVITE,NOTIFY,OPTIONS,PRACK Call-ID: SDf8g6a01-27301352b7ea1c0f93267a1c979f75bb-v300g00010 CSeq: 1 INVITE x-trunk: 65 Contact: v=0 o=- 0 0 IN IP4 193.201.229.19 s=- c=IN IP4 193.201.229.19 t=0 0 m=audio 11402 RTP/AVP 8 3 9 0 18 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=maxptime:20 a=ptime:20 <-------------> [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 0 [ 45]: INVITE sip:79227707072@85.143.215.192 SIP/2.0 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 1 [ 98]: Record-Route: [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 2 [103]: Record-Route: [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 3 [ 80]: Via: SIP/2.0/UDP 127.0.0.1;branch=z9hG4bK5252.03bd4ab6ce101876fed512f5bdc8e124.0 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 4 [ 84]: Via: SIP/2.0/UDP 193.201.229.35:5060;rport=5060;branch=z9hG4bKqik62d30eookug1hrvi0.1 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 5 [ 19]: Content-Length: 244 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 6 [ 16]: Max-Forwards: 56 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 7 [ 28]: Request-Disposition: no-fork [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 8 [ 17]: Supported: 100rel [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 9 [ 29]: Content-Type: application/sdp [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 10 [ 17]: MIME-version: 1.0 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 11 [ 23]: User-Agent: multifon.ru [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 12 [ 12]: Expires: 180 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 13 [ 46]: Content-Disposition: session;handling=required [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 14 [ 74]: From: ;tag=SDf8g6a01-286D324631353641EBCAB801 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 15 [ 36]: To: sip:79227707072@multifon.ru:5060 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 16 [ 53]: P-Asserted-Identity: sip:79222566747@multifon.ru:5060 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 17 [ 54]: Allow: ACK,BYE,CANCEL,INFO,INVITE,NOTIFY,OPTIONS,PRACK [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 18 [ 62]: Call-ID: SDf8g6a01-27301352b7ea1c0f93267a1c979f75bb-v300g00010 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 19 [ 14]: CSeq: 1 INVITE [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 20 [ 11]: x-trunk: 65 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 21 [ 60]: Contact: [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 22 [ 0]: [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Body 0 [ 3]: v=0 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Body 1 [ 29]: o=- 0 0 IN IP4 193.201.229.19 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Body 2 [ 3]: s=- [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Body 3 [ 23]: c=IN IP4 193.201.229.19 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Body 4 [ 5]: t=0 0 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Body 5 [ 32]: m=audio 11402 RTP/AVP 8 3 9 0 18 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Body 7 [ 19]: a=rtpmap:3 GSM/8000 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Body 8 [ 20]: a=rtpmap:9 G722/8000 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Body 9 [ 20]: a=rtpmap:0 PCMU/8000 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Body 10 [ 21]: a=rtpmap:18 G729/8000 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Body 11 [ 13]: a=maxptime:20 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Body 12 [ 10]: a=ptime:20 [Jan 19 00:25:10] VERBOSE[2245] chan_sip.c: --- (22 headers 13 lines) --- [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: = Looking for Call ID: SDf8g6a01-27301352b7ea1c0f93267a1c979f75bb-v300g00010 (Checking From) --From tag SDf8g6a01-286D324631353641EBCAB801 --To-tag [Jan 19 00:25:10] DEBUG[2245] acl.c: For destination '127.0.0.1', our source address is '127.0.0.1'. [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Setting AST_TRANSPORT_UDP with address 127.0.0.1:5068 [Jan 19 00:25:10] DEBUG[2245] netsock2.c: Splitting '127.0.0.1' into... [Jan 19 00:25:10] DEBUG[2245] netsock2.c: ...host '127.0.0.1' and port ''. [Jan 19 00:25:10] VERBOSE[2245] chan_sip.c: Sending to 127.0.0.1:5060 (no NAT) [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Allocating new SIP dialog for SDf8g6a01-27301352b7ea1c0f93267a1c979f75bb-v300g00010 - INVITE (No RTP) [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Jan 19 00:25:10] DEBUG[2245][C-00000000] sip/reqresp_parser.c: Begin: parsing SIP "Supported: 100rel" [Jan 19 00:25:10] DEBUG[2245][C-00000000] sip/reqresp_parser.c: Found SIP option: -100rel- [Jan 19 00:25:10] DEBUG[2245][C-00000000] sip/reqresp_parser.c: Matched SIP option: 100rel [Jan 19 00:25:10] DEBUG[2245][C-00000000] netsock2.c: Splitting '127.0.0.1' into... [Jan 19 00:25:10] DEBUG[2245][C-00000000] netsock2.c: ...host '127.0.0.1' and port ''. [Jan 19 00:25:10] VERBOSE[2245][C-00000000] chan_sip.c: Sending to 127.0.0.1:5060 (no NAT) [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: Initializing initreq for method INVITE - callid SDf8g6a01-27301352b7ea1c0f93267a1c979f75bb-v300g00010 [Jan 19 00:25:10] VERBOSE[2245][C-00000000] chan_sip.c: Using INVITE request as basis request - SDf8g6a01-27301352b7ea1c0f93267a1c979f75bb-v300g00010 [Jan 19 00:25:10] DEBUG[2245][C-00000000] netsock2.c: Splitting 'multifon.ru' into... [Jan 19 00:25:10] DEBUG[2245][C-00000000] netsock2.c: ...host 'multifon.ru' and port ''. [Jan 19 00:25:10] VERBOSE[2245][C-00000000] chan_sip.c: Found peer 'kamailio' for '79222566747' from 127.0.0.1:5060 [Jan 19 00:25:10] DEBUG[2245][C-00000000] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x2962928' [Jan 19 00:25:10] DEBUG[2245][C-00000000] res_rtp_asterisk.c: Allocated port 27366 for RTP instance '0x2962928' [Jan 19 00:25:10] DEBUG[2245][C-00000000] rtp_engine.c: RTP instance '0x2962928' is setup and ready to go [Jan 19 00:25:10] DEBUG[2245][C-00000000] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x2962928' [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: Setting NAT on RTP to Off [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: Processing session-level SDP o=- 0 0 IN IP4 193.201.229.19... OK. [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: Processing session-level SDP s=-... UNSUPPORTED OR FAILED. [Jan 19 00:25:10] DEBUG[2245][C-00000000] netsock2.c: Splitting '193.201.229.19' into... [Jan 19 00:25:10] DEBUG[2245][C-00000000] netsock2.c: ...host '193.201.229.19' and port ''. [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: Processing session-level SDP c=IN IP4 193.201.229.19... OK. [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Jan 19 00:25:10] VERBOSE[2245][C-00000000] chan_sip.c: Found RTP audio format 8 [Jan 19 00:25:10] DEBUG[2245][C-00000000] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7f656c11c520 [Jan 19 00:25:10] VERBOSE[2245][C-00000000] chan_sip.c: Found RTP audio format 3 [Jan 19 00:25:10] DEBUG[2245][C-00000000] rtp_engine.c: Setting tx payload type 3 based on m type on 0x7f656c11c520 [Jan 19 00:25:10] VERBOSE[2245][C-00000000] chan_sip.c: Found RTP audio format 9 [Jan 19 00:25:10] DEBUG[2245][C-00000000] rtp_engine.c: Setting tx payload type 9 based on m type on 0x7f656c11c520 [Jan 19 00:25:10] VERBOSE[2245][C-00000000] chan_sip.c: Found RTP audio format 0 [Jan 19 00:25:10] DEBUG[2245][C-00000000] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7f656c11c520 [Jan 19 00:25:10] VERBOSE[2245][C-00000000] chan_sip.c: Found RTP audio format 18 [Jan 19 00:25:10] DEBUG[2245][C-00000000] rtp_engine.c: Setting tx payload type 18 based on m type on 0x7f656c11c520 [Jan 19 00:25:10] VERBOSE[2245][C-00000000] chan_sip.c: Found audio description format PCMA for ID 8 [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Jan 19 00:25:10] VERBOSE[2245][C-00000000] chan_sip.c: Found audio description format GSM for ID 3 [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:3 GSM/8000... OK. [Jan 19 00:25:10] VERBOSE[2245][C-00000000] chan_sip.c: Found audio description format G722 for ID 9 [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. [Jan 19 00:25:10] VERBOSE[2245][C-00000000] chan_sip.c: Found audio description format PCMU for ID 0 [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Jan 19 00:25:10] VERBOSE[2245][C-00000000] chan_sip.c: Found audio description format G729 for ID 18 [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK. [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=maxptime:20... UNSUPPORTED OR FAILED. [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Jan 19 00:25:10] VERBOSE[2245][C-00000000] chan_sip.c: Capabilities: us - (alaw|ulaw), peer - audio=(ulaw|gsm|alaw|g722|g729)/video=(nothing)/text=(nothing), combined - (alaw|ulaw) [Jan 19 00:25:10] VERBOSE[2245][C-00000000] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x0 (nothing), combined - 0x0 (nothing) [Jan 19 00:25:10] DEBUG[2245][C-00000000] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x2962928' [Jan 19 00:25:10] VERBOSE[2245][C-00000000] chan_sip.c: Peer audio RTP is at port 193.201.229.19:11402 [Jan 19 00:25:10] DEBUG[2245][C-00000000] rtp_engine.c: Copying payload 0 (0x2d75ea0) from 0x7f656c11c520 to 0x2962af0 [Jan 19 00:25:10] DEBUG[2245][C-00000000] rtp_engine.c: Copying payload 3 (0x2d75e20) from 0x7f656c11c520 to 0x2962af0 [Jan 19 00:25:10] DEBUG[2245][C-00000000] rtp_engine.c: Copying payload 8 (0x2bca490) from 0x7f656c11c520 to 0x2962af0 [Jan 19 00:25:10] DEBUG[2245][C-00000000] rtp_engine.c: Copying payload 9 (0x2d75e60) from 0x7f656c11c520 to 0x2962af0 [Jan 19 00:25:10] DEBUG[2245][C-00000000] rtp_engine.c: Copying payload 18 (0x2d75ee0) from 0x7f656c11c520 to 0x2962af0 [Jan 19 00:25:10] DEBUG[2245][C-00000000] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x2962928' [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: We're settling with these formats: (alaw|ulaw) [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: Checking SIP call limits for device [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: Updating call counter for incoming call [Jan 19 00:25:10] DEBUG[2245][C-00000000] netsock2.c: Splitting '85.143.215.192' into... [Jan 19 00:25:10] DEBUG[2245][C-00000000] netsock2.c: ...host '85.143.215.192' and port ''. [Jan 19 00:25:10] DEBUG[2245][C-00000000] netsock2.c: Splitting 'multifon.ru' into... [Jan 19 00:25:10] DEBUG[2245][C-00000000] netsock2.c: ...host 'multifon.ru' and port ''. [Jan 19 00:25:10] VERBOSE[2245][C-00000000] chan_sip.c: Looking for 79227707072 in main (domain 85.143.215.192) [Jan 19 00:25:10] DEBUG[2245][C-00000000] pbx_lua.c: Looking up 79227707072@main:1 [Jan 19 00:25:10] DEBUG[2173] threadpool.c: Increasing threadpool stasis-core's size by 1 [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: *** Our native formats are (alaw) [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: *** Joint capabilities are (alaw|ulaw) [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: *** Our capabilities are (alaw|ulaw) [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: *** AST_CODEC_CHOOSE formats are alaw [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: This channel will not be able to handle video. [Jan 19 00:25:10] DEBUG[2245][C-00000000] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21 [Jan 19 00:25:10] DEBUG[2245][C-00000000] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116 [Jan 19 00:25:10] DEBUG[2245][C-00000000] pbx_lua.c: Looking up 79227707072@main:1 [Jan 19 00:25:10] DEBUG[2245][C-00000000] sip/route.c: sip_route_process_header: [Jan 19 00:25:10] DEBUG[2245][C-00000000] sip/route.c: sip_route_process_header: [Jan 19 00:25:10] VERBOSE[2245][C-00000000] sip/route.c: sip_route_dump: route/path hop: [Jan 19 00:25:10] VERBOSE[2245][C-00000000] sip/route.c: sip_route_dump: route/path hop: [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: SIP/kamailio-00000000: New call is still down.... Trying... [Jan 19 00:25:10] VERBOSE[2245][C-00000000] chan_sip.c: <--- Transmitting (no NAT) to 127.0.0.1:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 127.0.0.1;branch=z9hG4bK5252.03bd4ab6ce101876fed512f5bdc8e124.0;received=127.0.0.1 Via: SIP/2.0/UDP 193.201.229.35:5060;rport=5060;branch=z9hG4bKqik62d30eookug1hrvi0.1 Record-Route: Record-Route: From: ;tag=SDf8g6a01-286D324631353641EBCAB801 To: sip:79227707072@multifon.ru:5060 Call-ID: SDf8g6a01-27301352b7ea1c0f93267a1c979f75bb-v300g00010 CSeq: 1 INVITE Server: Asterisk PBX 13.10.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Contact: Content-Length: 0 <------------> [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 127.0.0.1:5060 [Jan 19 00:25:10] DEBUG[2207] devicestate.c: No provider found, checking channel drivers for SIP - kamailio [Jan 19 00:25:10] DEBUG[2207] chan_sip.c: Checking device state for peer kamailio [Jan 19 00:25:10] DEBUG[2207] devicestate.c: Changing state for SIP/kamailio - state 1 (Not in use) [Jan 19 00:25:10] DEBUG[2374][C-00000000] pbx_lua.c: Looking up 79227707072@main:1 [Jan 19 00:25:10] DEBUG[2374][C-00000000] pbx_lua.c: Looking up 79227707072@main:1 [Jan 19 00:25:10] DEBUG[2207] devicestate.c: No provider found, checking channel drivers for SIP - kamailio [Jan 19 00:25:10] DEBUG[2207] chan_sip.c: Checking device state for peer kamailio [Jan 19 00:25:10] DEBUG[2207] devicestate.c: Changing state for SIP/kamailio - state 1 (Not in use) [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: SIP answering channel: SIP/kamailio-00000000 [Jan 19 00:25:10] DEBUG[2374][C-00000000] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: ** Our capability: (alaw|ulaw) Video flag: True Text flag: True [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: ** Our prefcodec: (nothing) [Jan 19 00:25:10] VERBOSE[2374][C-00000000] chan_sip.c: Audio is at 27366 [Jan 19 00:25:10] VERBOSE[2374][C-00000000] chan_sip.c: Adding codec alaw to SDP [Jan 19 00:25:10] VERBOSE[2374][C-00000000] chan_sip.c: Adding codec ulaw to SDP [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: -- Done with adding codecs to SDP [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Setting framing on incoming call: 0 [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Done building SDP. Settling with this capability: (alaw|ulaw) [Jan 19 00:25:10] VERBOSE[2374][C-00000000] chan_sip.c: <--- Reliably Transmitting (no NAT) to 127.0.0.1:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 127.0.0.1;branch=z9hG4bK5252.03bd4ab6ce101876fed512f5bdc8e124.0;received=127.0.0.1 Via: SIP/2.0/UDP 193.201.229.35:5060;rport=5060;branch=z9hG4bKqik62d30eookug1hrvi0.1 Record-Route: Record-Route: From: ;tag=SDf8g6a01-286D324631353641EBCAB801 To: sip:79227707072@multifon.ru:5060;tag=as797ef490 Call-ID: SDf8g6a01-27301352b7ea1c0f93267a1c979f75bb-v300g00010 CSeq: 1 INVITE Server: Asterisk PBX 13.10.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 200 v=0 o=root 922386801 922386801 IN IP4 127.0.0.1 s=Asterisk PBX 13.10.0 c=IN IP4 127.0.0.1 t=0 0 m=audio 27366 RTP/AVP 8 0 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=maxptime:150 a=sendrecv <------------> [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #12 [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 127.0.0.1:5060 [Jan 19 00:25:10] DEBUG[2374][C-00000000] res_rtp_asterisk.c: 0x2dbb8a0 -- Probation learning mode pass with source address 193.201.229.19:11402 [Jan 19 00:25:10] DEBUG[2374][C-00000000] pbx_lua.c: Looking up 79227707072@main:-1 [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Asked to create a SIP channel with formats: (alaw) [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Allocating new SIP dialog for 064af9b46890c52073c01d5b4eec0656@[2a04:ac00:1:6c9a:5054:ff:fe00:a021]:5068 - INVITE (No RTP) [Jan 19 00:25:10] DEBUG[2374][C-00000000] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x2985828' [Jan 19 00:25:10] DEBUG[2374][C-00000000] res_rtp_asterisk.c: Allocated port 28328 for RTP instance '0x2985828' [Jan 19 00:25:10] DEBUG[2374][C-00000000] rtp_engine.c: RTP instance '0x2985828' is setup and ready to go [Jan 19 00:25:10] DEBUG[2374][C-00000000] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x2985828' [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Setting NAT on RTP to Off [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Jan 19 00:25:10] DEBUG[2374][C-00000000] acl.c: For destination '127.0.0.1', our source address is '127.0.0.1'. [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Setting AST_TRANSPORT_UDP with address 127.0.0.1:5068 [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Setting NAT on RTP to Off [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: SIP call-id changed from '064af9b46890c52073c01d5b4eec0656@[2a04:ac00:1:6c9a:5054:ff:fe00:a021]:5068' to '18a0d3403f7788942e0ca7654e960fc7@127.0.0.1:5068' [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: *** Our native formats are (alaw) [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: *** Joint capabilities are (alaw) [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: *** Our capabilities are (alaw|ulaw) [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: *** AST_CODEC_CHOOSE formats are alaw [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: *** Our preferred formats from the incoming channel are (alaw) [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: This channel will not be able to handle video. [Jan 19 00:25:10] DEBUG[2374][C-00000000] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21 [Jan 19 00:25:10] DEBUG[2374][C-00000000] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116 [Jan 19 00:25:10] DEBUG[2374][C-00000000] pbx_lua.c: Looking up @main:1 [Jan 19 00:25:10] DEBUG[2374][C-00000000] channel_internal_api.c: Channel Call ID changing from [C-00000000] to [C-00000000] [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Outgoing Call for test [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Updating call counter for outgoing call [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: ** Our capability: (alaw|ulaw) Video flag: False Text flag: False [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: ** Our prefcodec: (alaw) [Jan 19 00:25:10] VERBOSE[2374][C-00000000] chan_sip.c: Audio is at 28328 [Jan 19 00:25:10] VERBOSE[2374][C-00000000] chan_sip.c: Adding codec alaw to SDP [Jan 19 00:25:10] VERBOSE[2374][C-00000000] chan_sip.c: Adding codec ulaw to SDP [Jan 19 00:25:10] VERBOSE[2374][C-00000000] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: -- Done with adding codecs to SDP [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Done building SDP. Settling with this capability: (alaw|ulaw) [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Initializing initreq for method INVITE - callid 18a0d3403f7788942e0ca7654e960fc7@127.0.0.1:5068 [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Header 0 [ 38]: INVITE sip:test@127.0.0.1:5060 SIP/2.0 [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Header 1 [ 54]: Via: SIP/2.0/UDP 127.0.0.1:5068;branch=z9hG4bK1f0786e2 [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Header 3 [ 53]: From: ;tag=as58f0a3f2 [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Header 4 [ 29]: To: [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Header 5 [ 41]: Contact: [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Header 6 [ 56]: Call-ID: 18a0d3403f7788942e0ca7654e960fc7@127.0.0.1:5068 [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Header 8 [ 32]: User-Agent: Asterisk PBX 13.10.0 [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Header 9 [ 35]: Date: Wed, 18 Jan 2017 19:25:10 GMT [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Header 10 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Jan 19 00:25:10] VERBOSE[2374][C-00000000] chan_sip.c: Reliably Transmitting (no NAT) to 127.0.0.1:5060: INVITE sip:test@127.0.0.1:5060 SIP/2.0 Via: SIP/2.0/UDP 127.0.0.1:5068;branch=z9hG4bK1f0786e2 Max-Forwards: 70 From: ;tag=as58f0a3f2 To: Contact: Call-ID: 18a0d3403f7788942e0ca7654e960fc7@127.0.0.1:5068 CSeq: 102 INVITE User-Agent: Asterisk PBX 13.10.0 Date: Wed, 18 Jan 2017 19:25:10 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Type: application/sdp Content-Length: 258 v=0 o=root 1029898123 1029898123 IN IP4 127.0.0.1 s=Asterisk PBX 13.10.0 c=IN IP4 127.0.0.1 t=0 0 m=audio 28328 RTP/AVP 8 0 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=maxptime:150 a=sendrecv --- [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #14 [Jan 19 00:25:10] DEBUG[2374][C-00000000] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 127.0.0.1:5060 [Jan 19 00:25:10] VERBOSE[2245] chan_sip.c: <--- SIP read from UDP:127.0.0.1:5060 ---> SIP/2.0 100 trying -- your call is important to us Via: SIP/2.0/UDP 127.0.0.1:5068;branch=z9hG4bK1f0786e2;rport=5068 From: ;tag=as58f0a3f2 To: Call-ID: 18a0d3403f7788942e0ca7654e960fc7@127.0.0.1:5068 CSeq: 102 INVITE Server: kamailio (4.4.2 (x86_64/linux)) Content-Length: 0 <-------------> [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 0 [ 50]: SIP/2.0 100 trying -- your call is important to us [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 127.0.0.1:5068;branch=z9hG4bK1f0786e2;rport=5068 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 2 [ 53]: From: ;tag=as58f0a3f2 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 3 [ 29]: To: [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 4 [ 56]: Call-ID: 18a0d3403f7788942e0ca7654e960fc7@127.0.0.1:5068 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 6 [ 39]: Server: kamailio (4.4.2 (x86_64/linux)) [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Jan 19 00:25:10] VERBOSE[2245] chan_sip.c: --- (8 headers 0 lines) --- [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: = Looking for Call ID: 18a0d3403f7788942e0ca7654e960fc7@127.0.0.1:5068 (Checking To) --From tag as58f0a3f2 --To-tag [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: *** SIP TIMER: Cancelling retransmission #14 - INVITE (got response) [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '18a0d3403f7788942e0ca7654e960fc7@127.0.0.1:5068' Request 102: Found [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: SIP response 100 to standard invite [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: SIP TIMER: Rescheduling retransmission #12 (1) SIP/2.0 - 1 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: ** SIP timers: Rescheduling retransmission 2 to 200 ms (t1 100 ms (Retrans id #12)) [Jan 19 00:25:10] VERBOSE[2245] chan_sip.c: Retransmitting #1 (no NAT) to 127.0.0.1:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 127.0.0.1;branch=z9hG4bK5252.03bd4ab6ce101876fed512f5bdc8e124.0;received=127.0.0.1 Via: SIP/2.0/UDP 193.201.229.35:5060;rport=5060;branch=z9hG4bKqik62d30eookug1hrvi0.1 Record-Route: Record-Route: From: ;tag=SDf8g6a01-286D324631353641EBCAB801 To: sip:79227707072@multifon.ru:5060;tag=as797ef490 Call-ID: SDf8g6a01-27301352b7ea1c0f93267a1c979f75bb-v300g00010 CSeq: 1 INVITE Server: Asterisk PBX 13.10.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 200 v=0 o=root 922386801 922386801 IN IP4 127.0.0.1 s=Asterisk PBX 13.10.0 c=IN IP4 127.0.0.1 t=0 0 m=audio 27366 RTP/AVP 8 0 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=maxptime:150 a=sendrecv --- [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 127.0.0.1:5060 [Jan 19 00:25:10] VERBOSE[2245] chan_sip.c: <--- SIP read from UDP:127.0.0.1:5060 ---> ACK sip:79227707072@127.0.0.1:5068 SIP/2.0 Via: SIP/2.0/UDP 127.0.0.1;branch=z9hG4bK5252.ef7f7d58e14061903f03e26a615abddb.0 Via: SIP/2.0/UDP 193.201.229.35:5060;rport=5060;branch=z9hG4bKel0ghg2038bt11bu2le0.1 Content-Length: 0 Max-Forwards: 57 Request-Disposition: no-fork CSeq: 1 ACK To: sip:79227707072@multifon.ru:5060;tag=as797ef490 From: ;tag=SDf8g6a01-286D324631353641EBCAB801 Call-ID: SDf8g6a01-27301352b7ea1c0f93267a1c979f75bb-v300g00010 <-------------> [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 0 [ 42]: ACK sip:79227707072@127.0.0.1:5068 SIP/2.0 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 1 [ 80]: Via: SIP/2.0/UDP 127.0.0.1;branch=z9hG4bK5252.ef7f7d58e14061903f03e26a615abddb.0 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 2 [ 84]: Via: SIP/2.0/UDP 193.201.229.35:5060;rport=5060;branch=z9hG4bKel0ghg2038bt11bu2le0.1 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 3 [ 17]: Content-Length: 0 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 4 [ 16]: Max-Forwards: 57 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 5 [ 28]: Request-Disposition: no-fork [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 6 [ 11]: CSeq: 1 ACK [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 7 [ 51]: To: sip:79227707072@multifon.ru:5060;tag=as797ef490 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 8 [ 74]: From: ;tag=SDf8g6a01-286D324631353641EBCAB801 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 9 [ 62]: Call-ID: SDf8g6a01-27301352b7ea1c0f93267a1c979f75bb-v300g00010 [Jan 19 00:25:10] VERBOSE[2245] chan_sip.c: --- (10 headers 0 lines) --- [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: = Looking for Call ID: SDf8g6a01-27301352b7ea1c0f93267a1c979f75bb-v300g00010 (Checking From) --From tag SDf8g6a01-286D324631353641EBCAB801 --To-tag as797ef490 [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #12 [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: Stopping retransmission on 'SDf8g6a01-27301352b7ea1c0f93267a1c979f75bb-v300g00010' of Response 1: Match Found [Jan 19 00:25:10] VERBOSE[2245] chan_sip.c: <--- SIP read from UDP:127.0.0.1:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 127.0.0.1:5068;rport=5068;branch=z9hG4bK1f0786e2 Record-Route: Record-Route: Contact: To: ;tag=ad76d640 From: ;tag=as58f0a3f2 Call-ID: 18a0d3403f7788942e0ca7654e960fc7@127.0.0.1:5068 CSeq: 102 INVITE User-Agent: 3CXPhone 6.0.26523.0 Content-Length: 0 <-------------> [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 0 [ 19]: SIP/2.0 180 Ringing [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 127.0.0.1:5068;rport=5068;branch=z9hG4bK1f0786e2 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 2 [ 67]: Record-Route: [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 3 [ 62]: Record-Route: [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 4 [ 68]: Contact: [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 5 [ 42]: To: ;tag=ad76d640 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 6 [ 53]: From: ;tag=as58f0a3f2 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 7 [ 56]: Call-ID: 18a0d3403f7788942e0ca7654e960fc7@127.0.0.1:5068 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 8 [ 16]: CSeq: 102 INVITE [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 9 [ 32]: User-Agent: 3CXPhone 6.0.26523.0 [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Jan 19 00:25:10] VERBOSE[2245] chan_sip.c: --- (11 headers 0 lines) --- [Jan 19 00:25:10] DEBUG[2245] chan_sip.c: = Looking for Call ID: 18a0d3403f7788942e0ca7654e960fc7@127.0.0.1:5068 (Checking To) --From tag as58f0a3f2 --To-tag ad76d640 [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '18a0d3403f7788942e0ca7654e960fc7@127.0.0.1:5068' Request 102: Found [Jan 19 00:25:10] DEBUG[2245][C-00000000] chan_sip.c: SIP response 180 to standard invite [Jan 19 00:25:10] DEBUG[2245][C-00000000] sip/route.c: sip_route_process_header: [Jan 19 00:25:10] DEBUG[2245][C-00000000] sip/route.c: sip_route_process_header: [Jan 19 00:25:10] VERBOSE[2245][C-00000000] sip/route.c: sip_route_dump: route/path hop: [Jan 19 00:25:10] VERBOSE[2245][C-00000000] sip/route.c: sip_route_dump: route/path hop: [Jan 19 00:25:10] DEBUG[2207] devicestate.c: No provider found, checking channel drivers for SIP - kamailio [Jan 19 00:25:10] DEBUG[2207] chan_sip.c: Checking device state for peer kamailio [Jan 19 00:25:10] DEBUG[2207] devicestate.c: Changing state for SIP/kamailio - state 1 (Not in use) [Jan 19 00:25:10] DEBUG[2374][C-00000000] rtp_engine.c: Setting early bridge SDP of 'SIP/kamailio-00000000' with that of 'SIP/kamailio-00000001' [Jan 19 00:25:10] DEBUG[2374][C-00000000] channel.c: Driver for channel 'SIP/kamailio-00000000' does not support indication 3, emulating it [Jan 19 00:25:10] DEBUG[2374][C-00000000] channel.c: Channel SIP/kamailio-00000000 setting write format path: slin -> alaw [Jan 19 00:25:10] DEBUG[2374][C-00000000] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Jan 19 00:25:10] DEBUG[2374][C-00000000] res_rtp_asterisk.c: Ooh, format changed from none to alaw [Jan 19 00:25:12] DEBUG[2374][C-00000000] res_rtp_asterisk.c: Got RTCP report of 84 bytes [Jan 19 00:25:12] DEBUG[2374][C-00000000] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jan 19 00:25:12] DEBUG[2374][C-00000000] netsock2.c: Splitting '58503.simplecloud.club' into... [Jan 19 00:25:12] DEBUG[2374][C-00000000] netsock2.c: ...host '58503.simplecloud.club' and port ''. [Jan 19 00:25:12] DEBUG[2374][C-00000000] acl.c: Multiple addresses. Using the first only [Jan 19 00:25:12] DEBUG[2374][C-00000000] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jan 19 00:25:12] DEBUG[2374][C-00000000] acl.c: Attached to given IP address [Jan 19 00:25:14] DTMF[2374][C-00000000] channel.c: DTMF begin '*' received on SIP/kamailio-00000000 [Jan 19 00:25:14] DTMF[2374][C-00000000] channel.c: DTMF begin passthrough '*' on SIP/kamailio-00000000 [Jan 19 00:25:14] DEBUG[2374][C-00000000] chan_sip.c: * Detected inband DTMF '*' [Jan 19 00:25:14] DTMF[2374][C-00000000] channel.c: DTMF end '*' received on SIP/kamailio-00000000, duration 242 ms [Jan 19 00:25:14] DTMF[2374][C-00000000] channel.c: DTMF end accepted with begin '*' on SIP/kamailio-00000000 [Jan 19 00:25:14] DTMF[2374][C-00000000] channel.c: DTMF end passthrough '*' on SIP/kamailio-00000000 [Jan 19 00:25:14] DEBUG[2374][C-00000000] pbx_lua.c: Looking up *@main:1 [Jan 19 00:25:15] DEBUG[2245] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jan 19 00:25:15] DEBUG[2245] netsock2.c: Splitting '58503.simplecloud.club' into... [Jan 19 00:25:15] DEBUG[2245] netsock2.c: ...host '58503.simplecloud.club' and port ''. [Jan 19 00:25:15] DEBUG[2245] acl.c: Multiple addresses. Using the first only [Jan 19 00:25:15] DEBUG[2245] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jan 19 00:25:15] DEBUG[2245] acl.c: Attached to given IP address [Jan 19 00:25:20] DEBUG[2245] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jan 19 00:25:20] DEBUG[2245] netsock2.c: Splitting '58503.simplecloud.club' into... [Jan 19 00:25:20] DEBUG[2245] netsock2.c: ...host '58503.simplecloud.club' and port ''. [Jan 19 00:25:20] DEBUG[2245] acl.c: Multiple addresses. Using the first only [Jan 19 00:25:20] DEBUG[2245] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jan 19 00:25:20] DEBUG[2245] acl.c: Attached to given IP address [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Allocating new SIP dialog for 49daa8cb05179895132f10d008bf93ad@[2a04:ac00:1:6c9a:5054:ff:fe00:a021]:5068 - OPTIONS (No RTP) [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Jan 19 00:25:24] DEBUG[2245] acl.c: For destination '127.0.0.1', our source address is '127.0.0.1'. [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Setting AST_TRANSPORT_UDP with address 127.0.0.1:5068 [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: SIP call-id changed from '49daa8cb05179895132f10d008bf93ad@[2a04:ac00:1:6c9a:5054:ff:fe00:a021]:5068' to '730eb3d0558e118e56b79fb67770e6e8@127.0.0.1:5068' [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Initializing initreq for method OPTIONS - callid 730eb3d0558e118e56b79fb67770e6e8@127.0.0.1:5068 [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Header 0 [ 29]: OPTIONS sip:127.0.0.1 SIP/2.0 [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Header 1 [ 54]: Via: SIP/2.0/UDP 127.0.0.1:5068;branch=z9hG4bK4d96ba42 [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Header 3 [ 61]: From: "asterisk" ;tag=as1f190005 [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Header 4 [ 19]: To: [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Header 5 [ 38]: Contact: [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Header 6 [ 56]: Call-ID: 730eb3d0558e118e56b79fb67770e6e8@127.0.0.1:5068 [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Header 8 [ 32]: User-Agent: Asterisk PBX 13.10.0 [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Header 9 [ 35]: Date: Wed, 18 Jan 2017 19:25:24 GMT [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Header 10 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Jan 19 00:25:24] VERBOSE[2245] chan_sip.c: Reliably Transmitting (no NAT) to 127.0.0.1:5060: OPTIONS sip:127.0.0.1 SIP/2.0 Via: SIP/2.0/UDP 127.0.0.1:5068;branch=z9hG4bK4d96ba42 Max-Forwards: 70 From: "asterisk" ;tag=as1f190005 To: Contact: Call-ID: 730eb3d0558e118e56b79fb67770e6e8@127.0.0.1:5068 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 13.10.0 Date: Wed, 18 Jan 2017 19:25:24 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 --- [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #9 [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 127.0.0.1:5060 [Jan 19 00:25:24] VERBOSE[2245] chan_sip.c: <--- SIP read from UDP:127.0.0.1:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 127.0.0.1:5068;branch=z9hG4bK4d96ba42 From: "asterisk" ;tag=as1f190005 To: ;tag=b27e1a1d33761e85846fc98f5f3a7e58.7539 Call-ID: 730eb3d0558e118e56b79fb67770e6e8@127.0.0.1:5068 CSeq: 102 OPTIONS Accept: */* Accept-Encoding: Accept-Language: en Supported: Server: kamailio (4.4.2 (x86_64/linux)) Content-Length: 0 <-------------> [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Header 1 [ 54]: Via: SIP/2.0/UDP 127.0.0.1:5068;branch=z9hG4bK4d96ba42 [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Header 2 [ 61]: From: "asterisk" ;tag=as1f190005 [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Header 3 [ 61]: To: ;tag=b27e1a1d33761e85846fc98f5f3a7e58.7539 [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Header 4 [ 56]: Call-ID: 730eb3d0558e118e56b79fb67770e6e8@127.0.0.1:5068 [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Header 6 [ 11]: Accept: */* [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Header 7 [ 17]: Accept-Encoding: [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Header 8 [ 19]: Accept-Language: en [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Header 9 [ 11]: Supported: [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Header 10 [ 39]: Server: kamailio (4.4.2 (x86_64/linux)) [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Jan 19 00:25:24] VERBOSE[2245] chan_sip.c: --- (12 headers 0 lines) --- [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: = Looking for Call ID: 730eb3d0558e118e56b79fb67770e6e8@127.0.0.1:5068 (Checking To) --From tag as1f190005 --To-tag b27e1a1d33761e85846fc98f5f3a7e58.7539 [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #9 [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Stopping retransmission on '730eb3d0558e118e56b79fb67770e6e8@127.0.0.1:5068' of Request 102: Match Found [Jan 19 00:25:24] DEBUG[2245] chan_sip.c: Destroying SIP dialog 730eb3d0558e118e56b79fb67770e6e8@127.0.0.1:5068 [Jan 19 00:25:24] VERBOSE[2245] chan_sip.c: Really destroying SIP dialog '730eb3d0558e118e56b79fb67770e6e8@127.0.0.1:5068' Method: OPTIONS [Jan 19 00:25:25] DEBUG[2245] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jan 19 00:25:25] DEBUG[2245] netsock2.c: Splitting '58503.simplecloud.club' into... [Jan 19 00:25:25] DEBUG[2245] netsock2.c: ...host '58503.simplecloud.club' and port ''. [Jan 19 00:25:25] DEBUG[2245] acl.c: Multiple addresses. Using the first only [Jan 19 00:25:25] DEBUG[2245] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jan 19 00:25:25] DEBUG[2245] acl.c: Attached to given IP address [Jan 19 00:25:26] VERBOSE[2245] chan_sip.c: <--- SIP read from UDP:127.0.0.1:5060 ---> BYE sip:79227707072@127.0.0.1:5068 SIP/2.0 Via: SIP/2.0/UDP 127.0.0.1;branch=z9hG4bK2252.666d14a9e66cd498dcb1d7654feb762e.0 Via: SIP/2.0/UDP 193.201.229.35:5060;rport=5060;branch=z9hG4bKel0ghg2038bt11bu2le0cd0000010.1 Content-Length: 0 Max-Forwards: 57 Request-Disposition: no-fork Reason: X.int;reasoncode=0x00000000;add-info=01CA.FFFE.0000 Reason: Q.850;cause=16 To: sip:79227707072@multifon.ru:5060;tag=as797ef490 From: ;tag=SDf8g6a01-286D324631353641EBCAB801 Call-ID: SDf8g6a01-27301352b7ea1c0f93267a1c979f75bb-v300g00010 CSeq: 2 BYE <-------------> [Jan 19 00:25:26] DEBUG[2245] chan_sip.c: Header 0 [ 42]: BYE sip:79227707072@127.0.0.1:5068 SIP/2.0 [Jan 19 00:25:26] DEBUG[2245] chan_sip.c: Header 1 [ 80]: Via: SIP/2.0/UDP 127.0.0.1;branch=z9hG4bK2252.666d14a9e66cd498dcb1d7654feb762e.0 [Jan 19 00:25:26] DEBUG[2245] chan_sip.c: Header 2 [ 93]: Via: SIP/2.0/UDP 193.201.229.35:5060;rport=5060;branch=z9hG4bKel0ghg2038bt11bu2le0cd0000010.1 [Jan 19 00:25:26] DEBUG[2245] chan_sip.c: Header 3 [ 17]: Content-Length: 0 [Jan 19 00:25:26] DEBUG[2245] chan_sip.c: Header 4 [ 16]: Max-Forwards: 57 [Jan 19 00:25:26] DEBUG[2245] chan_sip.c: Header 5 [ 28]: Request-Disposition: no-fork [Jan 19 00:25:26] DEBUG[2245] chan_sip.c: Header 6 [ 59]: Reason: X.int;reasoncode=0x00000000;add-info=01CA.FFFE.0000 [Jan 19 00:25:26] DEBUG[2245] chan_sip.c: Header 7 [ 22]: Reason: Q.850;cause=16 [Jan 19 00:25:26] DEBUG[2245] chan_sip.c: Header 8 [ 51]: To: sip:79227707072@multifon.ru:5060;tag=as797ef490 [Jan 19 00:25:26] DEBUG[2245] chan_sip.c: Header 9 [ 74]: From: ;tag=SDf8g6a01-286D324631353641EBCAB801 [Jan 19 00:25:26] DEBUG[2245] chan_sip.c: Header 10 [ 62]: Call-ID: SDf8g6a01-27301352b7ea1c0f93267a1c979f75bb-v300g00010 [Jan 19 00:25:26] DEBUG[2245] chan_sip.c: Header 11 [ 11]: CSeq: 2 BYE [Jan 19 00:25:26] VERBOSE[2245] chan_sip.c: --- (12 headers 0 lines) --- [Jan 19 00:25:26] DEBUG[2245] chan_sip.c: = Looking for Call ID: SDf8g6a01-27301352b7ea1c0f93267a1c979f75bb-v300g00010 (Checking From) --From tag SDf8g6a01-286D324631353641EBCAB801 --To-tag as797ef490 [Jan 19 00:25:34] DEBUG[2373] threadpool.c: Worker thread idle timeout reached. Dying. [Jan 19 00:25:34] DEBUG[2173] threadpool.c: Destroying worker thread 6