[Dec 9 14:47:28] Asterisk 13.0.1 built by build @ f84488be2076 on a x86_64 running Linux on 2014-12-04 02:08:09 UTC [Dec 9 14:47:35] DEBUG[11909] acl.c: For destination '10.206.221.116', our source address is '10.206.221.116'. [Dec 9 14:47:35] DEBUG[11909] chan_sip.c: Setting AST_TRANSPORT_UDP with address 10.206.221.116:5080 [Dec 9 14:47:35] DEBUG[11909] netsock2.c: Splitting '10.206.221.116:5060' into... [Dec 9 14:47:35] DEBUG[11909] netsock2.c: ...host '10.206.221.116' and port '5060'. [Dec 9 14:47:35] DEBUG[11909] chan_sip.c: Allocating new SIP dialog for 54870b877978-6cf51c6nk42l - INVITE (No RTP) [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Dec 9 14:47:35] DEBUG[11909][C-00000000] sip/reqresp_parser.c: Begin: parsing SIP "Supported: timer, 100rel, replaces, from-change" [Dec 9 14:47:35] DEBUG[11909][C-00000000] sip/reqresp_parser.c: Found SIP option: -timer- [Dec 9 14:47:35] DEBUG[11909][C-00000000] sip/reqresp_parser.c: Matched SIP option: timer [Dec 9 14:47:35] DEBUG[11909][C-00000000] sip/reqresp_parser.c: Found SIP option: -100rel- [Dec 9 14:47:35] DEBUG[11909][C-00000000] sip/reqresp_parser.c: Matched SIP option: 100rel [Dec 9 14:47:35] DEBUG[11909][C-00000000] sip/reqresp_parser.c: Found SIP option: -replaces- [Dec 9 14:47:35] DEBUG[11909][C-00000000] sip/reqresp_parser.c: Matched SIP option: replaces [Dec 9 14:47:35] DEBUG[11909][C-00000000] sip/reqresp_parser.c: Found SIP option: -from-change- [Dec 9 14:47:35] DEBUG[11909][C-00000000] sip/reqresp_parser.c: Matched SIP option: from-change [Dec 9 14:47:35] DEBUG[11909][C-00000000] netsock2.c: Splitting '10.206.221.116:5060' into... [Dec 9 14:47:35] DEBUG[11909][C-00000000] netsock2.c: ...host '10.206.221.116' and port '5060'. [Dec 9 14:47:35] DEBUG[11909][C-00000000] netsock2.c: Splitting 'vbx49.ecntelecoms.com' into... [Dec 9 14:47:35] DEBUG[11909][C-00000000] netsock2.c: ...host 'vbx49.ecntelecoms.com' and port ''. [Dec 9 14:47:35] DEBUG[11909][C-00000000] res_config_mysql.c: MySQL RealTime: Connection okay. [Dec 9 14:47:35] DEBUG[11909][C-00000000] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sippeers_13 WHERE name = '0550010059' AND host = 'dynamic' [Dec 9 14:47:35] NOTICE[11909][C-00000000] chan_sip.c: The 'username' field for sip peers has been deprecated in favor of the term 'defaultuser' [Dec 9 14:47:35] WARNING[11909][C-00000000] sip/config_parser.c: nat=yes is deprecated, use nat=force_rport,comedia instead [Dec 9 14:47:35] DEBUG[11909][C-00000000] netsock2.c: Splitting '10.168.110.209' into... [Dec 9 14:47:35] DEBUG[11909][C-00000000] netsock2.c: ...host '10.168.110.209' and port ''. [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port. [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port. [Dec 9 14:47:35] DEBUG[11909][C-00000000] db.c: Unable to find key '0550010059' in family 'SIP/Registry' [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: -REALTIME- loading peer from database to memory. Name: 0550010059. Peer objects: 0 [Dec 9 14:47:35] DEBUG[11909][C-00000000] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x1dd77f58' [Dec 9 14:47:35] DEBUG[11909][C-00000000] res_rtp_asterisk.c: Allocated port 17940 for RTP instance '0x1dd77f58' [Dec 9 14:47:35] DEBUG[11909][C-00000000] pjsip: icess0x1dd7bcf ICE session created, comp_cnt=2, role is Unknown agent [Dec 9 14:47:35] DEBUG[11909][C-00000000] netsock2.c: Splitting '10.206.221.116' into... [Dec 9 14:47:35] DEBUG[11909][C-00000000] netsock2.c: ...host '10.206.221.116' and port ''. [Dec 9 14:47:35] DEBUG[11909][C-00000000] pjsip: icess0x1dd7bcf Candidate 0 added: comp_id=1, type=host, foundation=Hacedd74, addr=10.206.221.116:17940, base=10.206.221.116:17940, prio=0x7effffff (2130706431) [Dec 9 14:47:35] DEBUG[11909][C-00000000] rtp_engine.c: RTP instance '0x1dd77f58' is setup and ready to go [Dec 9 14:47:35] DEBUG[11909][C-00000000] pjsip: icess0x1dd7bcf Destroying ICE session 0x1dd7bcf8 [Dec 9 14:47:35] DEBUG[11909][C-00000000] pjsip: stuse0x1dd7e10 STUN session 0x1dd7e538 destroy request, ref_cnt=4 [Dec 9 14:47:35] DEBUG[11909][C-00000000] pjsip: stuse0x1dd7f10 STUN session 0x1dd7f538 destroy request, ref_cnt=3 [Dec 9 14:47:35] DEBUG[11909][C-00000000] pjsip: ice_session.c ICE session 0x1dd7bcf8 destroyed [Dec 9 14:47:35] DEBUG[11909][C-00000000] pjsip: stun_session.c STUN session 0x1dd7e538 destroyed [Dec 9 14:47:35] DEBUG[11909][C-00000000] pjsip: stun_session.c STUN session 0x1dd7f538 destroyed [Dec 9 14:47:35] DEBUG[11909][C-00000000] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x1dd7e918' [Dec 9 14:47:35] DEBUG[11909][C-00000000] res_rtp_asterisk.c: Allocated port 12638 for RTP instance '0x1dd7e918' [Dec 9 14:47:35] DEBUG[11909][C-00000000] pjsip: icess0x1dd7bec ICE session created, comp_cnt=2, role is Unknown agent [Dec 9 14:47:35] DEBUG[11909][C-00000000] netsock2.c: Splitting '10.206.221.116' into... [Dec 9 14:47:35] DEBUG[11909][C-00000000] netsock2.c: ...host '10.206.221.116' and port ''. [Dec 9 14:47:35] DEBUG[11909][C-00000000] pjsip: icess0x1dd7bec Candidate 0 added: comp_id=1, type=host, foundation=Hacedd74, addr=10.206.221.116:12638, base=10.206.221.116:12638, prio=0x7effffff (2130706431) [Dec 9 14:47:35] DEBUG[11909][C-00000000] rtp_engine.c: RTP instance '0x1dd7e918' is setup and ready to go [Dec 9 14:47:35] DEBUG[11909][C-00000000] pjsip: icess0x1dd7bec Destroying ICE session 0x1dd7bec8 [Dec 9 14:47:35] DEBUG[11909][C-00000000] pjsip: stuse0x1dd84bb STUN session 0x1dd84fe8 destroy request, ref_cnt=4 [Dec 9 14:47:35] DEBUG[11909][C-00000000] pjsip: stuse0x1dd85bb STUN session 0x1dd85fe8 destroy request, ref_cnt=3 [Dec 9 14:47:35] DEBUG[11909][C-00000000] pjsip: ice_session.c ICE session 0x1dd7bec8 destroyed [Dec 9 14:47:35] DEBUG[11909][C-00000000] pjsip: stun_session.c STUN session 0x1dd84fe8 destroyed [Dec 9 14:47:35] DEBUG[11909][C-00000000] pjsip: stun_session.c STUN session 0x1dd85fe8 destroyed [Dec 9 14:47:35] DEBUG[11909][C-00000000] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x1dd7e918' [Dec 9 14:47:35] VERBOSE[11909][C-00000000] netsock2.c: Using SIP VIDEO TOS bits 184 [Dec 9 14:47:35] VERBOSE[11909][C-00000000] netsock2.c: Using SIP VIDEO CoS mark 6 [Dec 9 14:47:35] DEBUG[11909][C-00000000] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x1dd77f58' [Dec 9 14:47:35] VERBOSE[11909][C-00000000] netsock2.c: Using SIP RTP TOS bits 184 [Dec 9 14:47:35] VERBOSE[11909][C-00000000] netsock2.c: Using SIP RTP CoS mark 5 [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Setting NAT on RTP to On [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Setting NAT on VRTP to On [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Processing session-level SDP o=root 1582248307 1582248307 IN IP4 10.168.110.209... OK. [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Processing session-level SDP s=call... UNSUPPORTED OR FAILED. [Dec 9 14:47:35] DEBUG[11909][C-00000000] netsock2.c: Splitting '10.168.110.209' into... [Dec 9 14:47:35] DEBUG[11909][C-00000000] netsock2.c: ...host '10.168.110.209' and port ''. [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Processing session-level SDP c=IN IP4 10.168.110.209... OK. [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Dec 9 14:47:35] DEBUG[11909][C-00000000] rtp_engine.c: Setting payload 9 (0x1dd86b58) based on m type on 0x2b939f617e40 [Dec 9 14:47:35] DEBUG[11909][C-00000000] rtp_engine.c: Setting payload 0 (0x1dd8aa08) based on m type on 0x2b939f617e40 [Dec 9 14:47:35] DEBUG[11909][C-00000000] rtp_engine.c: Setting payload 8 (0x1dd8ae68) based on m type on 0x2b939f617e40 [Dec 9 14:47:35] DEBUG[11909][C-00000000] rtp_engine.c: Setting payload 3 (0x1dd8b2c8) based on m type on 0x2b939f617e40 [Dec 9 14:47:35] DEBUG[11909][C-00000000] rtp_engine.c: Setting payload 99 (0x1dd8b728) based on m type on 0x2b939f617e40 [Dec 9 14:47:35] DEBUG[11909][C-00000000] rtp_engine.c: Setting payload 108 (0x1dd8bb88) based on m type on 0x2b939f617e40 [Dec 9 14:47:35] DEBUG[11909][C-00000000] rtp_engine.c: Setting payload 18 (0x1dd8bfe8) based on m type on 0x2b939f617e40 [Dec 9 14:47:35] DEBUG[11909][C-00000000] rtp_engine.c: Setting payload 101 (0x1dd8c448) based on m type on 0x2b939f617e40 [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:3 GSM/8000... OK. [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:99 G726-32/8000... OK. [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:108 AAL2-G726-32/8000... OK. [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK. [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=no... OK. [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED. [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Dec 9 14:47:35] DEBUG[11909][C-00000000] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x1dd77f58' [Dec 9 14:47:35] DEBUG[11909][C-00000000] rtp_engine.c: Copying payload 0 (0x1dd86b58) from 0x2b939f617e40 to 0x1dd78098 [Dec 9 14:47:35] DEBUG[11909][C-00000000] rtp_engine.c: Copying payload 3 (0x1dd8ae68) from 0x2b939f617e40 to 0x1dd78098 [Dec 9 14:47:35] DEBUG[11909][C-00000000] rtp_engine.c: Copying payload 8 (0x1dd8aa08) from 0x2b939f617e40 to 0x1dd78098 [Dec 9 14:47:35] DEBUG[11909][C-00000000] rtp_engine.c: Copying payload 9 (0x1dd8c8a8) from 0x2b939f617e40 to 0x1dd78098 [Dec 9 14:47:35] DEBUG[11909][C-00000000] rtp_engine.c: Copying payload 18 (0x1dd8bb88) from 0x2b939f617e40 to 0x1dd78098 [Dec 9 14:47:35] DEBUG[11909][C-00000000] rtp_engine.c: Copying payload 99 (0x1dd8b2c8) from 0x2b939f617e40 to 0x1dd78098 [Dec 9 14:47:35] DEBUG[11909][C-00000000] rtp_engine.c: Copying payload 101 (0x1dd8bfe8) from 0x2b939f617e40 to 0x1dd78098 [Dec 9 14:47:35] DEBUG[11909][C-00000000] rtp_engine.c: Copying payload 108 (0x1dd8b728) from 0x2b939f617e40 to 0x1dd78098 [Dec 9 14:47:35] DEBUG[11909][C-00000000] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x1dd77f58' [Dec 9 14:47:35] DEBUG[11909][C-00000000] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x1dd7e918' [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: We're settling with these formats: (ulaw|alaw|gsm|g726|g726aal2|g729|g722) [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Checking SIP call limits for device 0550010059 [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Updating call counter for incoming call [Dec 9 14:47:35] DEBUG[11909][C-00000000] netsock2.c: Splitting '10.206.221.116:5080' into... [Dec 9 14:47:35] DEBUG[11909][C-00000000] netsock2.c: ...host '10.206.221.116' and port ''. [Dec 9 14:47:35] DEBUG[11909][C-00000000] netsock2.c: Splitting 'vbx49.ecntelecoms.com' into... [Dec 9 14:47:35] DEBUG[11909][C-00000000] netsock2.c: ...host 'vbx49.ecntelecoms.com' and port ''. [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Incoming INVITE with 'timer' option supported [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: INVITE also has "Session-Expires" header. [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Session-Expires: 3600 [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Refresher: UAS [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: INVITE also has "Min-SE" header. [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Received Min-SE: 90 [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: *** Our native formats are (ulaw) [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: *** Joint capabilities are (ulaw|alaw|gsm|g726|g726aal2|g729|g722) [Dec 9 14:47:35] VERBOSE[11909][C-00000000] strings.c: failed to extend from 64 to 98 [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: *** Our capabilities are (g723|ulaw|alaw|gsm|g726|g726aal2|adpcm|slin|slin|slin|slin|) [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: *** AST_CODEC_CHOOSE formats are ulaw [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: This channel can handle video! HOLLYWOOD next! [Dec 9 14:47:35] DEBUG[11909][C-00000000] sip/route.c: sip_route_process_header: [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: SIP/0550010059-00000000: New call is still down.... Trying... [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 10.206.221.116:5060 [Dec 9 14:47:35] DEBUG[11909][C-00000000] res_config_mysql.c: MySQL RealTime: Connection okay. [Dec 9 14:47:35] DEBUG[11909][C-00000000] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sippeers_13 WHERE name = '200' AND host = 'dynamic' [Dec 9 14:47:35] DEBUG[11909][C-00000000] res_config_mysql.c: MySQL RealTime: Connection okay. [Dec 9 14:47:35] DEBUG[11909][C-00000000] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sippeers_13 WHERE name = '200' [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Launching 'Goto' [Dec 9 14:47:35] VERBOSE[11927][C-00000000] pbx.c: Executing [200@hostedpbx:1] Goto("SIP/0550010059-00000000", "testparkvar,200,1") in new stack [Dec 9 14:47:35] VERBOSE[11927][C-00000000] pbx.c: Goto (testparkvar,200,1) [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Launching 'Park' [Dec 9 14:47:35] VERBOSE[11927][C-00000000] pbx.c: Executing [200@testparkvar:1] Park("SIP/0550010059-00000000", "VBX48") in new stack [Dec 9 14:47:35] DEBUG[11927][C-00000000] chan_sip.c: SIP answering channel: SIP/0550010059-00000000 [Dec 9 14:47:35] DEBUG[11927][C-00000000] res_rtp_asterisk.c: Setting the marker bit due to a source update [Dec 9 14:47:35] DEBUG[11927][C-00000000] chan_sip.c: Setting framing from config on incoming call [Dec 9 14:47:35] DEBUG[11927][C-00000000] chan_sip.c: ** Our capability: (ulaw|alaw|gsm|g726|g726aal2|g729|g722) Video flag: True Text flag: True [Dec 9 14:47:35] DEBUG[11927][C-00000000] chan_sip.c: ** Our prefcodec: (nothing) [Dec 9 14:47:35] DEBUG[11927][C-00000000] chan_sip.c: -- Done with adding codecs to SDP [Dec 9 14:47:35] DEBUG[11927][C-00000000] chan_sip.c: Done building SDP. Settling with this capability: (ulaw|alaw|gsm|g726|g726aal2|g729|g722) [Dec 9 14:47:35] DEBUG[11927][C-00000000] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.206.221.116:5060 [Dec 9 14:47:35] DEBUG[11927][C-00000000] chan_sip.c: Session timer started: 4 - 54870b877978-6cf51c6nk42l 900000ms [Dec 9 14:47:35] DEBUG[11875] devicestate.c: No provider found, checking channel drivers for SIP - 0550010059 [Dec 9 14:47:35] DEBUG[11875] chan_sip.c: Checking device state for peer 0550010059 [Dec 9 14:47:35] DEBUG[11875] devicestate.c: Changing state for SIP/0550010059 - state 2 (In use) [Dec 9 14:47:35] DEBUG[11875] devicestate.c: No provider found, checking channel drivers for SIP - 0550010059 [Dec 9 14:47:35] DEBUG[11875] chan_sip.c: Checking device state for peer 0550010059 [Dec 9 14:47:35] DEBUG[11875] devicestate.c: Changing state for SIP/0550010059 - state 2 (In use) [Dec 9 14:47:35] DEBUG[11875] devicestate.c: No provider found, checking channel drivers for SIP - 0550010059 [Dec 9 14:47:35] DEBUG[11875] chan_sip.c: Checking device state for peer 0550010059 [Dec 9 14:47:35] DEBUG[11875] devicestate.c: Changing state for SIP/0550010059 - state 2 (In use) [Dec 9 14:47:35] DEBUG[11923] app_queue.c: Device 'SIP/0550010059' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Stopping retransmission on '54870b877978-6cf51c6nk42l' of Response 2: Match Found [Dec 9 14:47:35] DEBUG[11927][C-00000000] res_rtp_asterisk.c: Got RTCP report of 24 bytes [Dec 9 14:47:35] DEBUG[11927][C-00000000] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Dec 9 14:47:35] DEBUG[11927][C-00000000] acl.c: Attached to given IP address [Dec 9 14:47:35] DEBUG[11927][C-00000000] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Dec 9 14:47:35] DEBUG[11927][C-00000000] acl.c: Attached to given IP address [Dec 9 14:47:35] DEBUG[11918] netsock2.c: Splitting '10.168.110.209:55245' into... [Dec 9 14:47:35] DEBUG[11918] netsock2.c: ...host '10.168.110.209' and port '55245'. [Dec 9 14:47:35] DEBUG[11918] netsock2.c: Splitting '10.206.221.116:17940' into... [Dec 9 14:47:35] DEBUG[11918] netsock2.c: ...host '10.206.221.116' and port '17940'. [Dec 9 14:47:35] DEBUG[11927][C-00000000] res_rtp_asterisk.c: 0x1dd78bd0 -- Probation learning mode pass with source address 10.168.110.209:55244 [Dec 9 14:47:35] DEBUG[11927][C-00000000] res_parking.c: Parking lot 'VBX48' -- extension '700@parkedcalls' with application Park is compatible. [Dec 9 14:47:35] ERROR[11927][C-00000000] res_parking.c: Extensions for dynamic parking lot 'VBX48' could not be registered. Dynamic lot creation failed. [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx ael-dundi-e164-canonical pbx_ael [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx ael-dundi-e164-canonical/pbx_ael; refc=1; tmp.root=(nil) [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx ael-dundi-e164-customers pbx_ael [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx ael-dundi-e164-customers/pbx_ael; refc=1; tmp.root=(nil) [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx ael-dundi-e164-via-pstn pbx_ael [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx ael-dundi-e164-via-pstn/pbx_ael; refc=1; tmp.root=(nil) [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx ael-dundi-e164-local pbx_ael [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx ael-dundi-e164-local/pbx_ael; refc=1; tmp.root=(nil) [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx ael-dundi-e164-switch pbx_ael [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx ael-dundi-e164-switch/pbx_ael; refc=1; tmp.root=(nil) [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx ael-dundi-e164-lookup pbx_ael [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx ael-dundi-e164-lookup/pbx_ael; refc=1; tmp.root=(nil) [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx ael-dundi-e164 pbx_ael [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx ael-dundi-e164/pbx_ael; refc=1; tmp.root=0x1ddc7ce0 [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx ael-iaxtel700 pbx_ael [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx ael-iaxtel700/pbx_ael; refc=1; tmp.root=0x1ddc70b0 [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx ael-iaxprovider pbx_ael [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx ael-iaxprovider/pbx_ael; refc=1; tmp.root=(nil) [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx ael-trunkint pbx_ael [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx ael-trunkint/pbx_ael; refc=1; tmp.root=0x1ddc6d50 [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx ael-trunkld pbx_ael [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx ael-trunkld/pbx_ael; refc=1; tmp.root=0x1ddc6510 [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx ael-trunklocal pbx_ael [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx ael-trunklocal/pbx_ael; refc=1; tmp.root=0x1df686c0 [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx ael-trunktollfree pbx_ael [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx ael-trunktollfree/pbx_ael; refc=1; tmp.root=0x1df68270 [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx ael-international pbx_ael [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx ael-international/pbx_ael; refc=1; tmp.root=(nil) [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx ael-longdistance pbx_ael [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx ael-longdistance/pbx_ael; refc=1; tmp.root=(nil) [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx ael-local pbx_ael [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx ael-local/pbx_ael; refc=1; tmp.root=(nil) [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx ael-std-exten-ael pbx_ael [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx ael-std-exten-ael/pbx_ael; refc=1; tmp.root=0x1df65bf0 [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx ael-demo pbx_ael [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx ael-demo/pbx_ael; refc=1; tmp.root=0x1ddd89c0 [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx ael-default pbx_ael [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx ael-default/pbx_ael; refc=1; tmp.root=(nil) [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx ael-builtin-h-bubble pbx_ael [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx ael-builtin-h-bubble/pbx_ael; refc=1; tmp.root=0x1ddd7a70 [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx parkedcalls res_parking [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx parkedcalls/res_parking; refc=2; tmp.root=0x1dd55f30 [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx __func_periodic_hook_context__ func_periodic_hook [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx __func_periodic_hook_context__/func_periodic_hook; refc=1; tmp.root=0x1dd55520 [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx local pbx_lua [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx local/pbx_lua; refc=1; tmp.root=(nil) [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx demo pbx_lua [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx demo/pbx_lua; refc=1; tmp.root=0x1ddc5a20 [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx public pbx_lua [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx public/pbx_lua; refc=1; tmp.root=(nil) [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx default pbx_lua [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx default/pbx_lua; refc=1; tmp.root=0x1defa6a0 [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx testparkvar pbx_config [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx testparkvar/pbx_config; refc=1; tmp.root=0x1defa610 [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Investigate ctx hostedpbx pbx_config [Dec 9 14:47:35] DEBUG[11927][C-00000000] pbx.c: Couldn't delete ctx hostedpbx/pbx_config; refc=1; tmp.root=0x1defa730 [Dec 9 14:47:35] ERROR[11927][C-00000000] parking/parking_applications.c: Could not find parking lot: 'VBX48' [Dec 9 14:47:35] VERBOSE[11927][C-00000000] pbx.c: Auto fallthrough, channel 'SIP/0550010059-00000000' status is 'UNKNOWN' [Dec 9 14:47:35] DEBUG[11927][C-00000000] channel.c: Soft-Hanging (0x10) up channel 'SIP/0550010059-00000000' [Dec 9 14:47:35] DEBUG[11927][C-00000000] channel.c: Hanging up channel 'SIP/0550010059-00000000' [Dec 9 14:47:35] DEBUG[11927][C-00000000] chan_sip.c: Hangup call SIP/0550010059-00000000, SIP callid 54870b877978-6cf51c6nk42l [Dec 9 14:47:35] DEBUG[11927][C-00000000] chan_sip.c: Updating call counter for incoming call [Dec 9 14:47:35] DEBUG[11927][C-00000000] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x1dd77f58' [Dec 9 14:47:35] DEBUG[11927][C-00000000] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x1dd7e918' [Dec 9 14:47:35] DEBUG[11927][C-00000000] chan_sip.c: Session timer stopped: 4 - 54870b877978-6cf51c6nk42l [Dec 9 14:47:35] DEBUG[11927][C-00000000] chan_sip.c: Trying to put 'BYE sip:055' onto UDP socket destined for 10.206.221.116:5060 [Dec 9 14:47:35] DEBUG[11876] cdr.c: Finalized CDR for SIP/0550010059-00000000 - start 1418129255.088378 answer 1418129255.093332 end 1418129255.549513 dispo ANSWERED [Dec 9 14:47:35] DEBUG[11875] devicestate.c: No provider found, checking channel drivers for SIP - 0550010059 [Dec 9 14:47:35] DEBUG[11875] chan_sip.c: Checking device state for peer 0550010059 [Dec 9 14:47:35] DEBUG[11875] devicestate.c: Changing state for SIP/0550010059 - state 1 (Not in use) [Dec 9 14:47:35] DEBUG[11875] devicestate.c: No provider found, checking channel drivers for SIP - 0550010059 [Dec 9 14:47:35] DEBUG[11875] chan_sip.c: Checking device state for peer 0550010059 [Dec 9 14:47:35] DEBUG[11875] devicestate.c: Changing state for SIP/0550010059 - state 1 (Not in use) [Dec 9 14:47:35] DEBUG[11923] app_queue.c: Device 'SIP/0550010059' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 9 14:47:35] DEBUG[11876] cdr_mysql.c: Inserting a CDR record. [Dec 9 14:47:35] DEBUG[11876] cdr_mysql.c: SQL command as follows: INSERT INTO vas_cdr (`calldate`,`clid`,`src`,`dst`,`dcontext`,`channel`,`lastapp`,`lastdata`,`duration`,`billsec`,`disposition`,`amaflags`,`accountcode`,`uniqueid`) VALUES ('2014-12-09 14:47:35','\"19\" <0550010059>','0550010059','200','testparkvar','SIP/0550010059-00000000','Park','VBX48','0','0','ANSWERED','3','0550010059','1418129255.0') [Dec 9 14:47:35] DEBUG[11909][C-00000000] chan_sip.c: Stopping retransmission on '54870b877978-6cf51c6nk42l' of Request 102: Match Found [Dec 9 14:47:35] DEBUG[11909] chan_sip.c: Destroying SIP dialog 54870b877978-6cf51c6nk42l [Dec 9 14:47:35] DEBUG[11909] rtp_engine.c: Destroyed RTP instance '0x1dd77f58' [Dec 9 14:47:35] DEBUG[11909] rtp_engine.c: Destroyed RTP instance '0x1dd7e918' [Dec 9 14:47:43] VERBOSE[11897] asterisk.c: Remote UNIX connection disconnected [Dec 9 14:48:19] DEBUG[11888] threadpool.c: Worker thread idle timeout reached. Dying. [Dec 9 14:48:19] DEBUG[11886] threadpool.c: Destroying worker thread 1 [Dec 9 14:48:19] DEBUG[11889] threadpool.c: Worker thread idle timeout reached. Dying. [Dec 9 14:48:19] DEBUG[11886] threadpool.c: Destroying worker thread 2 [Dec 9 14:48:19] DEBUG[11890] threadpool.c: Worker thread idle timeout reached. Dying. [Dec 9 14:48:19] DEBUG[11886] threadpool.c: Destroying worker thread 3 [Dec 9 14:48:19] DEBUG[11891] threadpool.c: Worker thread idle timeout reached. Dying. [Dec 9 14:48:19] DEBUG[11886] threadpool.c: Destroying worker thread 4 [Dec 9 14:48:21] DEBUG[11893] threadpool.c: Worker thread idle timeout reached. Dying. [Dec 9 14:48:21] DEBUG[11865] threadpool.c: Destroying worker thread 5 [Dec 9 14:48:24] DEBUG[11887] threadpool.c: Worker thread idle timeout reached. Dying. [Dec 9 14:48:24] DEBUG[11886] threadpool.c: Destroying worker thread 0