[Feb 14 09:47:19] DEBUG[1910] db.c: Unable to find key '(bogus_peer)' in family 'SIP/Registry' [Feb 14 09:47:19] VERBOSE[1891] chan_sip.c: Reloading SIP [Feb 14 09:47:19] DEBUG[1891] config.c: Parsing /etc/asterisk/sip.conf [Feb 14 09:47:19] VERBOSE[1891] config.c: Parsing '/etc/asterisk/sip.conf': Found [Feb 14 09:47:19] DEBUG[1891] config.c: Parsing /etc/asterisk/users.conf [Feb 14 09:47:19] VERBOSE[1891] config.c: Parsing '/etc/asterisk/users.conf': Found [Feb 14 09:47:19] DEBUG[1891] acl.c: Multiple addresses. Using the first only [Feb 14 09:47:19] VERBOSE[1891] netsock2.c: Using SIP CoS mark 4 [Feb 14 09:47:19] DEBUG[1891] tcptls.c: Nothing changed in SIP TCP server [Feb 14 09:47:19] DEBUG[1891] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port. [Feb 14 09:47:19] DEBUG[1891] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port. [Feb 14 09:47:19] DEBUG[1891] config.c: Parsing /etc/asterisk/sip_notify.conf [Feb 14 09:47:19] VERBOSE[1891] config.c: Parsing '/etc/asterisk/sip_notify.conf': Found [Feb 14 09:47:19] DEBUG[1891] sched.c: Asterisk Schedule Dump (0 in Q, 47 Total, 6 Cache, 5 high-water) [Feb 14 09:47:19] DEBUG[1891] sched.c: ============================================================= [Feb 14 09:47:19] DEBUG[1891] sched.c: |ID Callback Data Time (sec:ms) | [Feb 14 09:47:19] DEBUG[1891] sched.c: +-----+-----------------+-----------------+-----------------+ [Feb 14 09:47:19] DEBUG[1891] sched.c: ============================================================= [Feb 14 09:47:41] DEBUG[1910] chan_sip.c: Asked to create a SIP channel with formats: (slin) [Feb 14 09:47:41] DEBUG[1910] chan_sip.c: Allocating new SIP dialog for 5e31f5b767f3a35927ed10b0740fc70d@[::1]:5060 - INVITE (No RTP) [Feb 14 09:47:41] DEBUG[1910] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f124c006b08' [Feb 14 09:47:41] DEBUG[1910] res_rtp_asterisk.c: Allocated port 13520 for RTP instance '0x7f124c006b08' [Feb 14 09:47:41] DEBUG[1910] rtp_engine.c: RTP instance '0x7f124c006b08' is setup and ready to go [Feb 14 09:47:41] DEBUG[1910] acl.c: Multiple addresses. Using the first only [Feb 14 09:47:41] DEBUG[1910] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f124c006b08' [Feb 14 09:47:41] VERBOSE[1910] netsock2.c: Using SIP RTP CoS mark 5 [Feb 14 09:47:41] DEBUG[1910] chan_sip.c: Setting NAT on RTP to Off [Feb 14 09:47:41] DEBUG[1910] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Feb 14 09:47:41] DEBUG[1910] chan_sip.c: Setting NAT on RTP to Off [Feb 14 09:47:41] DEBUG[1910] chan_sip.c: SIP call-id changed from '5e31f5b767f3a35927ed10b0740fc70d@[::1]:5060' to '68d3994f35b7c9d35c17ee953c878da5@192.168.1.172:5060' [Feb 14 09:47:41] DEBUG[1910] channel.c: Channel 0x7f124c00d0c8 'SIP/100-00000003' allocated [Feb 14 09:47:41] DEBUG[1941] chan_sip.c: Outgoing Call for 100 [Feb 14 09:47:41] DEBUG[1941] chan_sip.c: ** Our capability: (alaw) Video flag: False Text flag: False [Feb 14 09:47:41] DEBUG[1941] chan_sip.c: ** Our prefcodec: (slin) [Feb 14 09:47:41] VERBOSE[1941] chan_sip.c: Audio is at 13520 [Feb 14 09:47:41] VERBOSE[1941] chan_sip.c: Adding codec alaw to SDP [Feb 14 09:47:41] VERBOSE[1941] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Feb 14 09:47:41] DEBUG[1941] chan_sip.c: Initializing initreq for method INVITE - callid 68d3994f35b7c9d35c17ee953c878da5@192.168.1.172:5060 [Feb 14 09:47:41] VERBOSE[1941] chan_sip.c: Reliably Transmitting (no NAT) to 192.168.1.140:5060: INVITE sip:100@192.168.1.140 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.172:5060;branch=z9hG4bK64f421eb Max-Forwards: 70 From: "Anonymous" ;tag=as7f30c3c7 To: Contact: Call-ID: 68d3994f35b7c9d35c17ee953c878da5@192.168.1.172:5060 CSeq: 102 INVITE User-Agent: Asterisk PBX 15.2.1 Date: Wed, 14 Feb 2018 08:47:41 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Type: application/sdp Content-Length: 241 v=0 o=root 1060643296 1060643296 IN IP4 192.168.1.172 s=Asterisk PBX 15.2.1 c=IN IP4 192.168.1.172 t=0 0 m=audio 13520 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=maxptime:150 a=sendrecv --- [Feb 14 09:47:41] VERBOSE[1941] dial.c: Called 100 [Feb 14 09:47:41] VERBOSE[1891] chan_sip.c: <--- SIP read from UDP:192.168.1.140:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.1.172:5060;branch=z9hG4bK64f421eb From: "Anonymous" ;tag=as7f30c3c7 To: ;tag=1 Call-ID: 68d3994f35b7c9d35c17ee953c878da5@192.168.1.172:5060 CSeq: 102 INVITE Contact: Content-Length: 0 <-------------> [Feb 14 09:47:41] VERBOSE[1891] chan_sip.c: --- (8 headers 0 lines) --- [Feb 14 09:47:41] DEBUG[1891] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '68d3994f35b7c9d35c17ee953c878da5@192.168.1.172:5060' Request 102: Found [Feb 14 09:47:41] VERBOSE[1891] chan_sip.c: <--- SIP read from UDP:192.168.1.140:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.1.172:5060;branch=z9hG4bK64f421eb From: "Anonymous" ;tag=as7f30c3c7 To: ;tag=1 Call-ID: 68d3994f35b7c9d35c17ee953c878da5@192.168.1.172:5060 CSeq: 102 INVITE Contact: Content-Length: 0 <-------------> [Feb 14 09:47:41] VERBOSE[1891] chan_sip.c: --- (8 headers 0 lines) --- [Feb 14 09:47:41] DEBUG[1891] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '68d3994f35b7c9d35c17ee953c878da5@192.168.1.172:5060' Request 102: Found [Feb 14 09:47:41] VERBOSE[1891] sip/route.c: sip_route_dump: route/path hop: [Feb 14 09:47:41] VERBOSE[1941] dial.c: SIP/100-00000003 is ringing [Feb 14 09:47:41] VERBOSE[1891] chan_sip.c: <--- SIP read from UDP:192.168.1.140:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.172:5060;branch=z9hG4bK64f421eb From: "Anonymous" ;tag=as7f30c3c7 To: ;tag=1 Call-ID: 68d3994f35b7c9d35c17ee953c878da5@192.168.1.172:5060 CSeq: 102 INVITE Contact: Content-Type: application/sdp Content-Length: 150 v=0 o=user1 53655765 2353687637 IN IP4 192.168.1.140 s=- c=IN IP4 192.168.1.140 t=0 0 m=audio 49000 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=ptime:40 <-------------> [Feb 14 09:47:41] VERBOSE[1891] chan_sip.c: --- (9 headers 8 lines) --- [Feb 14 09:47:41] DEBUG[1891] chan_sip.c: Acked pending invite 102 [Feb 14 09:47:41] DEBUG[1891] chan_sip.c: Stopping retransmission on '68d3994f35b7c9d35c17ee953c878da5@192.168.1.172:5060' of Request 102: Match Found [Feb 14 09:47:41] VERBOSE[1891] chan_sip.c: Found RTP audio format 8 [Feb 14 09:47:41] DEBUG[1891] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7f12100b7350 [Feb 14 09:47:41] VERBOSE[1891] chan_sip.c: Found audio description format PCMA for ID 8 [Feb 14 09:47:41] DEBUG[1891] chan_sip.c: Setting framing to 40 [Feb 14 09:47:41] VERBOSE[1891] chan_sip.c: Capabilities: us - (alaw), peer - audio=(alaw)/video=(nothing)/text=(nothing), combined - (alaw) [Feb 14 09:47:41] VERBOSE[1891] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x0 (nothing), combined - 0x0 (nothing) [Feb 14 09:47:41] DEBUG[1891] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f124c006b08' [Feb 14 09:47:41] VERBOSE[1891] res_rtp_asterisk.c: 0x7f124c007a30 -- Strict RTP learning after remote address set to: 192.168.1.140:49000 [Feb 14 09:47:41] VERBOSE[1891] chan_sip.c: Peer audio RTP is at port 192.168.1.140:49000 [Feb 14 09:47:41] DEBUG[1891] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7f124c006b08' [Feb 14 09:47:41] DEBUG[1891] chan_sip.c: Setting native formats after processing SDP. peer joint formats (alaw), old nativeformats (alaw) [Feb 14 09:47:41] DEBUG[1891] channel.c: Channel SIP/100-00000003 setting read format path: alaw -> alaw [Feb 14 09:47:41] DEBUG[1891] channel.c: Channel SIP/100-00000003 setting write format path: alaw -> alaw [Feb 14 09:47:41] VERBOSE[1891] sip/route.c: sip_route_dump: route/path hop: [Feb 14 09:47:41] DEBUG[1891] chan_sip.c: Strict routing enforced for session 68d3994f35b7c9d35c17ee953c878da5@192.168.1.172:5060 [Feb 14 09:47:41] VERBOSE[1891] chan_sip.c: set_destination: Parsing for address/port to send to [Feb 14 09:47:41] VERBOSE[1891] chan_sip.c: set_destination: set destination to 192.168.1.140:5060 [Feb 14 09:47:41] VERBOSE[1891] chan_sip.c: Transmitting (no NAT) to 192.168.1.140:5060: ACK sip:192.168.1.140:5060;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 192.168.1.172:5060;branch=z9hG4bK79882946 Max-Forwards: 70 From: "Anonymous" ;tag=as7f30c3c7 To: ;tag=1 Contact: Call-ID: 68d3994f35b7c9d35c17ee953c878da5@192.168.1.172:5060 CSeq: 102 ACK User-Agent: Asterisk PBX 15.2.1 Content-Length: 0 --- [Feb 14 09:47:41] VERBOSE[1941] dial.c: SIP/100-00000003 answered [Feb 14 09:47:41] VERBOSE[1941] pbx.c: Launching MusicOnHold() on SIP/100-00000003 [Feb 14 09:47:41] VERBOSE[1941] res_musiconhold.c: Started music on hold, class 'default', on channel 'SIP/100-00000003' [Feb 14 09:47:41] DEBUG[1941] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Feb 14 09:47:41] DEBUG[1941] channel.c: Channel SIP/100-00000003 setting write format path: slin -> alaw [Feb 14 09:47:41] DEBUG[1941] res_musiconhold.c: SIP/100-00000003 Opened file 0 '/var/lib/asterisk/moh/macroform-cold_day' [Feb 14 09:47:41] DEBUG[1941] res_rtp_asterisk.c: Ooh, format changed from none to alaw [Feb 14 09:47:41] DEBUG[1941] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0x7f124c006b08' [Feb 14 09:48:01] DEBUG[1940] threadpool.c: Worker thread idle timeout reached. Dying.