[Sep 11 14:11:28] DEBUG[6598] channel.c: setting peeraccount to stl-admin for Agent/0010 from data on channel SIP/69.30.55.34-0000009f [Sep 11 14:11:28] DEBUG[6598] channel.c: setting peeraccount to stl-admin for SIP/69.30.55.34-0000009f from data on channel Agent/0010 [Sep 11 14:13:33] DEBUG[6637] channel.c: setting peeraccount to stl-admin for Agent/0010 from data on channel SIP/69.30.55.34-000000a1 [Sep 11 14:13:33] DEBUG[6637] channel.c: setting peeraccount to stl-admin for SIP/69.30.55.34-000000a1 from data on channel Agent/0010 [Sep 11 14:14:19] DEBUG[6654] channel.c: setting peeraccount to stl-admin for Agent/0010 from data on channel SIP/69.30.55.34-000000a3 [Sep 11 14:14:19] DEBUG[6654] channel.c: setting peeraccount to stl-admin for SIP/69.30.55.34-000000a3 from data on channel Agent/0010 [Sep 11 14:29:51] DEBUG[6969] config.c: Parsing /etc/asterisk/logger.conf [Sep 11 14:29:51] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:29:51] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:29:51] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:29:51] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:29:51] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:29:52] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:29:52] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:29:52] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:29:53] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:29:53] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:29:53] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:29:54] DEBUG[742] chan_sip.c: Auto destroying SIP dialog 'XVOoL2uedsEAe0ym2yQA88Z2fn8M5rOt' [Sep 11 14:29:54] DEBUG[742] chan_sip.c: Destroying SIP dialog XVOoL2uedsEAe0ym2yQA88Z2fn8M5rOt [Sep 11 14:29:54] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:29:54] DEBUG[6893] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:29:54] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:29:54] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:29:55] DEBUG[742] chan_sip.c: = Looking for Call ID: 16yd69cvh2z90 (Checking From) --From tag 13k0jo9ljqihx --To-tag as3eb8097b [Sep 11 14:29:55] DEBUG[742] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [Sep 11 14:29:55] DEBUG[742] netsock2.c: Splitting '107.21.15.145:5060' into... [Sep 11 14:29:55] DEBUG[742] netsock2.c: ...host '107.21.15.145' and port '5060'. [Sep 11 14:29:55] DEBUG[742] chan_sip.c: Setting SIP_ALREADYGONE on dialog 16yd69cvh2z90 [Sep 11 14:29:55] DEBUG[742] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f83e0093978' [Sep 11 14:29:55] DEBUG[742] chan_sip.c: Received bye, issuing owner hangup [Sep 11 14:29:55] DEBUG[742] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 107.21.15.145:5060 [Sep 11 14:29:55] DEBUG[6893] channel.c: Set channel SIP/phono4-ext.voxeolabs.net-000000af to write format ulaw [Sep 11 14:29:55] DEBUG[6893] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:29:55] DEBUG[758] manager.c: Examining event: Event: Agentlogoff Privilege: agent,all Agent: 0000 Logintime: 158 Uniqueid: 1347391632.302 [Sep 11 14:29:55] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:29:55] DEBUG[6893] devicestate.c: device 'Agent/0000' state '5' [Sep 11 14:29:55] DEBUG[6893] pbx.c: Spawn extension (default,500,1) exited non-zero on 'SIP/phono4-ext.voxeolabs.net-000000af' [Sep 11 14:29:55] DEBUG[6893] channel.c: Soft-Hanging up channel 'SIP/phono4-ext.voxeolabs.net-000000af' [Sep 11 14:29:55] DEBUG[6893] channel.c: Hanging up channel 'SIP/phono4-ext.voxeolabs.net-000000af' [Sep 11 14:29:55] DEBUG[6893] chan_sip.c: Hangup call SIP/phono4-ext.voxeolabs.net-000000af, SIP callid 16yd69cvh2z90 [Sep 11 14:29:55] DEBUG[6893] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f83e0093978' [Sep 11 14:29:55] DEBUG[758] manager.c: Examining event: Event: Hangup Privilege: call,all Channel: SIP/phono4-ext.voxeolabs.net-000000af Uniqueid: 1347391632.302 CallerIDNum: a9bce45d-60a6-450e-865f-791103280c03 CallerIDName: ConnectedLineNum: ConnectedLineName: Cause: 0 Cause-txt: Unknown [Sep 11 14:29:55] DEBUG[6893] cdr_mysql.c: Inserting a CDR record. [Sep 11 14:29:55] DEBUG[6893] cdr_mysql.c: SQL command as follows: INSERT INTO cdr (`calldate`,`clid`,`src`,`dst`,`dcontext`,`channel`,`lastapp`,`duration`,`billsec`,`disposition`,`amaflags`,`uniqueid`) VALUES ('2012-09-11 14:27:12','a9bce45d-60a6-450e-865f-791103280c03','a9bce45d-60a6-450e-865f-791103280c03','500','default','SIP/phono4-ext.voxeolabs.net-000000af','AgentLogin','163','163','ANSWERED','3','1347391632.302') [Sep 11 14:29:55] DEBUG[720] devicestate.c: No provider found, checking channel drivers for SIP - phono4-ext.voxeolabs.net [Sep 11 14:29:55] DEBUG[720] chan_sip.c: Checking device state for peer phono4-ext.voxeolabs.net [Sep 11 14:29:55] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:29:55] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:29:55] DEBUG[720] devicestate.c: Changing state for SIP/phono4-ext.voxeolabs.net - state 4 (Invalid) [Sep 11 14:29:55] DEBUG[720] devicestate.c: device 'SIP/phono4-ext.voxeolabs.net' state '4' [Sep 11 14:29:56] DEBUG[763] manager.c: Examining event: Event: Hangup Privilege: call,all Channel: SIP/phono4-ext.voxeolabs.net-000000af Uniqueid: 1347391632.302 CallerIDNum: a9bce45d-60a6-450e-865f-791103280c03 CallerIDName: ConnectedLineNum: ConnectedLineName: Cause: 0 Cause-txt: Unknown [Sep 11 14:29:56] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:29:56] DEBUG[758] manager.c: Examining event: Event: QueueMemberStatus Privilege: agent,all Queue: so_crm_5 Location: Agent/0000 MemberName: admin Membership: realtime Penalty: 0 CallsTaken: 4 LastCall: 1347391682 Status: 5 Paused: 0 [Sep 11 14:29:56] DEBUG[757] app_queue.c: Device 'Agent/0000' changed to state '5' (Unavailable) [Sep 11 14:29:56] DEBUG[757] app_queue.c: Device 'SIP/phono4-ext.voxeolabs.net' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Sep 11 14:29:56] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:29:56] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:29:56] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:29:56] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:29:56] DEBUG[742] chan_sip.c: = Looking for Call ID: 3bed14f2-b870dc38-83eb436@70.167.153.136 (Checking From) --From tag 080c1054 --To-tag [Sep 11 14:29:56] DEBUG[742] acl.c: For destination '216.115.69.144', our source address is '50.22.175.70'. [Sep 11 14:29:56] DEBUG[742] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 50.22.175.70:5060 [Sep 11 14:29:56] DEBUG[742] chan_sip.c: Allocating new SIP dialog for 3bed14f2-b870dc38-83eb436@70.167.153.136 - OPTIONS (No RTP) [Sep 11 14:29:56] DEBUG[742] chan_sip.c: **** Received OPTIONS (3) - Command in SIP OPTIONS [Sep 11 14:29:56] DEBUG[742] netsock2.c: Splitting '50.22.175.70:5060' into... [Sep 11 14:29:56] DEBUG[742] netsock2.c: ...host '50.22.175.70' and port ''. [Sep 11 14:29:56] DEBUG[742] netsock2.c: Splitting 'invalid' into... [Sep 11 14:29:56] DEBUG[742] netsock2.c: ...host 'invalid' and port ''. [Sep 11 14:29:56] DEBUG[742] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 216.115.69.144:5060 [Sep 11 14:29:56] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:29:57] DEBUG[742] chan_sip.c: = Looking for Call ID: 4ultieponnfh (Checking From) --From tag 6kr6aom5h80k --To-tag [Sep 11 14:29:57] DEBUG[742] acl.c: For destination '107.21.15.145', our source address is '50.22.175.70'. [Sep 11 14:29:57] DEBUG[742] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 50.22.175.70:5060 [Sep 11 14:29:57] DEBUG[742] chan_sip.c: Allocating new SIP dialog for 4ultieponnfh - INVITE (No RTP) [Sep 11 14:29:57] DEBUG[742] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Sep 11 14:29:57] DEBUG[742] netsock2.c: Splitting '107.21.15.145:5060' into... [Sep 11 14:29:57] DEBUG[742] netsock2.c: ...host '107.21.15.145' and port '5060'. [Sep 11 14:29:57] DEBUG[742] netsock2.c: Splitting 'phono4-ext.voxeolabs.net' into... [Sep 11 14:29:57] DEBUG[742] netsock2.c: ...host 'phono4-ext.voxeolabs.net' and port ''. [Sep 11 14:29:57] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:29:57] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:29:57] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:29:58] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:29:58] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:29:58] DEBUG[742] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x1f2bf98' [Sep 11 14:29:58] DEBUG[742] res_rtp_asterisk.c: Allocated port 11054 for RTP instance '0x1f2bf98' [Sep 11 14:29:58] DEBUG[742] rtp_engine.c: RTP instance '0x1f2bf98' is setup and ready to go [Sep 11 14:29:58] DEBUG[742] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x1f2bf98' [Sep 11 14:29:58] DEBUG[742] chan_sip.c: Setting NAT on RTP to Off [Sep 11 14:29:58] DEBUG[742] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Sep 11 14:29:58] DEBUG[742] chan_sip.c: Processing session-level SDP o=- 0 0 IN IP4 107.21.15.145... UNSUPPORTED OR FAILED. [Sep 11 14:29:58] DEBUG[742] chan_sip.c: Processing session-level SDP s=voxeo... UNSUPPORTED OR FAILED. [Sep 11 14:29:58] DEBUG[742] netsock2.c: Splitting '107.21.15.145' into... [Sep 11 14:29:58] DEBUG[742] netsock2.c: ...host '107.21.15.145' and port ''. [Sep 11 14:29:58] DEBUG[742] chan_sip.c: Processing session-level SDP c=IN IP4 107.21.15.145... OK. [Sep 11 14:29:58] DEBUG[742] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Sep 11 14:29:58] DEBUG[742] rtp_engine.c: Setting payload 0 based on m type on 0x7f83e657b060 [Sep 11 14:29:58] DEBUG[742] rtp_engine.c: Setting payload 116 based on m type on 0x7f83e657b060 [Sep 11 14:29:58] DEBUG[742] rtp_engine.c: Setting payload 9 based on m type on 0x7f83e657b060 [Sep 11 14:29:58] DEBUG[742] rtp_engine.c: Setting payload 101 based on m type on 0x7f83e657b060 [Sep 11 14:29:58] DEBUG[742] rtp_engine.c: Setting payload 115 based on m type on 0x7f83e657b060 [Sep 11 14:29:58] DEBUG[742] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Sep 11 14:29:58] DEBUG[742] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:116 SPEEX/16000... OK. [Sep 11 14:29:58] DEBUG[742] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. [Sep 11 14:29:58] DEBUG[742] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Sep 11 14:29:58] DEBUG[742] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED. [Sep 11 14:29:58] DEBUG[742] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:115 SPEEX/8000... OK. [Sep 11 14:29:58] DEBUG[742] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Sep 11 14:29:58] DEBUG[742] rtp_engine.c: Incorporating payload 0 on 0x7f83e657b060 [Sep 11 14:29:58] DEBUG[742] rtp_engine.c: Incorporating payload 9 on 0x7f83e657b060 [Sep 11 14:29:58] DEBUG[742] rtp_engine.c: Incorporating payload 101 on 0x7f83e657b060 [Sep 11 14:29:58] DEBUG[742] rtp_engine.c: Incorporating payload 115 on 0x7f83e657b060 [Sep 11 14:29:58] DEBUG[742] rtp_engine.c: Incorporating payload 116 on 0x7f83e657b060 [Sep 11 14:29:58] DEBUG[742] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x1f2bf98' [Sep 11 14:29:58] DEBUG[742] rtp_engine.c: Copying payload 0 from 0x7f83e657b060 to 0x1f2c160 [Sep 11 14:29:58] DEBUG[742] rtp_engine.c: Copying payload 9 from 0x7f83e657b060 to 0x1f2c160 [Sep 11 14:29:58] DEBUG[742] rtp_engine.c: Copying payload 101 from 0x7f83e657b060 to 0x1f2c160 [Sep 11 14:29:58] DEBUG[742] rtp_engine.c: Copying payload 115 from 0x7f83e657b060 to 0x1f2c160 [Sep 11 14:29:58] DEBUG[742] rtp_engine.c: Copying payload 116 from 0x7f83e657b060 to 0x1f2c160 [Sep 11 14:29:58] DEBUG[742] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x1f2bf98' [Sep 11 14:29:58] DEBUG[742] chan_sip.c: We're settling with these formats: 0x4 (ulaw) [Sep 11 14:29:58] DEBUG[742] chan_sip.c: Checking SIP call limits for device [Sep 11 14:29:58] DEBUG[742] chan_sip.c: Updating call counter for incoming call [Sep 11 14:29:58] DEBUG[742] netsock2.c: Splitting '50.22.175.70' into... [Sep 11 14:29:58] DEBUG[742] netsock2.c: ...host '50.22.175.70' and port ''. [Sep 11 14:29:58] DEBUG[742] netsock2.c: Splitting 'phono4-ext.voxeolabs.net' into... [Sep 11 14:29:58] DEBUG[742] netsock2.c: ...host 'phono4-ext.voxeolabs.net' and port ''. [Sep 11 14:29:58] DEBUG[742] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Sep 11 14:29:58] DEBUG[742] chan_sip.c: *** Joint capabilities are 0x4 (ulaw) [Sep 11 14:29:58] DEBUG[758] manager.c: Examining event: Event: Newchannel Privilege: call,all Channel: SIP/phono4-ext.voxeolabs.net-000000b2 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: a9bce45d-60a6-450e-865f-791103280c03 CallerIDName: AccountCode: Exten: 500 Context: default Uniqueid: 1347391798.309 [Sep 11 14:29:58] DEBUG[742] chan_sip.c: *** Our capabilities are 0x80000008010e (gsm|ulaw|alaw|g729|h263|testlaw) [Sep 11 14:29:58] DEBUG[742] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Sep 11 14:29:58] DEBUG[742] chan_sip.c: This channel will not be able to handle video. [Sep 11 14:29:58] DEBUG[742] chan_sip.c: build_route: Contact hop: [Sep 11 14:29:58] DEBUG[742] chan_sip.c: SIP/phono4-ext.voxeolabs.net-000000b2: New call is still down.... Trying... [Sep 11 14:29:58] DEBUG[742] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 107.21.15.145:5060 [Sep 11 14:29:58] DEBUG[720] devicestate.c: No provider found, checking channel drivers for SIP - phono4-ext.voxeolabs.net [Sep 11 14:29:58] DEBUG[720] chan_sip.c: Checking device state for peer phono4-ext.voxeolabs.net [Sep 11 14:29:58] DEBUG[758] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: SIP/phono4-ext.voxeolabs.net-000000b2 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: a9bce45d-60a6-450e-865f-791103280c03 CallerIDName: ConnectedLineNum: ConnectedLineName: Uniqueid: 1347391798.309 [Sep 11 14:29:58] DEBUG[6976] pbx.c: Launching 'AgentLogin' [Sep 11 14:29:58] DEBUG[742] chan_sip.c: = Looking for Call ID: 4ultieponnfh (Checking From) --From tag 6kr6aom5h80k --To-tag [Sep 11 14:29:58] DEBUG[742] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Sep 11 14:29:58] DEBUG[742] chan_sip.c: Ignoring SIP message because of retransmit (INVITE Seqno 1, ours 1) [Sep 11 14:29:58] DEBUG[742] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 107.21.15.145:5060 [Sep 11 14:29:58] DEBUG[742] chan_sip.c: = Looking for Call ID: 4ultieponnfh (Checking From) --From tag 6kr6aom5h80k --To-tag [Sep 11 14:29:58] DEBUG[742] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Sep 11 14:29:58] DEBUG[742] chan_sip.c: Ignoring SIP message because of retransmit (INVITE Seqno 1, ours 1) [Sep 11 14:29:58] DEBUG[742] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 107.21.15.145:5060 [Sep 11 14:29:58] DEBUG[6976] chan_sip.c: SIP answering channel: SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:29:58] DEBUG[6976] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:29:58] DEBUG[758] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: SIP/phono4-ext.voxeolabs.net-000000b2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: a9bce45d-60a6-450e-865f-791103280c03 CallerIDName: ConnectedLineNum: ConnectedLineName: Uniqueid: 1347391798.309 [Sep 11 14:29:58] DEBUG[6976] chan_sip.c: Setting framing from config on incoming call [Sep 11 14:29:58] DEBUG[6976] chan_sip.c: ** Our capability: 0x4 (ulaw) Video flag: True Text flag: True [Sep 11 14:29:58] DEBUG[6976] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Sep 11 14:29:58] DEBUG[6976] chan_sip.c: -- Done with adding codecs to SDP [Sep 11 14:29:58] DEBUG[6976] chan_sip.c: Done building SDP. Settling with this capability: 0x4 (ulaw) [Sep 11 14:29:58] DEBUG[6976] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 107.21.15.145:5060 [Sep 11 14:29:58] DEBUG[742] chan_sip.c: = Looking for Call ID: 4ultieponnfh (Checking From) --From tag 6kr6aom5h80k --To-tag as2885fbd6 [Sep 11 14:29:58] DEBUG[742] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Sep 11 14:29:58] DEBUG[742] chan_sip.c: Stopping retransmission on '4ultieponnfh' of Response 1: Match Found [Sep 11 14:29:58] DEBUG[6976] channel.c: Set channel SIP/phono4-ext.voxeolabs.net-000000b2 to write format gsm [Sep 11 14:29:58] DEBUG[6976] res_rtp_asterisk.c: Ooh, format changed from unknown to ulaw [Sep 11 14:29:58] DEBUG[6976] res_rtp_asterisk.c: Created smoother: format: ulaw ms: 20 len: 160 [Sep 11 14:29:58] DEBUG[6976] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Sep 11 14:29:58] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:29:58] DEBUG[6976] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 48 (0), at 107.21.15.145:20714 [Sep 11 14:29:58] DTMF[6976] channel.c: DTMF begin '0' received on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:29:58] DTMF[6976] channel.c: DTMF begin ignored '0' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:29:58] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:29:58] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:29:58] DEBUG[6976] res_rtp_asterisk.c: Creating END DTMF Frame: 48 (0), at 107.21.15.145:20714 [Sep 11 14:29:58] DTMF[6976] channel.c: DTMF end '0' received on SIP/phono4-ext.voxeolabs.net-000000b2, duration 0 ms [Sep 11 14:29:58] DTMF[6976] channel.c: DTMF end accepted without begin '0' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:29:58] DTMF[6976] channel.c: DTMF end passthrough '0' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:29:58] DEBUG[6976] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:29:58] DEBUG[6976] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:29:58] DEBUG[6976] channel.c: Set channel SIP/phono4-ext.voxeolabs.net-000000b2 to write format ulaw [Sep 11 14:29:58] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:29:58] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:29:59] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:29:59] DEBUG[6976] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 48 (0), at 107.21.15.145:20714 [Sep 11 14:29:59] DTMF[6976] channel.c: DTMF begin '0' received on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:29:59] DTMF[6976] channel.c: DTMF begin ignored '0' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:29:59] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:29:59] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:29:59] DEBUG[6976] res_rtp_asterisk.c: Creating END DTMF Frame: 48 (0), at 107.21.15.145:20714 [Sep 11 14:29:59] DTMF[6976] channel.c: DTMF end '0' received on SIP/phono4-ext.voxeolabs.net-000000b2, duration 0 ms [Sep 11 14:29:59] DTMF[6976] channel.c: DTMF end accepted without begin '0' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:29:59] DTMF[6976] channel.c: DTMF end passthrough '0' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:29:59] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:29:59] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:29:59] DEBUG[720] devicestate.c: Changing state for SIP/phono4-ext.voxeolabs.net - state 4 (Invalid) [Sep 11 14:29:59] DEBUG[720] devicestate.c: device 'SIP/phono4-ext.voxeolabs.net' state '4' [Sep 11 14:29:59] DEBUG[720] devicestate.c: No provider found, checking channel drivers for SIP - phono4-ext.voxeolabs.net [Sep 11 14:29:59] DEBUG[720] chan_sip.c: Checking device state for peer phono4-ext.voxeolabs.net [Sep 11 14:29:59] DEBUG[757] app_queue.c: Device 'SIP/phono4-ext.voxeolabs.net' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Sep 11 14:29:59] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:29:59] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:29:59] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:29:59] DEBUG[6976] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 48 (0), at 107.21.15.145:20714 [Sep 11 14:29:59] DTMF[6976] channel.c: DTMF begin '0' received on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:29:59] DTMF[6976] channel.c: DTMF begin ignored '0' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:29:59] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:29:59] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:29:59] DEBUG[6976] res_rtp_asterisk.c: Creating END DTMF Frame: 48 (0), at 107.21.15.145:20714 [Sep 11 14:29:59] DTMF[6976] channel.c: DTMF end '0' received on SIP/phono4-ext.voxeolabs.net-000000b2, duration 0 ms [Sep 11 14:29:59] DTMF[6976] channel.c: DTMF end accepted without begin '0' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:29:59] DTMF[6976] channel.c: DTMF end passthrough '0' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:29:59] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:29:59] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:29:59] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:29:59] DEBUG[6976] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 48 (0), at 107.21.15.145:20714 [Sep 11 14:29:59] DTMF[6976] channel.c: DTMF begin '0' received on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:29:59] DTMF[6976] channel.c: DTMF begin ignored '0' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:29:59] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:29:59] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:29:59] DEBUG[6976] res_rtp_asterisk.c: Creating END DTMF Frame: 48 (0), at 107.21.15.145:20714 [Sep 11 14:29:59] DTMF[6976] channel.c: DTMF end '0' received on SIP/phono4-ext.voxeolabs.net-000000b2, duration 0 ms [Sep 11 14:29:59] DTMF[6976] channel.c: DTMF end accepted without begin '0' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:29:59] DTMF[6976] channel.c: DTMF end passthrough '0' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:29:59] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:29:59] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:30:00] DEBUG[720] devicestate.c: Changing state for SIP/phono4-ext.voxeolabs.net - state 4 (Invalid) [Sep 11 14:30:00] DEBUG[720] devicestate.c: device 'SIP/phono4-ext.voxeolabs.net' state '4' [Sep 11 14:30:00] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 0000000b (len = 4) [Sep 11 14:30:00] DEBUG[6976] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 35 (#), at 107.21.15.145:20714 [Sep 11 14:30:00] DTMF[6976] channel.c: DTMF begin '#' received on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:00] DTMF[6976] channel.c: DTMF begin ignored '#' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:00] DEBUG[6976] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:30:00] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 0000000b (len = 4) [Sep 11 14:30:00] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 0000000b (len = 4) [Sep 11 14:30:00] DEBUG[6976] res_rtp_asterisk.c: Creating END DTMF Frame: 35 (#), at 107.21.15.145:20714 [Sep 11 14:30:00] DTMF[6976] channel.c: DTMF end '#' received on SIP/phono4-ext.voxeolabs.net-000000b2, duration 0 ms [Sep 11 14:30:00] DTMF[6976] channel.c: DTMF end accepted without begin '#' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:00] DTMF[6976] channel.c: DTMF end passthrough '#' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:00] DEBUG[6976] channel.c: Set channel SIP/phono4-ext.voxeolabs.net-000000b2 to write format gsm [Sep 11 14:30:00] DEBUG[6976] res_rtp_asterisk.c: Difference is 11208, ms is 1421 [Sep 11 14:30:00] DEBUG[6976] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Sep 11 14:30:00] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 0000000b (len = 4) [Sep 11 14:30:00] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 0000000b (len = 4) [Sep 11 14:30:00] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:00] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:00] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000006 (len = 4) [Sep 11 14:30:00] DEBUG[6976] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 54 (6), at 107.21.15.145:20714 [Sep 11 14:30:00] DTMF[6976] channel.c: DTMF begin '6' received on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:00] DTMF[6976] channel.c: DTMF begin ignored '6' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:00] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000006 (len = 4) [Sep 11 14:30:00] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000006 (len = 4) [Sep 11 14:30:00] DEBUG[6976] res_rtp_asterisk.c: Creating END DTMF Frame: 54 (6), at 107.21.15.145:20714 [Sep 11 14:30:00] DTMF[6976] channel.c: DTMF end '6' received on SIP/phono4-ext.voxeolabs.net-000000b2, duration 0 ms [Sep 11 14:30:00] DTMF[6976] channel.c: DTMF end accepted without begin '6' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:00] DTMF[6976] channel.c: DTMF end passthrough '6' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:00] DEBUG[6976] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:00] DEBUG[6976] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:00] DEBUG[6976] channel.c: Set channel SIP/phono4-ext.voxeolabs.net-000000b2 to write format ulaw [Sep 11 14:30:00] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000006 (len = 4) [Sep 11 14:30:00] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000006 (len = 4) [Sep 11 14:30:00] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:01] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:30:01] DEBUG[6976] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 48 (0), at 107.21.15.145:20714 [Sep 11 14:30:01] DTMF[6976] channel.c: DTMF begin '0' received on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:01] DTMF[6976] channel.c: DTMF begin ignored '0' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:01] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:30:01] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:30:01] DEBUG[6976] res_rtp_asterisk.c: Creating END DTMF Frame: 48 (0), at 107.21.15.145:20714 [Sep 11 14:30:01] DTMF[6976] channel.c: DTMF end '0' received on SIP/phono4-ext.voxeolabs.net-000000b2, duration 0 ms [Sep 11 14:30:01] DTMF[6976] channel.c: DTMF end accepted without begin '0' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:01] DTMF[6976] channel.c: DTMF end passthrough '0' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:01] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:30:01] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:30:01] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:01] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000005 (len = 4) [Sep 11 14:30:01] DEBUG[6976] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 53 (5), at 107.21.15.145:20714 [Sep 11 14:30:01] DTMF[6976] channel.c: DTMF begin '5' received on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:01] DTMF[6976] channel.c: DTMF begin ignored '5' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:01] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000005 (len = 4) [Sep 11 14:30:01] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000005 (len = 4) [Sep 11 14:30:01] DEBUG[6976] res_rtp_asterisk.c: Creating END DTMF Frame: 53 (5), at 107.21.15.145:20714 [Sep 11 14:30:01] DTMF[6976] channel.c: DTMF end '5' received on SIP/phono4-ext.voxeolabs.net-000000b2, duration 0 ms [Sep 11 14:30:01] DTMF[6976] channel.c: DTMF end accepted without begin '5' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:01] DTMF[6976] channel.c: DTMF end passthrough '5' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:01] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000005 (len = 4) [Sep 11 14:30:01] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000005 (len = 4) [Sep 11 14:30:01] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Sep 11 14:30:01] DEBUG[6976] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 51 (3), at 107.21.15.145:20714 [Sep 11 14:30:01] DTMF[6976] channel.c: DTMF begin '3' received on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:01] DTMF[6976] channel.c: DTMF begin ignored '3' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:01] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Sep 11 14:30:01] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Sep 11 14:30:01] DEBUG[6976] res_rtp_asterisk.c: Creating END DTMF Frame: 51 (3), at 107.21.15.145:20714 [Sep 11 14:30:01] DTMF[6976] channel.c: DTMF end '3' received on SIP/phono4-ext.voxeolabs.net-000000b2, duration 0 ms [Sep 11 14:30:01] DTMF[6976] channel.c: DTMF end accepted without begin '3' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:01] DTMF[6976] channel.c: DTMF end passthrough '3' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:01] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Sep 11 14:30:01] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Sep 11 14:30:01] DEBUG[757] app_queue.c: Device 'SIP/phono4-ext.voxeolabs.net' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Sep 11 14:30:01] DEBUG[763] manager.c: Examining event: Event: Newchannel Privilege: call,all Channel: SIP/phono4-ext.voxeolabs.net-000000b2 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: a9bce45d-60a6-450e-865f-791103280c03 CallerIDName: AccountCode: Exten: 500 Context: default Uniqueid: 1347391798.309 [Sep 11 14:30:01] DEBUG[763] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: SIP/phono4-ext.voxeolabs.net-000000b2 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: a9bce45d-60a6-450e-865f-791103280c03 CallerIDName: ConnectedLineNum: ConnectedLineName: Uniqueid: 1347391798.309 [Sep 11 14:30:01] DEBUG[763] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: SIP/phono4-ext.voxeolabs.net-000000b2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: a9bce45d-60a6-450e-865f-791103280c03 CallerIDName: ConnectedLineNum: ConnectedLineName: Uniqueid: 1347391798.309 [Sep 11 14:30:01] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:01] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:01] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:02] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 0000000b (len = 4) [Sep 11 14:30:02] DEBUG[6976] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 35 (#), at 107.21.15.145:20714 [Sep 11 14:30:02] DTMF[6976] channel.c: DTMF begin '#' received on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:02] DTMF[6976] channel.c: DTMF begin ignored '#' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:02] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 0000000b (len = 4) [Sep 11 14:30:02] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 0000000b (len = 4) [Sep 11 14:30:02] DEBUG[6976] res_rtp_asterisk.c: Creating END DTMF Frame: 35 (#), at 107.21.15.145:20714 [Sep 11 14:30:02] DTMF[6976] channel.c: DTMF end '#' received on SIP/phono4-ext.voxeolabs.net-000000b2, duration 0 ms [Sep 11 14:30:02] DTMF[6976] channel.c: DTMF end accepted without begin '#' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:02] DTMF[6976] channel.c: DTMF end passthrough '#' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:02] DEBUG[6976] channel.c: Set channel SIP/phono4-ext.voxeolabs.net-000000b2 to write format gsm [Sep 11 14:30:02] DEBUG[6976] res_rtp_asterisk.c: Difference is 11032, ms is 1399 [Sep 11 14:30:02] DEBUG[6976] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Sep 11 14:30:02] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 0000000b (len = 4) [Sep 11 14:30:02] DEBUG[6976] res_rtp_asterisk.c: - RTP 2833 Event: 0000000b (len = 4) [Sep 11 14:30:02] DEBUG[742] chan_sip.c: Auto destroying SIP dialog '537a377-f007f823-d1f4da7@216.115.69.131' [Sep 11 14:30:02] DEBUG[742] chan_sip.c: Destroying SIP dialog 537a377-f007f823-d1f4da7@216.115.69.131 [Sep 11 14:30:02] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:02] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:02] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:03] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:03] DEBUG[6976] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:30:03] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:03] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:03] DEBUG[6976] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:03] DEBUG[6976] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:03] DEBUG[6976] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:03] DEBUG[6976] channel.c: Set channel SIP/phono4-ext.voxeolabs.net-000000b2 to write format ulaw [Sep 11 14:30:03] DEBUG[6976] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:03] DEBUG[6976] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Sep 11 14:30:03] DEBUG[758] manager.c: Examining event: Event: MusicOnHold Privilege: call,all State: Start Channel: SIP/phono4-ext.voxeolabs.net-000000b2 UniqueID: 1347391798.309 Class: default [Sep 11 14:30:03] DEBUG[758] manager.c: Examining event: Event: Agentlogin Privilege: agent,all Agent: 0000 Channel: SIP/phono4-ext.voxeolabs.net-000000b2 Uniqueid: 1347391798.309 [Sep 11 14:30:03] DEBUG[6976] chan_agent.c: Checking availability of '0000' [Sep 11 14:30:03] DEBUG[6976] devicestate.c: device 'Agent/0000' state '1' [Sep 11 14:30:03] DEBUG[6976] chan_agent.c: Wrapup time for 0000 expired! [Sep 11 14:30:03] DEBUG[6976] devicestate.c: device 'Agent/0000' state '1' [Sep 11 14:30:03] DEBUG[6976] chan_agent.c: Checking availability of '0000' [Sep 11 14:30:03] DEBUG[6976] res_timing_timerfd.c: Expected to acknowledge 1 ticks but got 9 instead [Sep 11 14:30:03] DEBUG[757] app_queue.c: Device 'Agent/0000' changed to state '1' (Not in use) [Sep 11 14:30:03] DEBUG[758] manager.c: Examining event: Event: QueueMemberStatus Privilege: agent,all Queue: so_crm_5 Location: Agent/0000 MemberName: admin Membership: realtime Penalty: 0 CallsTaken: 4 LastCall: 1347391682 Status: 1 Paused: 0 [Sep 11 14:30:03] DEBUG[758] manager.c: Examining event: Event: QueueMemberStatus Privilege: agent,all Queue: so_crm_5 Location: Agent/0000 MemberName: admin Membership: realtime Penalty: 0 CallsTaken: 4 LastCall: 1347391682 Status: 1 Paused: 0 [Sep 11 14:30:03] DEBUG[757] app_queue.c: Device 'Agent/0000' changed to state '1' (Not in use) [Sep 11 14:30:03] DEBUG[6976] channel.c: Set channel SIP/phono4-ext.voxeolabs.net-000000b2 to write format slin [Sep 11 14:30:03] DEBUG[6976] res_musiconhold.c: SIP/phono4-ext.voxeolabs.net-000000b2 Opened file 0 '/var/lib/asterisk/moh/macroform-cold_day' [Sep 11 14:30:03] DEBUG[6976] res_rtp_asterisk.c: Difference is 1504, ms is 208 [Sep 11 14:30:03] DEBUG[6976] channel.c: Generator got voice, switching to phase locked mode [Sep 11 14:30:03] DEBUG[6976] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:04] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:04] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:04] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:05] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:05] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:05] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:05] DEBUG[763] manager.c: Examining event: Event: MusicOnHold Privilege: call,all State: Start Channel: SIP/phono4-ext.voxeolabs.net-000000b2 UniqueID: 1347391798.309 Class: default [Sep 11 14:30:05] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:05] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:05] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:06] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:06] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:06] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:06] DEBUG[6976] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:30:07] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:07] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:07] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:08] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:08] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:08] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:09] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:09] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:09] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:09] DEBUG[742] chan_sip.c: = Looking for Call ID: wrgXWVqrzCHmvkazADeRBqq1woeFZckN (Checking From) --From tag K.qPaFlcYPUaIoFE70xYTZOaCAt4tTw1 --To-tag [Sep 11 14:30:09] DEBUG[742] acl.c: For destination '97.104.212.126', our source address is '50.22.175.70'. [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 50.22.175.70:5060 [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Allocating new SIP dialog for wrgXWVqrzCHmvkazADeRBqq1woeFZckN - INVITE (No RTP) [Sep 11 14:30:09] DEBUG[742] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Sep 11 14:30:09] DEBUG[742] sip/reqresp_parser.c: Begin: parsing SIP "Supported: replaces, 100rel, timer, norefersub" [Sep 11 14:30:09] DEBUG[742] sip/reqresp_parser.c: Found SIP option: -replaces- [Sep 11 14:30:09] DEBUG[742] sip/reqresp_parser.c: Matched SIP option: replaces [Sep 11 14:30:09] DEBUG[742] sip/reqresp_parser.c: Found SIP option: -100rel- [Sep 11 14:30:09] DEBUG[742] sip/reqresp_parser.c: Matched SIP option: 100rel [Sep 11 14:30:09] DEBUG[742] sip/reqresp_parser.c: Found SIP option: -timer- [Sep 11 14:30:09] DEBUG[742] sip/reqresp_parser.c: Matched SIP option: timer [Sep 11 14:30:09] DEBUG[742] sip/reqresp_parser.c: Found SIP option: -norefersub- [Sep 11 14:30:09] DEBUG[742] sip/reqresp_parser.c: Matched SIP option: norefersub [Sep 11 14:30:09] DEBUG[742] netsock2.c: Splitting '10.0.1.15:62168' into... [Sep 11 14:30:09] DEBUG[742] netsock2.c: ...host '10.0.1.15' and port '62168'. [Sep 11 14:30:09] DEBUG[742] netsock2.c: Splitting '50.22.175.70' into... [Sep 11 14:30:09] DEBUG[742] netsock2.c: ...host '50.22.175.70' and port ''. [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 97.104.212.126:34077 [Sep 11 14:30:09] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:09] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:09] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:09] DEBUG[742] chan_sip.c: = Looking for Call ID: wrgXWVqrzCHmvkazADeRBqq1woeFZckN (Checking From) --From tag K.qPaFlcYPUaIoFE70xYTZOaCAt4tTw1 --To-tag as570c54d7 [Sep 11 14:30:09] DEBUG[742] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Stopping retransmission on 'wrgXWVqrzCHmvkazADeRBqq1woeFZckN' of Response 25924: Match Found [Sep 11 14:30:09] DEBUG[742] chan_sip.c: = Looking for Call ID: wrgXWVqrzCHmvkazADeRBqq1woeFZckN (Checking From) --From tag K.qPaFlcYPUaIoFE70xYTZOaCAt4tTw1 --To-tag [Sep 11 14:30:09] DEBUG[742] netsock2.c: Splitting '50.22.175.70' into... [Sep 11 14:30:09] DEBUG[742] netsock2.c: ...host '50.22.175.70' and port ''. [Sep 11 14:30:09] DEBUG[742] netsock2.c: Splitting '50.22.175.70' into... [Sep 11 14:30:09] DEBUG[742] netsock2.c: ...host '50.22.175.70' and port ''. [Sep 11 14:30:09] DEBUG[742] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Sep 11 14:30:09] DEBUG[742] netsock2.c: Splitting '10.0.1.15:62168' into... [Sep 11 14:30:09] DEBUG[742] netsock2.c: ...host '10.0.1.15' and port '62168'. [Sep 11 14:30:09] DEBUG[742] netsock2.c: Splitting '50.22.175.70' into... [Sep 11 14:30:09] DEBUG[742] netsock2.c: ...host '50.22.175.70' and port ''. [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f83e0043c48' [Sep 11 14:30:09] DEBUG[742] res_rtp_asterisk.c: Allocated port 18698 for RTP instance '0x7f83e0043c48' [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: RTP instance '0x7f83e0043c48' is setup and ready to go [Sep 11 14:30:09] DEBUG[742] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f83e0043c48' [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Setting NAT on RTP to Off [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Processing session-level SDP o=- 3556380609 3556380609 IN IP4 10.0.1.15... UNSUPPORTED OR FAILED. [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Processing session-level SDP s=pjmedia... UNSUPPORTED OR FAILED. [Sep 11 14:30:09] DEBUG[742] netsock2.c: Splitting '10.0.1.15' into... [Sep 11 14:30:09] DEBUG[742] netsock2.c: ...host '10.0.1.15' and port ''. [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Processing session-level SDP c=IN IP4 10.0.1.15... OK. [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Processing session-level SDP a=X-nat:0... UNSUPPORTED OR FAILED. [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Setting payload 103 based on m type on 0x7f83e657b060 [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Setting payload 102 based on m type on 0x7f83e657b060 [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Setting payload 104 based on m type on 0x7f83e657b060 [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Setting payload 3 based on m type on 0x7f83e657b060 [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Setting payload 0 based on m type on 0x7f83e657b060 [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Setting payload 8 based on m type on 0x7f83e657b060 [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Setting payload 9 based on m type on 0x7f83e657b060 [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Setting payload 101 based on m type on 0x7f83e657b060 [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Processing media-level (audio) SDP a=rtcp:4009 IN IP4 10.0.1.15... UNSUPPORTED OR FAILED. [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:103 speex/16000... OK. [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:102 speex/8000... OK. [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Unsetting payload 104 on 0x7f83e657b060 [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:104 speex/32000... UNSUPPORTED OR FAILED. [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:109 iLBC/8000... OK. [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Processing media-level (audio) SDP a=fmtp:109 mode=30... UNSUPPORTED OR FAILED. [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:3 GSM/8000... OK. [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED. [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Incorporating payload 0 on 0x7f83e657b060 [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Incorporating payload 3 on 0x7f83e657b060 [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Incorporating payload 8 on 0x7f83e657b060 [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Incorporating payload 9 on 0x7f83e657b060 [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Incorporating payload 101 on 0x7f83e657b060 [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Incorporating payload 102 on 0x7f83e657b060 [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Incorporating payload 103 on 0x7f83e657b060 [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Incorporating payload 109 on 0x7f83e657b060 [Sep 11 14:30:09] DEBUG[742] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f83e0043c48' [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Copying payload 0 from 0x7f83e657b060 to 0x7f83e0043e10 [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Copying payload 3 from 0x7f83e657b060 to 0x7f83e0043e10 [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Copying payload 8 from 0x7f83e657b060 to 0x7f83e0043e10 [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Copying payload 9 from 0x7f83e657b060 to 0x7f83e0043e10 [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Copying payload 101 from 0x7f83e657b060 to 0x7f83e0043e10 [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Copying payload 102 from 0x7f83e657b060 to 0x7f83e0043e10 [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Copying payload 103 from 0x7f83e657b060 to 0x7f83e0043e10 [Sep 11 14:30:09] DEBUG[742] rtp_engine.c: Copying payload 109 from 0x7f83e657b060 to 0x7f83e0043e10 [Sep 11 14:30:09] DEBUG[742] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7f83e0043c48' [Sep 11 14:30:09] DEBUG[742] chan_sip.c: We're settling with these formats: 0x4 (ulaw) [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Checking SIP call limits for device matt [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Updating call counter for incoming call [Sep 11 14:30:09] DEBUG[742] netsock2.c: Splitting '50.22.175.70' into... [Sep 11 14:30:09] DEBUG[742] netsock2.c: ...host '50.22.175.70' and port ''. [Sep 11 14:30:09] DEBUG[742] netsock2.c: Splitting '50.22.175.70' into... [Sep 11 14:30:09] DEBUG[742] netsock2.c: ...host '50.22.175.70' and port ''. [Sep 11 14:30:09] DEBUG[742] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Sep 11 14:30:09] DEBUG[742] chan_sip.c: *** Joint capabilities are 0x4 (ulaw) [Sep 11 14:30:09] DEBUG[742] chan_sip.c: *** Our capabilities are 0x4 (ulaw) [Sep 11 14:30:09] DEBUG[758] manager.c: Examining event: Event: Newchannel Privilege: call,all Channel: SIP/matt-000000b3 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: matt CallerIDName: Matt AccountCode: Exten: 123 Context: internal Uniqueid: 1347391809.310 [Sep 11 14:30:09] DEBUG[742] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Sep 11 14:30:09] DEBUG[742] chan_sip.c: This channel will not be able to handle video. [Sep 11 14:30:09] DEBUG[742] chan_sip.c: build_route: Contact hop: "Matt" [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Incoming INVITE with 'timer' option supported and "Session-Expires" header. [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Session-Expires: 1800 [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Received Min-SE: 90 [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Session timer started: 1998 - wrgXWVqrzCHmvkazADeRBqq1woeFZckN [Sep 11 14:30:09] DEBUG[742] chan_sip.c: SIP/matt-000000b3: New call is still down.... Trying... [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 97.104.212.126:34077 [Sep 11 14:30:09] DEBUG[720] devicestate.c: No provider found, checking channel drivers for SIP - matt [Sep 11 14:30:09] DEBUG[720] chan_sip.c: Checking device state for peer matt [Sep 11 14:30:09] DEBUG[720] devicestate.c: Changing state for SIP/matt - state 1 (Not in use) [Sep 11 14:30:09] DEBUG[720] devicestate.c: device 'SIP/matt' state '1' [Sep 11 14:30:09] DEBUG[758] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: SIP/matt-000000b3 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: matt CallerIDName: Matt ConnectedLineNum: ConnectedLineName: Uniqueid: 1347391809.310 [Sep 11 14:30:09] DEBUG[757] app_queue.c: Device 'SIP/matt' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 11 14:30:09] DEBUG[6996] pbx.c: Launching 'Answer' [Sep 11 14:30:09] DEBUG[720] devicestate.c: No provider found, checking channel drivers for SIP - matt [Sep 11 14:30:09] DEBUG[6996] chan_sip.c: SIP answering channel: SIP/matt-000000b3 [Sep 11 14:30:09] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:09] DEBUG[720] chan_sip.c: Checking device state for peer matt [Sep 11 14:30:09] DEBUG[758] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: SIP/matt-000000b3 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: matt CallerIDName: Matt ConnectedLineNum: ConnectedLineName: Uniqueid: 1347391809.310 [Sep 11 14:30:09] DEBUG[720] devicestate.c: Changing state for SIP/matt - state 1 (Not in use) [Sep 11 14:30:09] DEBUG[720] devicestate.c: device 'SIP/matt' state '1' [Sep 11 14:30:09] DEBUG[6996] chan_sip.c: Setting framing from config on incoming call [Sep 11 14:30:09] DEBUG[757] app_queue.c: Device 'SIP/matt' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 11 14:30:09] DEBUG[6996] chan_sip.c: ** Our capability: 0x4 (ulaw) Video flag: True Text flag: True [Sep 11 14:30:09] DEBUG[6996] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Sep 11 14:30:09] DEBUG[6996] chan_sip.c: -- Done with adding codecs to SDP [Sep 11 14:30:09] DEBUG[6996] chan_sip.c: Done building SDP. Settling with this capability: 0x4 (ulaw) [Sep 11 14:30:09] DEBUG[6996] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 97.104.212.126:34077 [Sep 11 14:30:09] DEBUG[6996] res_rtp_asterisk.c: Got RTCP report of 32 bytes [Sep 11 14:30:09] DEBUG[742] chan_sip.c: = Looking for Call ID: wrgXWVqrzCHmvkazADeRBqq1woeFZckN (Checking From) --From tag K.qPaFlcYPUaIoFE70xYTZOaCAt4tTw1 --To-tag as4e28c0d0 [Sep 11 14:30:09] DEBUG[742] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Sep 11 14:30:09] DEBUG[742] chan_sip.c: Stopping retransmission on 'wrgXWVqrzCHmvkazADeRBqq1woeFZckN' of Response 25925: Match Found [Sep 11 14:30:09] DEBUG[6996] pbx.c: Launching 'Set' [Sep 11 14:30:09] DEBUG[6996] pbx.c: Launching 'Queue' [Sep 11 14:30:09] DEBUG[6996] app_queue.c: NO QUEUE_PRIO variable found. Using default. [Sep 11 14:30:09] DEBUG[6996] app_queue.c: queue: so_crm_5, options: tTH, url: (null), announce: (null), expires: 0, priority: 0 [Sep 11 14:30:10] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:10] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:10] DEBUG[6996] app_queue.c: Queue 'so_crm_5' Join, Channel 'SIP/matt-000000b3', Position '1' [Sep 11 14:30:10] DEBUG[758] manager.c: Examining event: Event: Join Privilege: call,all Channel: SIP/matt-000000b3 CallerIDNum: matt CallerIDName: Matt ConnectedLineNum: unknown ConnectedLineName: unknown Queue: so_crm_5 Position: 1 Count: 1 Uniqueid: 1347391809.310 [Sep 11 14:30:10] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:10] DEBUG[6996] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Sep 11 14:30:10] DEBUG[758] manager.c: Examining event: Event: MusicOnHold Privilege: call,all State: Start Channel: SIP/matt-000000b3 UniqueID: 1347391809.310 Class: default [Sep 11 14:30:10] DEBUG[6996] app_queue.c: There is 1 available member. [Sep 11 14:30:10] DEBUG[6996] app_queue.c: It's our turn (SIP/matt-000000b3). [Sep 11 14:30:10] DEBUG[6996] app_queue.c: SIP/matt-000000b3 is trying to call a queue member. [Sep 11 14:30:10] DEBUG[6996] app_queue.c: (Parallel) Trying 'Agent/0000' with metric 0 [Sep 11 14:30:10] DEBUG[758] manager.c: Examining event: Event: Newchannel Privilege: call,all Channel: Agent/0000 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: CallerIDName: AccountCode: Exten: 500 Context: default Uniqueid: 1347391810.311 [Sep 11 14:30:10] DEBUG[6976] chan_agent.c: agent_cont_sleep() returning 0 [Sep 11 14:30:10] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:10] DEBUG[6996] channel.c: Set channel SIP/phono4-ext.voxeolabs.net-000000b2 to write format ulaw [Sep 11 14:30:10] DEBUG[6996] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:10] DEBUG[758] manager.c: Examining event: Event: MusicOnHold Privilege: call,all State: Stop Channel: SIP/phono4-ext.voxeolabs.net-000000b2 UniqueID: 1347391798.309 [Sep 11 14:30:10] DEBUG[758] manager.c: Examining event: Event: NewCallerid Privilege: call,all Channel: Agent/0000 CallerIDNum: 123 CallerIDName: Uniqueid: 1347391810.311 CID-CallingPres: 0 (Presentation Allowed, Not Screened) [Sep 11 14:30:10] DEBUG[6996] channel.c: Not copying variable TRANSFER_CONTEXT. [Sep 11 14:30:10] DEBUG[6996] channel.c: Not copying variable SIPCALLID. [Sep 11 14:30:10] DEBUG[6996] channel.c: Not copying variable SIPDOMAIN. [Sep 11 14:30:10] DEBUG[6996] channel.c: Not copying variable SIPURI. [Sep 11 14:30:10] DEBUG[6996] chan_agent.c: Playing beep, lang 'en' [Sep 11 14:30:10] DEBUG[758] manager.c: Examining event: Event: QueueMemberStatus Privilege: agent,all Queue: so_crm_5 Location: Agent/0000 MemberName: admin Membership: realtime Penalty: 0 CallsTaken: 4 LastCall: 1347391682 Status: 1 Paused: 0 [Sep 11 14:30:10] DEBUG[6996] channel.c: Set channel SIP/phono4-ext.voxeolabs.net-000000b2 to write format gsm [Sep 11 14:30:10] DEBUG[6996] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Sep 11 14:30:10] DEBUG[6996] chan_agent.c: Played beep, result '0' [Sep 11 14:30:11] DEBUG[6996] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:11] DEBUG[6996] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:11] DEBUG[6996] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:11] DEBUG[6996] channel.c: Set channel SIP/phono4-ext.voxeolabs.net-000000b2 to write format ulaw [Sep 11 14:30:11] DEBUG[6996] chan_agent.c: Waited for stream, result '0' [Sep 11 14:30:11] DEBUG[6996] chan_agent.c: Set read format, result '0' [Sep 11 14:30:11] DEBUG[6996] chan_agent.c: Set write format, result '0' [Sep 11 14:30:11] DEBUG[758] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: Agent/0000 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 123 CallerIDName: ConnectedLineNum: matt ConnectedLineName: Matt Uniqueid: 1347391810.311 [Sep 11 14:30:11] DEBUG[720] devicestate.c: No provider found, checking channel drivers for Agent - 0000 [Sep 11 14:30:11] DEBUG[758] manager.c: Examining event: Event: QueueMemberStatus Privilege: agent,all Queue: so_crm_5 Location: Agent/0000 MemberName: admin Membership: realtime Penalty: 0 CallsTaken: 4 LastCall: 1347391682 Status: 1 Paused: 0 [Sep 11 14:30:11] DEBUG[6996] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:11] DEBUG[720] devicestate.c: Changing state for Agent/0000 - state 3 (Busy) [Sep 11 14:30:11] DEBUG[720] devicestate.c: device 'Agent/0000' state '3' [Sep 11 14:30:11] DEBUG[6996] channel.c: Set channel Agent/0000 to write format ulaw [Sep 11 14:30:11] DEBUG[758] manager.c: Examining event: Event: MusicOnHold Privilege: call,all State: Stop Channel: SIP/matt-000000b3 UniqueID: 1347391809.310 [Sep 11 14:30:11] DEBUG[758] manager.c: Examining event: Event: Leave Privilege: call,all Channel: SIP/matt-000000b3 Queue: so_crm_5 Count: 0 Position: 1 Uniqueid: 1347391809.310 [Sep 11 14:30:11] DEBUG[6996] app_queue.c: Queue 'so_crm_5' Leave, Channel 'SIP/matt-000000b3' [Sep 11 14:30:11] DEBUG[757] app_queue.c: Device 'Agent/0000' changed to state '3' (Busy) [Sep 11 14:30:11] DEBUG[758] manager.c: Examining event: Event: QueueMemberStatus Privilege: agent,all Queue: so_crm_5 Location: Agent/0000 MemberName: admin Membership: realtime Penalty: 0 CallsTaken: 4 LastCall: 1347391682 Status: 3 Paused: 0 [Sep 11 14:30:11] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:11] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:11] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:11] DEBUG[6996] features.c: bridge answer set, chan answer set [Sep 11 14:30:11] DEBUG[6996] features.c: Removing dialed interfaces datastore on Agent/0000 since we're bridging [Sep 11 14:30:11] DEBUG[758] manager.c: Examining event: Event: NewAccountCode Privilege: call,all Channel: Agent/0000 Uniqueid: 1347391810.311 AccountCode: OldAccountCode: [Sep 11 14:30:11] DEBUG[758] manager.c: Examining event: Event: Bridge Privilege: call,all Bridgestate: Link Bridgetype: core Channel1: SIP/matt-000000b3 Channel2: Agent/0000 Uniqueid1: 1347391809.310 Uniqueid2: 1347391810.311 CallerID1: matt CallerID2: 123 [Sep 11 14:30:11] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:11] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:11] DEBUG[6996] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:30:11] DEBUG[6996] chan_agent.c: Bridge on 'SIP/phono4-ext.voxeolabs.net-000000b2' being set to 'Agent/0000' (3) [Sep 11 14:30:11] DEBUG[6996] res_rtp_asterisk.c: Ooh, format changed from unknown to ulaw [Sep 11 14:30:11] DEBUG[6996] res_rtp_asterisk.c: Created smoother: format: ulaw ms: 20 len: 160 [Sep 11 14:30:12] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:12] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:12] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/matt-000000b3'/'Agent/0000', returning 'SIP/phono4-ext.voxeolabs.net-000000b2' [Sep 11 14:30:12] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning 'SIP/matt-000000b3' [Sep 11 14:30:13] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:13] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:13] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:13] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/matt-000000b3'/'Agent/0000', returning 'SIP/phono4-ext.voxeolabs.net-000000b2' [Sep 11 14:30:13] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning 'SIP/matt-000000b3' [Sep 11 14:30:13] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:14] DEBUG[763] manager.c: Examining event: Event: Newchannel Privilege: call,all Channel: SIP/matt-000000b3 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: matt CallerIDName: Matt AccountCode: Exten: 123 Context: internal Uniqueid: 1347391809.310 [Sep 11 14:30:14] DEBUG[763] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: SIP/matt-000000b3 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: matt CallerIDName: Matt ConnectedLineNum: ConnectedLineName: Uniqueid: 1347391809.310 [Sep 11 14:30:14] DEBUG[763] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: SIP/matt-000000b3 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: matt CallerIDName: Matt ConnectedLineNum: ConnectedLineName: Uniqueid: 1347391809.310 [Sep 11 14:30:14] DEBUG[763] manager.c: Examining event: Event: Join Privilege: call,all Channel: SIP/matt-000000b3 CallerIDNum: matt CallerIDName: Matt ConnectedLineNum: unknown ConnectedLineName: unknown Queue: so_crm_5 Position: 1 Count: 1 Uniqueid: 1347391809.310 [Sep 11 14:30:14] DEBUG[763] manager.c: Examining event: Event: MusicOnHold Privilege: call,all State: Start Channel: SIP/matt-000000b3 UniqueID: 1347391809.310 Class: default [Sep 11 14:30:14] DEBUG[763] manager.c: Examining event: Event: Newchannel Privilege: call,all Channel: Agent/0000 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: CallerIDName: AccountCode: Exten: 500 Context: default Uniqueid: 1347391810.311 [Sep 11 14:30:14] DEBUG[763] manager.c: Examining event: Event: MusicOnHold Privilege: call,all State: Stop Channel: SIP/phono4-ext.voxeolabs.net-000000b2 UniqueID: 1347391798.309 [Sep 11 14:30:14] DEBUG[763] manager.c: Examining event: Event: NewCallerid Privilege: call,all Channel: Agent/0000 CallerIDNum: 123 CallerIDName: Uniqueid: 1347391810.311 CID-CallingPres: 0 (Presentation Allowed, Not Screened) [Sep 11 14:30:14] DEBUG[763] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: Agent/0000 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 123 CallerIDName: ConnectedLineNum: matt ConnectedLineName: Matt Uniqueid: 1347391810.311 [Sep 11 14:30:14] DEBUG[763] manager.c: Examining event: Event: MusicOnHold Privilege: call,all State: Stop Channel: SIP/matt-000000b3 UniqueID: 1347391809.310 [Sep 11 14:30:14] DEBUG[763] manager.c: Examining event: Event: Leave Privilege: call,all Channel: SIP/matt-000000b3 Queue: so_crm_5 Count: 0 Position: 1 Uniqueid: 1347391809.310 [Sep 11 14:30:14] DEBUG[763] manager.c: Examining event: Event: NewAccountCode Privilege: call,all Channel: Agent/0000 Uniqueid: 1347391810.311 AccountCode: OldAccountCode: [Sep 11 14:30:14] DEBUG[763] manager.c: Examining event: Event: Bridge Privilege: call,all Bridgestate: Link Bridgetype: core Channel1: SIP/matt-000000b3 Channel2: Agent/0000 Uniqueid1: 1347391809.310 Uniqueid2: 1347391810.311 CallerID1: matt CallerID2: 123 [Sep 11 14:30:14] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:14] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:14] DEBUG[763] chan_agent.c: Asked for bridged channel on 'SIP/matt-000000b3'/'Agent/0000', returning 'SIP/phono4-ext.voxeolabs.net-000000b2' [Sep 11 14:30:14] DEBUG[763] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning 'SIP/matt-000000b3' [Sep 11 14:30:14] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:14] DEBUG[6996] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:30:14] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:14] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:14] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/matt-000000b3'/'Agent/0000', returning 'SIP/phono4-ext.voxeolabs.net-000000b2' [Sep 11 14:30:14] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning 'SIP/matt-000000b3' [Sep 11 14:30:14] DEBUG[6996] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:30:14] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:15] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:15] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:15] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/matt-000000b3'/'Agent/0000', returning 'SIP/phono4-ext.voxeolabs.net-000000b2' [Sep 11 14:30:15] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning 'SIP/matt-000000b3' [Sep 11 14:30:15] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:16] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:16] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:16] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/matt-000000b3'/'Agent/0000', returning 'SIP/phono4-ext.voxeolabs.net-000000b2' [Sep 11 14:30:16] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning 'SIP/matt-000000b3' [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 0000000b (len = 4) [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 35 (#), at 107.21.15.145:20714 [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF begin '#' received on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF begin passthrough '#' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF begin '#' received on Agent/0000 [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF begin passthrough '#' on Agent/0000 [Sep 11 14:30:17] DEBUG[6996] channel.c: Got DTMF begin on channel (Agent/0000) [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:17] DEBUG[6996] channel.c: Bridge stops bridging channels SIP/matt-000000b3 and Agent/0000 [Sep 11 14:30:17] DEBUG[6996] features.c: Not passing DTMF through, since it may be a feature code [Sep 11 14:30:17] DEBUG[758] manager.c: Examining event: Event: Unlink Privilege: call,all Channel1: SIP/matt-000000b3 Channel2: Agent/0000 Uniqueid1: 1347391809.310 Uniqueid2: 1347391810.311 CallerID1: matt CallerID2: 123 [Sep 11 14:30:17] DEBUG[758] manager.c: Examining event: Event: Bridge Privilege: call,all Bridgestate: Link Bridgetype: core Channel1: SIP/matt-000000b3 Channel2: Agent/0000 Uniqueid1: 1347391809.310 Uniqueid2: 1347391810.311 CallerID1: matt CallerID2: 123 [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 0000000b (len = 4) [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 0000000b (len = 4) [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: Creating END DTMF Frame: 35 (#), at 107.21.15.145:20714 [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF end '#' received on SIP/phono4-ext.voxeolabs.net-000000b2, duration 0 ms [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF end accepted with begin '#' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF end '#' detected to have actual duration 19 on the wire, emulation will be triggered on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF end '#' has duration 19 but want minimum 80, emulating on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 0000000b (len = 4) [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 0000000b (len = 4) [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF end emulation of '#' queued on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF end '#' received on Agent/0000, duration 63 ms [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF end accepted with begin '#' on Agent/0000 [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF end '#' detected to have actual duration 63 on the wire, emulation will be triggered on Agent/0000 [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF end '#' has duration 63 but want minimum 80, emulating on Agent/0000 [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF end emulation of '#' queued on Agent/0000 [Sep 11 14:30:17] DEBUG[6996] channel.c: Got DTMF end on channel (Agent/0000) [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:17] DEBUG[6996] channel.c: Bridge stops bridging channels SIP/matt-000000b3 and Agent/0000 [Sep 11 14:30:17] DEBUG[6996] features.c: Feature interpret: chan=SIP/matt-000000b3, peer=Agent/0000, code=#, sense=2, features=2, dynamic=# [Sep 11 14:30:17] DEBUG[6996] features.c: Set feature timer to 1000 ms [Sep 11 14:30:17] DEBUG[758] manager.c: Examining event: Event: Unlink Privilege: call,all Channel1: SIP/matt-000000b3 Channel2: Agent/0000 Uniqueid1: 1347391809.310 Uniqueid2: 1347391810.311 CallerID1: matt CallerID2: 123 [Sep 11 14:30:17] DEBUG[758] manager.c: Examining event: Event: Bridge Privilege: call,all Bridgestate: Link Bridgetype: core Channel1: SIP/matt-000000b3 Channel2: Agent/0000 Uniqueid1: 1347391809.310 Uniqueid2: 1347391810.311 CallerID1: matt CallerID2: 123 [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:17] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 0000000b (len = 4) [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 35 (#), at 107.21.15.145:20714 [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF begin '#' received on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF begin passthrough '#' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF begin '#' received on Agent/0000 [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF begin passthrough '#' on Agent/0000 [Sep 11 14:30:17] DEBUG[6996] channel.c: Got DTMF begin on channel (Agent/0000) [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:17] DEBUG[6996] channel.c: Bridge stops bridging channels SIP/matt-000000b3 and Agent/0000 [Sep 11 14:30:17] DEBUG[6996] features.c: Not passing DTMF through, since it may be a feature code [Sep 11 14:30:17] DEBUG[758] manager.c: Examining event: Event: Unlink Privilege: call,all Channel1: SIP/matt-000000b3 Channel2: Agent/0000 Uniqueid1: 1347391809.310 Uniqueid2: 1347391810.311 CallerID1: matt CallerID2: 123 [Sep 11 14:30:17] DEBUG[758] manager.c: Examining event: Event: Bridge Privilege: call,all Bridgestate: Link Bridgetype: core Channel1: SIP/matt-000000b3 Channel2: Agent/0000 Uniqueid1: 1347391809.310 Uniqueid2: 1347391810.311 CallerID1: matt CallerID2: 123 [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:17] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 0000000b (len = 4) [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 0000000b (len = 4) [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: Creating END DTMF Frame: 35 (#), at 107.21.15.145:20714 [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF end '#' received on SIP/phono4-ext.voxeolabs.net-000000b2, duration 0 ms [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF end accepted with begin '#' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF end '#' detected to have actual duration 20 on the wire, emulation will be triggered on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF end '#' has duration 20 but want minimum 80, emulating on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 0000000b (len = 4) [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 0000000b (len = 4) [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF end emulation of '#' queued on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF end '#' received on Agent/0000, duration 62 ms [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF end accepted with begin '#' on Agent/0000 [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF end '#' detected to have actual duration 62 on the wire, emulation will be triggered on Agent/0000 [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF end '#' has duration 62 but want minimum 80, emulating on Agent/0000 [Sep 11 14:30:17] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:17] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/matt-000000b3'/'Agent/0000', returning 'SIP/phono4-ext.voxeolabs.net-000000b2' [Sep 11 14:30:17] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning 'SIP/matt-000000b3' [Sep 11 14:30:17] DTMF[6996] channel.c: DTMF end emulation of '#' queued on Agent/0000 [Sep 11 14:30:17] DEBUG[6996] channel.c: Got DTMF end on channel (Agent/0000) [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:17] DEBUG[6996] channel.c: Bridge stops bridging channels SIP/matt-000000b3 and Agent/0000 [Sep 11 14:30:17] DEBUG[6996] features.c: Feature interpret: chan=SIP/matt-000000b3, peer=Agent/0000, code=##, sense=2, features=2, dynamic=# [Sep 11 14:30:17] DEBUG[6996] features.c: Feature detected: fname=Attended Transfer sname=atxfer exten=## [Sep 11 14:30:17] DEBUG[758] manager.c: Examining event: Event: Unlink Privilege: call,all Channel1: SIP/matt-000000b3 Channel2: Agent/0000 Uniqueid1: 1347391809.310 Uniqueid2: 1347391810.311 CallerID1: matt CallerID2: 123 [Sep 11 14:30:17] DEBUG[6996] features.c: Executing Attended Transfer SIP/matt-000000b3, Agent/0000 (sense=2) [Sep 11 14:30:17] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:17] DEBUG[6996] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Sep 11 14:30:17] DEBUG[758] manager.c: Examining event: Event: MusicOnHold Privilege: call,all State: Start Channel: SIP/matt-000000b3 UniqueID: 1347391809.310 Class: default [Sep 11 14:30:17] DEBUG[6996] channel.c: Set channel Agent/0000 to write format gsm [Sep 11 14:30:17] DEBUG[6996] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Sep 11 14:30:17] DEBUG[4528] channel.c: Set channel SIP/matt-000000b3 to write format slin [Sep 11 14:30:17] DEBUG[4528] res_musiconhold.c: SIP/matt-000000b3 Opened file 0 '/var/lib/asterisk/moh/macroform-cold_day' [Sep 11 14:30:17] DEBUG[4528] res_rtp_asterisk.c: Difference is 840, ms is 125 [Sep 11 14:30:17] DEBUG[4528] channel.c: Generator got voice, switching to phase locked mode [Sep 11 14:30:17] DEBUG[4528] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:17] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:18] DEBUG[763] manager.c: Examining event: Event: Unlink Privilege: call,all Channel1: SIP/matt-000000b3 Channel2: Agent/0000 Uniqueid1: 1347391809.310 Uniqueid2: 1347391810.311 CallerID1: matt CallerID2: 123 [Sep 11 14:30:18] DEBUG[763] manager.c: Examining event: Event: Bridge Privilege: call,all Bridgestate: Link Bridgetype: core Channel1: SIP/matt-000000b3 Channel2: Agent/0000 Uniqueid1: 1347391809.310 Uniqueid2: 1347391810.311 CallerID1: matt CallerID2: 123 [Sep 11 14:30:18] DEBUG[763] manager.c: Examining event: Event: Unlink Privilege: call,all Channel1: SIP/matt-000000b3 Channel2: Agent/0000 Uniqueid1: 1347391809.310 Uniqueid2: 1347391810.311 CallerID1: matt CallerID2: 123 [Sep 11 14:30:18] DEBUG[763] manager.c: Examining event: Event: Bridge Privilege: call,all Bridgestate: Link Bridgetype: core Channel1: SIP/matt-000000b3 Channel2: Agent/0000 Uniqueid1: 1347391809.310 Uniqueid2: 1347391810.311 CallerID1: matt CallerID2: 123 [Sep 11 14:30:18] DEBUG[763] manager.c: Examining event: Event: Unlink Privilege: call,all Channel1: SIP/matt-000000b3 Channel2: Agent/0000 Uniqueid1: 1347391809.310 Uniqueid2: 1347391810.311 CallerID1: matt CallerID2: 123 [Sep 11 14:30:18] DEBUG[763] manager.c: Examining event: Event: Bridge Privilege: call,all Bridgestate: Link Bridgetype: core Channel1: SIP/matt-000000b3 Channel2: Agent/0000 Uniqueid1: 1347391809.310 Uniqueid2: 1347391810.311 CallerID1: matt CallerID2: 123 [Sep 11 14:30:18] DEBUG[763] manager.c: Examining event: Event: Unlink Privilege: call,all Channel1: SIP/matt-000000b3 Channel2: Agent/0000 Uniqueid1: 1347391809.310 Uniqueid2: 1347391810.311 CallerID1: matt CallerID2: 123 [Sep 11 14:30:18] DEBUG[763] manager.c: Examining event: Event: MusicOnHold Privilege: call,all State: Start Channel: SIP/matt-000000b3 UniqueID: 1347391809.310 Class: default [Sep 11 14:30:18] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:18] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:18] DEBUG[763] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning '' [Sep 11 14:30:18] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:18] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:18] DEBUG[6996] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:18] DEBUG[6996] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:18] DEBUG[6996] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:18] DEBUG[6996] channel.c: Set channel Agent/0000 to write format ulaw [Sep 11 14:30:18] DEBUG[6996] channel.c: Set channel Agent/0000 to write format slin [Sep 11 14:30:18] DEBUG[6996] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Sep 11 14:30:18] DEBUG[6996] channel.c: Generator got voice, switching to phase locked mode [Sep 11 14:30:18] DEBUG[6996] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:18] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:18] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning '' [Sep 11 14:30:18] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000004 (len = 4) [Sep 11 14:30:18] DEBUG[6996] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 52 (4), at 107.21.15.145:20714 [Sep 11 14:30:18] DTMF[6996] channel.c: DTMF begin '4' received on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:18] DTMF[6996] channel.c: DTMF begin passthrough '4' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:18] DTMF[6996] channel.c: DTMF begin '4' received on Agent/0000 [Sep 11 14:30:18] DTMF[6996] channel.c: DTMF begin ignored '4' on Agent/0000 [Sep 11 14:30:18] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000004 (len = 4) [Sep 11 14:30:18] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000004 (len = 4) [Sep 11 14:30:18] DEBUG[6996] res_rtp_asterisk.c: Creating END DTMF Frame: 52 (4), at 107.21.15.145:20714 [Sep 11 14:30:18] DTMF[6996] channel.c: DTMF end '4' received on SIP/phono4-ext.voxeolabs.net-000000b2, duration 0 ms [Sep 11 14:30:18] DTMF[6996] channel.c: DTMF end accepted with begin '4' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:18] DTMF[6996] channel.c: DTMF end '4' detected to have actual duration 28 on the wire, emulation will be triggered on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:18] DTMF[6996] channel.c: DTMF end '4' has duration 28 but want minimum 80, emulating on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:18] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000004 (len = 4) [Sep 11 14:30:18] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000004 (len = 4) [Sep 11 14:30:18] DTMF[6996] channel.c: DTMF end emulation of '4' queued on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:18] DTMF[6996] channel.c: DTMF end '4' received on Agent/0000, duration 63 ms [Sep 11 14:30:18] DTMF[6996] channel.c: DTMF end passthrough '4' on Agent/0000 [Sep 11 14:30:18] DEBUG[6996] channel.c: Set channel Agent/0000 to write format ulaw [Sep 11 14:30:18] DEBUG[6996] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:18] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:19] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:30:19] DEBUG[6996] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 48 (0), at 107.21.15.145:20714 [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF begin '0' received on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF begin passthrough '0' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF begin '0' received on Agent/0000 [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF begin ignored '0' on Agent/0000 [Sep 11 14:30:19] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:30:19] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:30:19] DEBUG[6996] res_rtp_asterisk.c: Creating END DTMF Frame: 48 (0), at 107.21.15.145:20714 [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF end '0' received on SIP/phono4-ext.voxeolabs.net-000000b2, duration 0 ms [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF end accepted with begin '0' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF end '0' detected to have actual duration 19 on the wire, emulation will be triggered on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF end '0' has duration 19 but want minimum 80, emulating on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:19] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:30:19] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF end emulation of '0' queued on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF end '0' received on Agent/0000, duration 61 ms [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF end passthrough '0' on Agent/0000 [Sep 11 14:30:19] DEBUG[4528] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:30:19] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:19] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000007 (len = 4) [Sep 11 14:30:19] DEBUG[6996] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 55 (7), at 107.21.15.145:20714 [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF begin '7' received on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF begin passthrough '7' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF begin '7' received on Agent/0000 [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF begin ignored '7' on Agent/0000 [Sep 11 14:30:19] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000007 (len = 4) [Sep 11 14:30:19] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000007 (len = 4) [Sep 11 14:30:19] DEBUG[6996] res_rtp_asterisk.c: Creating END DTMF Frame: 55 (7), at 107.21.15.145:20714 [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF end '7' received on SIP/phono4-ext.voxeolabs.net-000000b2, duration 0 ms [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF end accepted with begin '7' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF end '7' detected to have actual duration 21 on the wire, emulation will be triggered on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF end '7' has duration 21 but want minimum 80, emulating on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:19] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000007 (len = 4) [Sep 11 14:30:19] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000007 (len = 4) [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF end emulation of '7' queued on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF end '7' received on Agent/0000, duration 60 ms [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF end passthrough '7' on Agent/0000 [Sep 11 14:30:19] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:19] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning '' [Sep 11 14:30:19] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:19] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000002 (len = 4) [Sep 11 14:30:19] DEBUG[6996] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 50 (2), at 107.21.15.145:20714 [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF begin '2' received on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF begin passthrough '2' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF begin '2' received on Agent/0000 [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF begin ignored '2' on Agent/0000 [Sep 11 14:30:19] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000002 (len = 4) [Sep 11 14:30:19] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000002 (len = 4) [Sep 11 14:30:19] DEBUG[6996] res_rtp_asterisk.c: Creating END DTMF Frame: 50 (2), at 107.21.15.145:20714 [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF end '2' received on SIP/phono4-ext.voxeolabs.net-000000b2, duration 0 ms [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF end accepted with begin '2' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF end '2' detected to have actual duration 27 on the wire, emulation will be triggered on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF end '2' has duration 27 but want minimum 80, emulating on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:19] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000002 (len = 4) [Sep 11 14:30:19] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000002 (len = 4) [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF end emulation of '2' queued on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF end '2' received on Agent/0000, duration 60 ms [Sep 11 14:30:19] DTMF[6996] channel.c: DTMF end passthrough '2' on Agent/0000 [Sep 11 14:30:20] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000006 (len = 4) [Sep 11 14:30:20] DEBUG[6996] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 54 (6), at 107.21.15.145:20714 [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF begin '6' received on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF begin passthrough '6' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF begin '6' received on Agent/0000 [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF begin ignored '6' on Agent/0000 [Sep 11 14:30:20] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000006 (len = 4) [Sep 11 14:30:20] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000006 (len = 4) [Sep 11 14:30:20] DEBUG[6996] res_rtp_asterisk.c: Creating END DTMF Frame: 54 (6), at 107.21.15.145:20714 [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF end '6' received on SIP/phono4-ext.voxeolabs.net-000000b2, duration 0 ms [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF end accepted with begin '6' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF end '6' detected to have actual duration 20 on the wire, emulation will be triggered on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF end '6' has duration 20 but want minimum 80, emulating on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:20] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000006 (len = 4) [Sep 11 14:30:20] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000006 (len = 4) [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF end emulation of '6' queued on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF end '6' received on Agent/0000, duration 60 ms [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF end passthrough '6' on Agent/0000 [Sep 11 14:30:20] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:20] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000007 (len = 4) [Sep 11 14:30:20] DEBUG[6996] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 55 (7), at 107.21.15.145:20714 [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF begin '7' received on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF begin passthrough '7' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF begin '7' received on Agent/0000 [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF begin ignored '7' on Agent/0000 [Sep 11 14:30:20] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000007 (len = 4) [Sep 11 14:30:20] DEBUG[6996] res_rtp_asterisk.c: Creating END DTMF Frame: 55 (7), at 107.21.15.145:20714 [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF end '7' received on SIP/phono4-ext.voxeolabs.net-000000b2, duration 0 ms [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF end accepted with begin '7' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF end '7' detected to have actual duration 22 on the wire, emulation will be triggered on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF end '7' has duration 22 but want minimum 80, emulating on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:20] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000007 (len = 4) [Sep 11 14:30:20] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000007 (len = 4) [Sep 11 14:30:20] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000007 (len = 4) [Sep 11 14:30:20] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:20] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning '' [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF end emulation of '7' queued on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF end '7' received on Agent/0000, duration 64 ms [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF end passthrough '7' on Agent/0000 [Sep 11 14:30:20] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000004 (len = 4) [Sep 11 14:30:20] DEBUG[6996] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 52 (4), at 107.21.15.145:20714 [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF begin '4' received on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF begin passthrough '4' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF begin '4' received on Agent/0000 [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF begin ignored '4' on Agent/0000 [Sep 11 14:30:20] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000004 (len = 4) [Sep 11 14:30:20] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000004 (len = 4) [Sep 11 14:30:20] DEBUG[6996] res_rtp_asterisk.c: Creating END DTMF Frame: 52 (4), at 107.21.15.145:20714 [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF end '4' received on SIP/phono4-ext.voxeolabs.net-000000b2, duration 0 ms [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF end accepted with begin '4' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF end '4' detected to have actual duration 25 on the wire, emulation will be triggered on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF end '4' has duration 25 but want minimum 80, emulating on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:20] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000004 (len = 4) [Sep 11 14:30:20] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000004 (len = 4) [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF end emulation of '4' queued on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF end '4' received on Agent/0000, duration 63 ms [Sep 11 14:30:20] DTMF[6996] channel.c: DTMF end passthrough '4' on Agent/0000 [Sep 11 14:30:21] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000004 (len = 4) [Sep 11 14:30:21] DEBUG[6996] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 52 (4), at 107.21.15.145:20714 [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF begin '4' received on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF begin passthrough '4' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF begin '4' received on Agent/0000 [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF begin ignored '4' on Agent/0000 [Sep 11 14:30:21] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:21] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000004 (len = 4) [Sep 11 14:30:21] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000004 (len = 4) [Sep 11 14:30:21] DEBUG[6996] res_rtp_asterisk.c: Creating END DTMF Frame: 52 (4), at 107.21.15.145:20714 [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF end '4' received on SIP/phono4-ext.voxeolabs.net-000000b2, duration 0 ms [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF end accepted with begin '4' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF end '4' detected to have actual duration 26 on the wire, emulation will be triggered on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF end '4' has duration 26 but want minimum 80, emulating on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:21] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000004 (len = 4) [Sep 11 14:30:21] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000004 (len = 4) [Sep 11 14:30:21] DEBUG[6996] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF end emulation of '4' queued on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF end '4' received on Agent/0000, duration 65 ms [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF end passthrough '4' on Agent/0000 [Sep 11 14:30:21] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:21] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Sep 11 14:30:21] DEBUG[6996] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 51 (3), at 107.21.15.145:20714 [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF begin '3' received on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF begin passthrough '3' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF begin '3' received on Agent/0000 [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF begin ignored '3' on Agent/0000 [Sep 11 14:30:21] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:21] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning '' [Sep 11 14:30:21] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Sep 11 14:30:21] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Sep 11 14:30:21] DEBUG[6996] res_rtp_asterisk.c: Creating END DTMF Frame: 51 (3), at 107.21.15.145:20714 [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF end '3' received on SIP/phono4-ext.voxeolabs.net-000000b2, duration 0 ms [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF end accepted with begin '3' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF end '3' detected to have actual duration 20 on the wire, emulation will be triggered on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF end '3' has duration 20 but want minimum 80, emulating on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:21] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Sep 11 14:30:21] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Sep 11 14:30:21] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF end emulation of '3' queued on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF end '3' received on Agent/0000, duration 63 ms [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF end passthrough '3' on Agent/0000 [Sep 11 14:30:21] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000004 (len = 4) [Sep 11 14:30:21] DEBUG[6996] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 52 (4), at 107.21.15.145:20714 [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF begin '4' received on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF begin passthrough '4' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF begin '4' received on Agent/0000 [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF begin ignored '4' on Agent/0000 [Sep 11 14:30:21] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000004 (len = 4) [Sep 11 14:30:21] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000004 (len = 4) [Sep 11 14:30:21] DEBUG[6996] res_rtp_asterisk.c: Creating END DTMF Frame: 52 (4), at 107.21.15.145:20714 [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF end '4' received on SIP/phono4-ext.voxeolabs.net-000000b2, duration 0 ms [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF end accepted with begin '4' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF end '4' detected to have actual duration 19 on the wire, emulation will be triggered on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF end '4' has duration 19 but want minimum 80, emulating on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:21] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000004 (len = 4) [Sep 11 14:30:21] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 00000004 (len = 4) [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF end emulation of '4' queued on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF end '4' received on Agent/0000, duration 63 ms [Sep 11 14:30:21] DTMF[6996] channel.c: DTMF end passthrough '4' on Agent/0000 [Sep 11 14:30:22] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:22] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:22] DEBUG[763] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning '' [Sep 11 14:30:22] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:22] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:22] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:22] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning '' [Sep 11 14:30:22] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:23] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:23] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:23] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning '' [Sep 11 14:30:23] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:23] DEBUG[4528] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:30:24] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:24] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:24] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning '' [Sep 11 14:30:25] DEBUG[6996] features.c: Checking if 4072674434@outbound_crm is a parking exten [Sep 11 14:30:25] DEBUG[758] manager.c: Examining event: Event: Newchannel Privilege: call,all Channel: Local/4072674434@outbound_crm-8c88;1 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: CallerIDName: AccountCode: Exten: 4072674434 Context: outbound_crm Uniqueid: 1347391825.312 [Sep 11 14:30:25] DEBUG[758] manager.c: Examining event: Event: Newchannel Privilege: call,all Channel: Local/4072674434@outbound_crm-8c88;2 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: CallerIDName: AccountCode: Exten: 4072674434 Context: outbound_crm Uniqueid: 1347391825.313 [Sep 11 14:30:25] DEBUG[6996] channel.c: Not copying variable BRIDGEPVTCALLID. [Sep 11 14:30:25] DEBUG[6996] channel.c: Not copying variable BRIDGEPEER. [Sep 11 14:30:25] DEBUG[7007] pbx.c: Result of 'EXTEN' is '4072674434' [Sep 11 14:30:25] DEBUG[7007] pbx.c: Launching 'Dial' [Sep 11 14:30:25] DEBUG[7007] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw) [Sep 11 14:30:25] DEBUG[7007] chan_sip.c: Allocating new SIP dialog for 19288c640469f799754891fa58dd8e98@72.14.190.50:5060 - INVITE (No RTP) [Sep 11 14:30:25] DEBUG[7007] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x1f0a558' [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: Allocated port 16464 for RTP instance '0x1f0a558' [Sep 11 14:30:25] DEBUG[7007] rtp_engine.c: RTP instance '0x1f0a558' is setup and ready to go [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x1f0a558' [Sep 11 14:30:25] DEBUG[7007] chan_sip.c: Setting NAT on RTP to Off [Sep 11 14:30:25] DEBUG[7007] acl.c: For destination '216.115.69.144', our source address is '50.22.175.70'. [Sep 11 14:30:25] DEBUG[7007] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 50.22.175.70:5060 [Sep 11 14:30:25] DEBUG[7007] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Sep 11 14:30:25] DEBUG[7007] chan_sip.c: *** Joint capabilities are 0x4 (ulaw) [Sep 11 14:30:25] DEBUG[7007] chan_sip.c: *** Our capabilities are 0x80000008010e (gsm|ulaw|alaw|g729|h263|testlaw) [Sep 11 14:30:25] DEBUG[7007] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Sep 11 14:30:25] DEBUG[758] manager.c: Examining event: Event: Newchannel Privilege: call,all Channel: SIP/flowroute-000000b4 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: CallerIDName: AccountCode: Exten: Context: inbound Uniqueid: 1347391825.314 [Sep 11 14:30:25] DEBUG[7007] chan_sip.c: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Sep 11 14:30:25] DEBUG[7007] chan_sip.c: This channel will not be able to handle video. [Sep 11 14:30:25] DEBUG[7007] rtp_engine.c: Can't find native functions for channel 'Local/4072674434@outbound_crm-8c88;2' [Sep 11 14:30:25] DEBUG[7007] rtp_engine.c: Seeded SDP of 'SIP/flowroute-000000b4' with that of 'Local/4072674434@outbound_crm-8c88;2' [Sep 11 14:30:25] DEBUG[7007] channel.c: Not copying variable DIALEDTIME. [Sep 11 14:30:25] DEBUG[7007] channel.c: Not copying variable ANSWEREDTIME. [Sep 11 14:30:25] DEBUG[7007] channel.c: Not copying variable DIALEDPEERNAME. [Sep 11 14:30:25] DEBUG[7007] channel.c: Not copying variable DIALEDPEERNUMBER. [Sep 11 14:30:25] DEBUG[7007] channel.c: Not copying variable DIALSTATUS. [Sep 11 14:30:25] DEBUG[7007] channel.c: Not copying variable TRANSFERERNAME. [Sep 11 14:30:25] DEBUG[7007] chan_sip.c: Outgoing Call for 14072674434 [Sep 11 14:30:25] DEBUG[7007] chan_sip.c: Updating call counter for outgoing call [Sep 11 14:30:25] DEBUG[758] manager.c: Examining event: Event: NewCallerid Privilege: call,all Channel: SIP/flowroute-000000b4 CallerIDNum: 4072674434 CallerIDName: Uniqueid: 1347391825.314 CID-CallingPres: 0 (Presentation Allowed, Not Screened) [Sep 11 14:30:25] DEBUG[7007] chan_sip.c: This call needs video offers, but there's no video support enabled! [Sep 11 14:30:25] DEBUG[7007] chan_sip.c: ** Our capability: 0x80000008000e (gsm|ulaw|alaw|h263|testlaw) Video flag: False Text flag: False [Sep 11 14:30:25] DEBUG[7007] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [Sep 11 14:30:25] DEBUG[7007] chan_sip.c: -- Done with adding codecs to SDP [Sep 11 14:30:25] DEBUG[7007] chan_sip.c: Done building SDP. Settling with this capability: 0x80000008000e (gsm|ulaw|alaw|h263|testlaw) [Sep 11 14:30:25] DEBUG[7007] chan_sip.c: Initializing initreq for method INVITE - callid 44d277ab032e2cbd65a5d3c428c78b10@sip.flowroute.com [Sep 11 14:30:25] DEBUG[7007] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 216.115.69.144:5060 [Sep 11 14:30:25] DEBUG[758] manager.c: Examining event: Event: Dial Privilege: call,all SubEvent: Begin Channel: Local/4072674434@outbound_crm-8c88;2 Destination: SIP/flowroute-000000b4 CallerIDNum: 123 CallerIDName: ConnectedLineNum: ConnectedLineName: UniqueID: 1347391825.313 DestUniqueID: 1347391825.314 Dialstring: 14072674434@flowroute [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[742] chan_sip.c: = Looking for Call ID: 44d277ab032e2cbd65a5d3c428c78b10@sip.flowroute.com (Checking To) --From tag as1519f496 --To-tag [Sep 11 14:30:25] DEBUG[742] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '44d277ab032e2cbd65a5d3c428c78b10@sip.flowroute.com' Request 102: Found [Sep 11 14:30:25] DEBUG[742] chan_sip.c: SIP response 100 to standard invite [Sep 11 14:30:25] DEBUG[742] chan_sip.c: = Looking for Call ID: 44d277ab032e2cbd65a5d3c428c78b10@sip.flowroute.com (Checking To) --From tag as1519f496 --To-tag da160a8e0534d7b0db4afd8620a22cb7.51e7 [Sep 11 14:30:25] DEBUG[742] chan_sip.c: Acked pending invite 102 [Sep 11 14:30:25] DEBUG[742] chan_sip.c: Stopping retransmission on '44d277ab032e2cbd65a5d3c428c78b10@sip.flowroute.com' of Request 102: Match Found [Sep 11 14:30:25] DEBUG[742] chan_sip.c: SIP response 407 to standard invite [Sep 11 14:30:25] DEBUG[742] chan_sip.c: Trying to put 'ACK sip:140' onto UDP socket destined for 216.115.69.144:5060 [Sep 11 14:30:25] DEBUG[742] chan_sip.c: Auth attempt 1 on INVITE [Sep 11 14:30:25] DEBUG[742] chan_sip.c: This call needs video offers, but there's no video support enabled! [Sep 11 14:30:25] DEBUG[742] chan_sip.c: ** Our capability: 0x80000008000e (gsm|ulaw|alaw|h263|testlaw) Video flag: False Text flag: False [Sep 11 14:30:25] DEBUG[742] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [Sep 11 14:30:25] DEBUG[742] chan_sip.c: -- Done with adding codecs to SDP [Sep 11 14:30:25] DEBUG[742] chan_sip.c: Done building SDP. Settling with this capability: 0x80000008000e (gsm|ulaw|alaw|h263|testlaw) [Sep 11 14:30:25] DEBUG[742] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 216.115.69.144:5060 [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[742] chan_sip.c: = Looking for Call ID: 44d277ab032e2cbd65a5d3c428c78b10@sip.flowroute.com (Checking To) --From tag as1519f496 --To-tag [Sep 11 14:30:25] DEBUG[742] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '44d277ab032e2cbd65a5d3c428c78b10@sip.flowroute.com' Request 103: Found [Sep 11 14:30:25] DEBUG[742] chan_sip.c: SIP response 100 to standard invite [Sep 11 14:30:25] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[742] chan_sip.c: = Looking for Call ID: 537a377-1508f823-45f4da7@216.115.69.131 (Checking From) --From tag 96acda78 --To-tag [Sep 11 14:30:25] DEBUG[742] acl.c: For destination '216.115.69.144', our source address is '50.22.175.70'. [Sep 11 14:30:25] DEBUG[742] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 50.22.175.70:5060 [Sep 11 14:30:25] DEBUG[742] chan_sip.c: Allocating new SIP dialog for 537a377-1508f823-45f4da7@216.115.69.131 - OPTIONS (No RTP) [Sep 11 14:30:25] DEBUG[742] chan_sip.c: **** Received OPTIONS (3) - Command in SIP OPTIONS [Sep 11 14:30:25] DEBUG[742] netsock2.c: Splitting '50.22.175.70:5060' into... [Sep 11 14:30:25] DEBUG[742] netsock2.c: ...host '50.22.175.70' and port ''. [Sep 11 14:30:25] DEBUG[742] netsock2.c: Splitting 'invalid' into... [Sep 11 14:30:25] DEBUG[742] netsock2.c: ...host 'invalid' and port ''. [Sep 11 14:30:25] DEBUG[742] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 216.115.69.144:5060 [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:25] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning '' [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:25] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[763] manager.c: Examining event: Event: Newchannel Privilege: call,all Channel: Local/4072674434@outbound_crm-8c88;1 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: CallerIDName: AccountCode: Exten: 4072674434 Context: outbound_crm Uniqueid: 1347391825.312 [Sep 11 14:30:26] DEBUG[763] manager.c: Examining event: Event: Newchannel Privilege: call,all Channel: Local/4072674434@outbound_crm-8c88;2 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: CallerIDName: AccountCode: Exten: 4072674434 Context: outbound_crm Uniqueid: 1347391825.313 [Sep 11 14:30:26] DEBUG[763] manager.c: Examining event: Event: Newchannel Privilege: call,all Channel: SIP/flowroute-000000b4 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: CallerIDName: AccountCode: Exten: Context: inbound Uniqueid: 1347391825.314 [Sep 11 14:30:26] DEBUG[763] manager.c: Examining event: Event: NewCallerid Privilege: call,all Channel: SIP/flowroute-000000b4 CallerIDNum: 4072674434 CallerIDName: Uniqueid: 1347391825.314 CID-CallingPres: 0 (Presentation Allowed, Not Screened) [Sep 11 14:30:26] DEBUG[763] manager.c: Examining event: Event: Dial Privilege: call,all SubEvent: Begin Channel: Local/4072674434@outbound_crm-8c88;2 Destination: SIP/flowroute-000000b4 CallerIDNum: 123 CallerIDName: ConnectedLineNum: ConnectedLineName: UniqueID: 1347391825.313 DestUniqueID: 1347391825.314 Dialstring: 14072674434@flowroute [Sep 11 14:30:26] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:26] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:26] DEBUG[763] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning '' [Sep 11 14:30:26] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:26] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning '' [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[6996] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:26] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[742] chan_sip.c: Auto destroying SIP dialog '16yd69cvh2z90' [Sep 11 14:30:27] DEBUG[742] chan_sip.c: Destroying SIP dialog 16yd69cvh2z90 [Sep 11 14:30:27] DEBUG[742] rtp_engine.c: Destroyed RTP instance '0x7f83e0093978' [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:27] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning '' [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:27] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[6996] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[742] chan_sip.c: Auto destroying SIP dialog '3bed14f2-b870dc38-83eb436@70.167.153.136' [Sep 11 14:30:28] DEBUG[742] chan_sip.c: Destroying SIP dialog 3bed14f2-b870dc38-83eb436@70.167.153.136 [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:28] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning '' [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:28] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[6996] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:29] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning '' [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:29] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:30] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:30] DEBUG[763] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning '' [Sep 11 14:30:30] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:30] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning '' [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:30] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:31] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:31] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:31] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:31] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:31] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:31] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:31] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:31] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:31] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:31] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:31] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:31] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:31] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:31] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:31] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:31] DEBUG[7007] res_rtp_asterisk.c: No remote address on RTP instance '0x1f0a558' so dropping frame [Sep 11 14:30:31] DEBUG[742] chan_sip.c: = Looking for Call ID: 44d277ab032e2cbd65a5d3c428c78b10@sip.flowroute.com (Checking To) --From tag as1519f496 --To-tag 26061 [Sep 11 14:30:31] DEBUG[742] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '44d277ab032e2cbd65a5d3c428c78b10@sip.flowroute.com' Request 103: Found [Sep 11 14:30:31] DEBUG[742] chan_sip.c: SIP response 180 to standard invite [Sep 11 14:30:31] DEBUG[742] chan_sip.c: build_route: Record-Route hop: [Sep 11 14:30:31] DEBUG[742] chan_sip.c: build_route: Record-Route hop: [Sep 11 14:30:31] DEBUG[742] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Sep 11 14:30:31] DEBUG[742] chan_sip.c: Processing session-level SDP o=- 34141 35015 IN IP4 64.194.139.61... UNSUPPORTED OR FAILED. [Sep 11 14:30:31] DEBUG[758] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: SIP/flowroute-000000b4 ChannelState: 5 ChannelStateDesc: Ringing CallerIDNum: 4072674434 CallerIDName: ConnectedLineNum: 123 ConnectedLineName: Uniqueid: 1347391825.314 [Sep 11 14:30:31] DEBUG[742] chan_sip.c: Processing session-level SDP s=-... UNSUPPORTED OR FAILED. [Sep 11 14:30:31] DEBUG[742] netsock2.c: Splitting '64.194.139.61' into... [Sep 11 14:30:31] DEBUG[742] netsock2.c: ...host '64.194.139.61' and port ''. [Sep 11 14:30:31] DEBUG[720] devicestate.c: No provider found, checking channel drivers for SIP - flowroute [Sep 11 14:30:31] DEBUG[720] chan_sip.c: Checking device state for peer flowroute [Sep 11 14:30:31] DEBUG[720] devicestate.c: Changing state for SIP/flowroute - state 1 (Not in use) [Sep 11 14:30:31] DEBUG[720] devicestate.c: device 'SIP/flowroute' state '1' [Sep 11 14:30:31] DEBUG[742] chan_sip.c: Processing session-level SDP c=IN IP4 64.194.139.61... OK. [Sep 11 14:30:31] DEBUG[742] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Sep 11 14:30:31] DEBUG[742] rtp_engine.c: Setting payload 0 based on m type on 0x7f83e657bac0 [Sep 11 14:30:31] DEBUG[742] rtp_engine.c: Setting payload 101 based on m type on 0x7f83e657bac0 [Sep 11 14:30:31] DEBUG[742] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Sep 11 14:30:31] DEBUG[742] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED. [Sep 11 14:30:31] DEBUG[742] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Sep 11 14:30:31] DEBUG[742] rtp_engine.c: Incorporating payload 0 on 0x7f83e657bac0 [Sep 11 14:30:31] DEBUG[742] rtp_engine.c: Incorporating payload 101 on 0x7f83e657bac0 [Sep 11 14:30:31] DEBUG[742] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x1f0a558' [Sep 11 14:30:31] DEBUG[742] rtp_engine.c: Copying payload 0 from 0x7f83e657bac0 to 0x1f0a720 [Sep 11 14:30:31] DEBUG[742] rtp_engine.c: Copying payload 101 from 0x7f83e657bac0 to 0x1f0a720 [Sep 11 14:30:31] DEBUG[742] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x1f0a558' [Sep 11 14:30:31] DEBUG[742] chan_sip.c: We're settling with these formats: 0x4 (ulaw) [Sep 11 14:30:31] DEBUG[742] chan_sip.c: We have an owner, now see if we need to change this call [Sep 11 14:30:31] DEBUG[757] app_queue.c: Device 'SIP/flowroute' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 11 14:30:31] DEBUG[720] devicestate.c: No provider found, checking channel drivers for Local - 4072674434@outbound_crm [Sep 11 14:30:31] DEBUG[720] chan_local.c: Checking if extension 4072674434@outbound_crm exists (devicestate) [Sep 11 14:30:31] DEBUG[720] devicestate.c: Changing state for Local/4072674434@outbound_crm - state 2 (In use) [Sep 11 14:30:31] DEBUG[720] devicestate.c: device 'Local/4072674434@outbound_crm' state '2' [Sep 11 14:30:31] DEBUG[758] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: Local/4072674434@outbound_crm-8c88;1 ChannelState: 5 ChannelStateDesc: Ringing CallerIDNum: CallerIDName: ConnectedLineNum: 123 ConnectedLineName: Uniqueid: 1347391825.312 [Sep 11 14:30:31] DEBUG[6996] channel.c: Driver for channel 'Agent/0000' does not support indication 3, emulating it [Sep 11 14:30:31] DEBUG[6996] channel.c: Set channel Agent/0000 to write format slin [Sep 11 14:30:31] DEBUG[6996] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Sep 11 14:30:31] DEBUG[757] app_queue.c: Device 'Local/4072674434@outbound_crm' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Sep 11 14:30:31] DEBUG[6996] channel.c: Generator got voice, switching to phase locked mode [Sep 11 14:30:31] DEBUG[6996] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:31] DEBUG[6996] res_rtp_asterisk.c: Difference is 100528, ms is 12586 [Sep 11 14:30:31] DEBUG[7007] res_rtp_asterisk.c: Ooh, format changed from unknown to ulaw [Sep 11 14:30:31] DEBUG[7007] res_rtp_asterisk.c: Created smoother: format: ulaw ms: 20 len: 160 [Sep 11 14:30:31] DEBUG[7007] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0x1f0a558' [Sep 11 14:30:31] DEBUG[6996] channel.c: Set channel Agent/0000 to write format ulaw [Sep 11 14:30:31] DEBUG[6996] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:31] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:31] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:31] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:31] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning '' [Sep 11 14:30:32] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:32] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:32] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning '' [Sep 11 14:30:32] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:33] DEBUG[6996] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:30:33] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:33] DEBUG[6996] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:30:33] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:33] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:33] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning '' [Sep 11 14:30:34] DEBUG[763] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: SIP/flowroute-000000b4 ChannelState: 5 ChannelStateDesc: Ringing CallerIDNum: 4072674434 CallerIDName: ConnectedLineNum: 123 ConnectedLineName: Uniqueid: 1347391825.314 [Sep 11 14:30:34] DEBUG[763] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: Local/4072674434@outbound_crm-8c88;1 ChannelState: 5 ChannelStateDesc: Ringing CallerIDNum: CallerIDName: ConnectedLineNum: 123 ConnectedLineName: Uniqueid: 1347391825.312 [Sep 11 14:30:34] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:34] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:34] DEBUG[763] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning '' [Sep 11 14:30:34] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:34] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:34] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:34] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:34] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning '' [Sep 11 14:30:35] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:35] DEBUG[742] chan_sip.c: = Looking for Call ID: 44d277ab032e2cbd65a5d3c428c78b10@sip.flowroute.com (Checking To) --From tag as1519f496 --To-tag 26061 [Sep 11 14:30:35] DEBUG[742] chan_sip.c: Acked pending invite 103 [Sep 11 14:30:35] DEBUG[742] chan_sip.c: Stopping retransmission on '44d277ab032e2cbd65a5d3c428c78b10@sip.flowroute.com' of Request 103: Match Found [Sep 11 14:30:35] DEBUG[742] chan_sip.c: SIP response 200 to standard invite [Sep 11 14:30:35] DEBUG[742] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Sep 11 14:30:35] DEBUG[742] chan_sip.c: Call 44d277ab032e2cbd65a5d3c428c78b10@sip.flowroute.com responded to our reinvite without changing SDP version; ignoring SDP. [Sep 11 14:30:35] DEBUG[742] chan_sip.c: Updating call counter for outgoing call [Sep 11 14:30:35] DEBUG[742] chan_sip.c: build_route: Record-Route hop: [Sep 11 14:30:35] DEBUG[742] chan_sip.c: build_route: Record-Route hop: [Sep 11 14:30:35] DEBUG[742] netsock2.c: Splitting '216.115.69.144' into... [Sep 11 14:30:35] DEBUG[742] netsock2.c: ...host '216.115.69.144' and port ''. [Sep 11 14:30:35] DEBUG[742] chan_sip.c: Trying to put 'ACK sip:140' onto UDP socket destined for 216.115.69.144:5060 [Sep 11 14:30:35] DEBUG[758] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: SIP/flowroute-000000b4 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 4072674434 CallerIDName: ConnectedLineNum: 123 ConnectedLineName: Uniqueid: 1347391825.314 [Sep 11 14:30:35] DEBUG[720] devicestate.c: No provider found, checking channel drivers for SIP - flowroute [Sep 11 14:30:35] DEBUG[720] chan_sip.c: Checking device state for peer flowroute [Sep 11 14:30:35] DEBUG[720] devicestate.c: Changing state for SIP/flowroute - state 1 (Not in use) [Sep 11 14:30:35] DEBUG[720] devicestate.c: device 'SIP/flowroute' state '1' [Sep 11 14:30:35] DEBUG[757] app_queue.c: Device 'SIP/flowroute' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 11 14:30:35] DEBUG[720] devicestate.c: No provider found, checking channel drivers for Local - 4072674434@outbound_crm [Sep 11 14:30:35] DEBUG[720] chan_local.c: Checking if extension 4072674434@outbound_crm exists (devicestate) [Sep 11 14:30:35] DEBUG[720] devicestate.c: Changing state for Local/4072674434@outbound_crm - state 2 (In use) [Sep 11 14:30:35] DEBUG[758] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: Local/4072674434@outbound_crm-8c88;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 123 CallerIDName: ConnectedLineNum: ConnectedLineName: Uniqueid: 1347391825.313 [Sep 11 14:30:35] DEBUG[720] devicestate.c: device 'Local/4072674434@outbound_crm' state '2' [Sep 11 14:30:35] DEBUG[720] devicestate.c: No provider found, checking channel drivers for Local - 4072674434@outbound_crm [Sep 11 14:30:35] DEBUG[720] chan_local.c: Checking if extension 4072674434@outbound_crm exists (devicestate) [Sep 11 14:30:35] DEBUG[720] devicestate.c: Changing state for Local/4072674434@outbound_crm - state 2 (In use) [Sep 11 14:30:35] DEBUG[758] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: Local/4072674434@outbound_crm-8c88;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: 123 ConnectedLineName: Uniqueid: 1347391825.312 [Sep 11 14:30:35] DEBUG[720] devicestate.c: device 'Local/4072674434@outbound_crm' state '2' [Sep 11 14:30:35] DEBUG[757] app_queue.c: Device 'Local/4072674434@outbound_crm' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Sep 11 14:30:35] DEBUG[757] app_queue.c: Device 'Local/4072674434@outbound_crm' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Sep 11 14:30:35] DEBUG[6996] features.c: Dial party C result: newchan:1, outstate:4 [Sep 11 14:30:35] DEBUG[6996] features.c: Actually doing an attended transfer. [Sep 11 14:30:35] DEBUG[7007] features.c: bridge answer set, chan answer set [Sep 11 14:30:35] DEBUG[7007] features.c: Removing dialed interfaces datastore on SIP/flowroute-000000b4 since we're bridging [Sep 11 14:30:35] DEBUG[758] manager.c: Examining event: Event: NewAccountCode Privilege: call,all Channel: SIP/flowroute-000000b4 Uniqueid: 1347391825.314 AccountCode: OldAccountCode: [Sep 11 14:30:35] DEBUG[758] manager.c: Examining event: Event: Bridge Privilege: call,all Bridgestate: Link Bridgetype: core Channel1: Local/4072674434@outbound_crm-8c88;2 Channel2: SIP/flowroute-000000b4 Uniqueid1: 1347391825.313 Uniqueid2: 1347391825.314 CallerID1: 123 CallerID2: 4072674434 [Sep 11 14:30:35] DEBUG[758] manager.c: Examining event: Event: NewAccountCode Privilege: call,all Channel: Local/4072674434@outbound_crm-8c88;1 Uniqueid: 1347391825.312 AccountCode: OldAccountCode: [Sep 11 14:30:35] DEBUG[6996] features.c: bridge answer set, chan answer set [Sep 11 14:30:35] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:35] DEBUG[6996] channel.c: Got a FRAME_CONTROL (-1) frame on channel Local/4072674434@outbound_crm-8c88;1 [Sep 11 14:30:35] DEBUG[758] manager.c: Examining event: Event: Bridge Privilege: call,all Bridgestate: Link Bridgetype: core Channel1: Agent/0000 Channel2: Local/4072674434@outbound_crm-8c88;1 Uniqueid1: 1347391810.311 Uniqueid2: 1347391825.312 CallerID1: 123 CallerID2: [Sep 11 14:30:35] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:35] DEBUG[758] manager.c: Examining event: Event: Unlink Privilege: call,all Channel1: Agent/0000 Channel2: Local/4072674434@outbound_crm-8c88;1 Uniqueid1: 1347391810.311 Uniqueid2: 1347391825.312 CallerID1: 123 CallerID2: [Sep 11 14:30:35] DEBUG[6996] channel.c: Bridge stops bridging channels Agent/0000 and Local/4072674434@outbound_crm-8c88;1 [Sep 11 14:30:35] DEBUG[7007] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:35] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:35] DEBUG[758] manager.c: Examining event: Event: Bridge Privilege: call,all Bridgestate: Link Bridgetype: core Channel1: Agent/0000 Channel2: Local/4072674434@outbound_crm-8c88;1 Uniqueid1: 1347391810.311 Uniqueid2: 1347391825.312 CallerID1: 123 CallerID2: [Sep 11 14:30:35] DEBUG[7007] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:35] DEBUG[7007] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:35] DEBUG[7007] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:35] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:35] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:35] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:35] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning 'Local/4072674434@outbound_crm-8c88;1' [Sep 11 14:30:35] DEBUG[758] chan_agent.c: Asked for bridged channel on 'Local/4072674434@outbound_crm-8c88;1'/'Agent/0000', returning 'SIP/phono4-ext.voxeolabs.net-000000b2' [Sep 11 14:30:36] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:36] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:36] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:36] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning 'Local/4072674434@outbound_crm-8c88;1' [Sep 11 14:30:36] DEBUG[758] chan_agent.c: Asked for bridged channel on 'Local/4072674434@outbound_crm-8c88;1'/'Agent/0000', returning 'SIP/phono4-ext.voxeolabs.net-000000b2' [Sep 11 14:30:37] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:37] DEBUG[4528] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:30:37] DEBUG[6996] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:30:37] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:37] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:37] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning 'Local/4072674434@outbound_crm-8c88;1' [Sep 11 14:30:37] DEBUG[758] chan_agent.c: Asked for bridged channel on 'Local/4072674434@outbound_crm-8c88;1'/'Agent/0000', returning 'SIP/phono4-ext.voxeolabs.net-000000b2' [Sep 11 14:30:37] DEBUG[763] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: SIP/flowroute-000000b4 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 4072674434 CallerIDName: ConnectedLineNum: 123 ConnectedLineName: Uniqueid: 1347391825.314 [Sep 11 14:30:37] DEBUG[763] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: Local/4072674434@outbound_crm-8c88;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 123 CallerIDName: ConnectedLineNum: ConnectedLineName: Uniqueid: 1347391825.313 [Sep 11 14:30:37] DEBUG[763] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: Local/4072674434@outbound_crm-8c88;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: CallerIDName: ConnectedLineNum: 123 ConnectedLineName: Uniqueid: 1347391825.312 [Sep 11 14:30:37] DEBUG[763] manager.c: Examining event: Event: NewAccountCode Privilege: call,all Channel: SIP/flowroute-000000b4 Uniqueid: 1347391825.314 AccountCode: OldAccountCode: [Sep 11 14:30:37] DEBUG[763] manager.c: Examining event: Event: Bridge Privilege: call,all Bridgestate: Link Bridgetype: core Channel1: Local/4072674434@outbound_crm-8c88;2 Channel2: SIP/flowroute-000000b4 Uniqueid1: 1347391825.313 Uniqueid2: 1347391825.314 CallerID1: 123 CallerID2: 4072674434 [Sep 11 14:30:37] DEBUG[763] manager.c: Examining event: Event: NewAccountCode Privilege: call,all Channel: Local/4072674434@outbound_crm-8c88;1 Uniqueid: 1347391825.312 AccountCode: OldAccountCode: [Sep 11 14:30:37] DEBUG[763] manager.c: Examining event: Event: Bridge Privilege: call,all Bridgestate: Link Bridgetype: core Channel1: Agent/0000 Channel2: Local/4072674434@outbound_crm-8c88;1 Uniqueid1: 1347391810.311 Uniqueid2: 1347391825.312 CallerID1: 123 CallerID2: [Sep 11 14:30:37] DEBUG[763] manager.c: Examining event: Event: Unlink Privilege: call,all Channel1: Agent/0000 Channel2: Local/4072674434@outbound_crm-8c88;1 Uniqueid1: 1347391810.311 Uniqueid2: 1347391825.312 CallerID1: 123 CallerID2: [Sep 11 14:30:37] DEBUG[763] manager.c: Examining event: Event: Bridge Privilege: call,all Bridgestate: Link Bridgetype: core Channel1: Agent/0000 Channel2: Local/4072674434@outbound_crm-8c88;1 Uniqueid1: 1347391810.311 Uniqueid2: 1347391825.312 CallerID1: 123 CallerID2: [Sep 11 14:30:37] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:37] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:37] DEBUG[763] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning 'Local/4072674434@outbound_crm-8c88;1' [Sep 11 14:30:37] DEBUG[763] chan_agent.c: Asked for bridged channel on 'Local/4072674434@outbound_crm-8c88;1'/'Agent/0000', returning 'SIP/phono4-ext.voxeolabs.net-000000b2' [Sep 11 14:30:37] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:38] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:38] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:38] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:38] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning 'Local/4072674434@outbound_crm-8c88;1' [Sep 11 14:30:38] DEBUG[758] chan_agent.c: Asked for bridged channel on 'Local/4072674434@outbound_crm-8c88;1'/'Agent/0000', returning 'SIP/phono4-ext.voxeolabs.net-000000b2' [Sep 11 14:30:39] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:39] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:39] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:39] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning 'Local/4072674434@outbound_crm-8c88;1' [Sep 11 14:30:39] DEBUG[758] chan_agent.c: Asked for bridged channel on 'Local/4072674434@outbound_crm-8c88;1'/'Agent/0000', returning 'SIP/phono4-ext.voxeolabs.net-000000b2' [Sep 11 14:30:40] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:40] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:40] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:40] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning 'Local/4072674434@outbound_crm-8c88;1' [Sep 11 14:30:40] DEBUG[758] chan_agent.c: Asked for bridged channel on 'Local/4072674434@outbound_crm-8c88;1'/'Agent/0000', returning 'SIP/phono4-ext.voxeolabs.net-000000b2' [Sep 11 14:30:41] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:41] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:41] DEBUG[6996] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:30:41] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:41] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning 'Local/4072674434@outbound_crm-8c88;1' [Sep 11 14:30:41] DEBUG[758] chan_agent.c: Asked for bridged channel on 'Local/4072674434@outbound_crm-8c88;1'/'Agent/0000', returning 'SIP/phono4-ext.voxeolabs.net-000000b2' [Sep 11 14:30:42] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:42] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:42] DEBUG[763] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning 'Local/4072674434@outbound_crm-8c88;1' [Sep 11 14:30:42] DEBUG[763] chan_agent.c: Asked for bridged channel on 'Local/4072674434@outbound_crm-8c88;1'/'Agent/0000', returning 'SIP/phono4-ext.voxeolabs.net-000000b2' [Sep 11 14:30:42] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:42] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Sep 11 14:30:42] DEBUG[6996] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 42 (*), at 107.21.15.145:20714 [Sep 11 14:30:42] DTMF[6996] channel.c: DTMF begin '*' received on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:42] DTMF[6996] channel.c: DTMF begin passthrough '*' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:42] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Sep 11 14:30:42] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Sep 11 14:30:42] DEBUG[6996] res_rtp_asterisk.c: Creating END DTMF Frame: 42 (*), at 107.21.15.145:20714 [Sep 11 14:30:42] DTMF[6996] channel.c: DTMF end '*' received on SIP/phono4-ext.voxeolabs.net-000000b2, duration 0 ms [Sep 11 14:30:42] DTMF[6996] channel.c: DTMF end accepted with begin '*' on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:42] DTMF[6996] channel.c: DTMF end '*' detected to have actual duration 25 on the wire, emulation will be triggered on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:42] DTMF[6996] channel.c: DTMF end '*' has duration 25 but want minimum 80, emulating on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:42] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Sep 11 14:30:42] DEBUG[6996] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Sep 11 14:30:42] DTMF[6996] channel.c: DTMF end emulation of '*' queued on SIP/phono4-ext.voxeolabs.net-000000b2 [Sep 11 14:30:42] DEBUG[6996] channel.c: Didn't get a frame from channel: Agent/0000 [Sep 11 14:30:42] DEBUG[7007] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:42] DEBUG[758] manager.c: Examining event: Event: Unlink Privilege: call,all Channel1: Agent/0000 Channel2: Local/4072674434@outbound_crm-8c88;1 Uniqueid1: 1347391810.311 Uniqueid2: 1347391825.312 CallerID1: 123 CallerID2: [Sep 11 14:30:42] DEBUG[6996] channel.c: Bridge stops bridging channels Agent/0000 and Local/4072674434@outbound_crm-8c88;1 [Sep 11 14:30:42] DEBUG[6996] channel.c: Set channel SIP/matt-000000b3 to write format ulaw [Sep 11 14:30:42] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:42] DEBUG[6996] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:42] DEBUG[758] manager.c: Examining event: Event: MusicOnHold Privilege: call,all State: Stop Channel: SIP/matt-000000b3 UniqueID: 1347391809.310 [Sep 11 14:30:42] DEBUG[6996] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:30:42] DEBUG[6996] channel.c: Planning to masquerade channel SIP/matt-000000b3 into the structure of Transfered/SIP/matt-000000b3 [Sep 11 14:30:42] DEBUG[758] manager.c: Examining event: Event: Newchannel Privilege: call,all Channel: Transfered/SIP/matt-000000b3 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: CallerIDName: AccountCode: Exten: Context: Uniqueid: 1347391842.315 [Sep 11 14:30:42] DEBUG[6996] channel.c: Done planning to masquerade channel SIP/matt-000000b3 into the structure of Transfered/SIP/matt-000000b3 [Sep 11 14:30:42] DEBUG[6996] channel.c: Actually Masquerading SIP/matt-000000b3(6) into the structure of Transfered/SIP/matt-000000b3(6) [Sep 11 14:30:42] DEBUG[758] manager.c: Examining event: Event: Masquerade Privilege: call,all Clone: SIP/matt-000000b3 CloneState: Up Original: Transfered/SIP/matt-000000b3 OriginalState: Up [Sep 11 14:30:42] DEBUG[758] manager.c: Examining event: Event: Rename Privilege: call,all Channel: SIP/matt-000000b3 Newname: SIP/matt-000000b3 Uniqueid: 1347391809.310 [Sep 11 14:30:42] DEBUG[758] manager.c: Examining event: Event: Rename Privilege: call,all Channel: Transfered/SIP/matt-000000b3 Newname: SIP/matt-000000b3 Uniqueid: 1347391842.315 [Sep 11 14:30:42] DEBUG[758] manager.c: Examining event: Event: Rename Privilege: call,all Channel: SIP/matt-000000b3 Newname: Transfered/SIP/matt-000000b3 Uniqueid: 1347391809.310 [Sep 11 14:30:42] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:42] DEBUG[6996] channel.c: Putting channel SIP/matt-000000b3 in ulaw/ulaw formats [Sep 11 14:30:42] DEBUG[6996] chan_sip.c: SIP Fixup: New owner for dialogue wrgXWVqrzCHmvkazADeRBqq1woeFZckN: SIP/matt-000000b3 (Old parent: Transfered/SIP/matt-000000b3) [Sep 11 14:30:42] DEBUG[6996] channel.c: Driver for channel 'SIP/matt-000000b3' does not support indication 3, emulating it [Sep 11 14:30:42] DEBUG[6996] channel.c: Set channel SIP/matt-000000b3 to write format slin [Sep 11 14:30:42] DEBUG[6996] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Sep 11 14:30:42] DEBUG[6996] channel.c: Done Masquerading SIP/matt-000000b3 (6) [Sep 11 14:30:42] DEBUG[6996] res_rtp_asterisk.c: Changing ssrc from 1172191529 to 1403163559 due to a source change [Sep 11 14:30:42] DEBUG[6996] channel.c: Set channel Local/4072674434@outbound_crm-8c88;1 to write format gsm [Sep 11 14:30:42] DEBUG[758] manager.c: Examining event: Event: NewCallerid Privilege: call,all Channel: SIP/matt-000000b3 CallerIDNum: matt CallerIDName: Matt Uniqueid: 1347391842.315 CID-CallingPres: 0 (Presentation Allowed, Not Screened) [Sep 11 14:30:42] DEBUG[6996] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Sep 11 14:30:42] DEBUG[7007] res_rtp_asterisk.c: Difference is 3656, ms is 477 [Sep 11 14:30:42] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:43] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:43] DEBUG[758] chan_agent.c: Asked for bridged channel on 'SIP/phono4-ext.voxeolabs.net-000000b2'/'Agent/0000', returning '' [Sep 11 14:30:43] DEBUG[6996] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:43] DEBUG[6996] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:43] DEBUG[6996] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:43] DEBUG[6996] channel.c: Set channel Local/4072674434@outbound_crm-8c88;1 to write format ulaw [Sep 11 14:30:43] DEBUG[7022] features.c: bridge answer set, chan answer set [Sep 11 14:30:43] DEBUG[758] manager.c: Examining event: Event: NewAccountCode Privilege: call,all Channel: Local/4072674434@outbound_crm-8c88;1 Uniqueid: 1347391825.312 AccountCode: OldAccountCode: [Sep 11 14:30:43] DEBUG[758] manager.c: Examining event: Event: Bridge Privilege: call,all Bridgestate: Link Bridgetype: core Channel1: SIP/matt-000000b3 Channel2: Local/4072674434@outbound_crm-8c88;1 Uniqueid1: 1347391842.315 Uniqueid2: 1347391825.312 CallerID1: matt CallerID2: [Sep 11 14:30:43] DEBUG[7022] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:43] DEBUG[7007] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:43] DEBUG[7022] channel.c: Generator got voice, switching to phase locked mode [Sep 11 14:30:43] DEBUG[7022] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:43] DEBUG[7022] res_rtp_asterisk.c: Difference is 6592, ms is 844 [Sep 11 14:30:43] DEBUG[7022] channel.c: Set channel SIP/matt-000000b3 to write format ulaw [Sep 11 14:30:43] DEBUG[7022] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:43] DEBUG[6996] cdr_mysql.c: Inserting a CDR record. [Sep 11 14:30:43] DEBUG[6996] cdr_mysql.c: SQL command as follows: INSERT INTO cdr (`calldate`,`clid`,`src`,`dst`,`dcontext`,`channel`,`dstchannel`,`lastapp`,`lastdata`,`duration`,`billsec`,`disposition`,`amaflags`,`uniqueid`) VALUES ('2012-09-11 14:30:09','\"Matt\" ','matt','123','internal','SIP/matt-000000b3','Agent/0000','Queue','so_crm_5,tTH','34','34','ANSWERED','3','1347391809.310') [Sep 11 14:30:43] DEBUG[6996] channel.c: Hanging up channel 'Agent/0000' [Sep 11 14:30:43] DEBUG[6996] chan_agent.c: Hangup called for state Up [Sep 11 14:30:43] DEBUG[6996] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:30:43] DEBUG[6996] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Sep 11 14:30:43] DEBUG[758] manager.c: Examining event: Event: MusicOnHold Privilege: call,all State: Start Channel: SIP/phono4-ext.voxeolabs.net-000000b2 UniqueID: 1347391798.309 Class: default [Sep 11 14:30:43] DEBUG[6996] devicestate.c: device 'Agent/0000' state '1' [Sep 11 14:30:43] DEBUG[758] manager.c: Examining event: Event: Hangup Privilege: call,all Channel: Agent/0000 Uniqueid: 1347391810.311 CallerIDNum: 123 CallerIDName: ConnectedLineNum: matt ConnectedLineName: Matt Cause: 0 Cause-txt: Unknown [Sep 11 14:30:43] DEBUG[757] app_queue.c: Device 'Agent/0000' changed to state '1' (Not in use) [Sep 11 14:30:43] DEBUG[758] manager.c: Examining event: Event: QueueMemberStatus Privilege: agent,all Queue: so_crm_5 Location: Agent/0000 MemberName: admin Membership: realtime Penalty: 0 CallsTaken: 5 LastCall: 1347391842 Status: 1 Paused: 0 [Sep 11 14:30:43] DEBUG[720] devicestate.c: No provider found, checking channel drivers for Agent - 0000 [Sep 11 14:30:43] DEBUG[720] devicestate.c: Changing state for Agent/0000 - state 0 (Unknown) [Sep 11 14:30:43] DEBUG[720] devicestate.c: device 'Agent/0000' state '0' [Sep 11 14:30:43] DEBUG[757] app_queue.c: Device 'Agent/0000' changed to state '0' (Unknown) [Sep 11 14:30:43] DEBUG[758] manager.c: Examining event: Event: QueueMemberStatus Privilege: agent,all Queue: so_crm_5 Location: Agent/0000 MemberName: admin Membership: realtime Penalty: 0 CallsTaken: 5 LastCall: 1347391842 Status: 0 Paused: 0 [Sep 11 14:30:43] DEBUG[6976] channel.c: Generator got voice, switching to phase locked mode [Sep 11 14:30:43] DEBUG[6976] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:43] DEBUG[6976] channel.c: Set channel SIP/phono4-ext.voxeolabs.net-000000b2 to write format slin [Sep 11 14:30:43] DEBUG[6976] res_musiconhold.c: SIP/phono4-ext.voxeolabs.net-000000b2 Opened file 0 '/var/lib/asterisk/moh/macroform-cold_day' [Sep 11 14:30:43] DEBUG[6976] res_rtp_asterisk.c: Difference is 7584, ms is 968 [Sep 11 14:30:43] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:43] DEBUG[6996] pbx.c: Spawn extension (internal,123,3) exited non-zero on 'Transfered/SIP/matt-000000b3' [Sep 11 14:30:43] DEBUG[6996] channel.c: Soft-Hanging up channel 'Transfered/SIP/matt-000000b3' [Sep 11 14:30:43] DEBUG[6996] channel.c: Hanging up zombie 'Transfered/SIP/matt-000000b3' [Sep 11 14:30:43] DEBUG[720] devicestate.c: No provider found, checking channel drivers for Transfered - SIP/matt [Sep 11 14:30:43] DEBUG[758] manager.c: Examining event: Event: Hangup Privilege: call,all Channel: Transfered/SIP/matt-000000b3 Uniqueid: 1347391809.310 CallerIDNum: CallerIDName: ConnectedLineNum: ConnectedLineName: Cause: 0 Cause-txt: Unknown [Sep 11 14:30:43] DEBUG[720] devicestate.c: Changing state for Transfered/SIP/matt - state 4 (Invalid) [Sep 11 14:30:43] DEBUG[720] devicestate.c: device 'Transfered/SIP/matt' state '4' [Sep 11 14:30:43] DEBUG[757] app_queue.c: Device 'Transfered/SIP/matt' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Sep 11 14:30:43] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:44] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:44] DEBUG[6976] chan_agent.c: Wrapup time for 0000 expired! [Sep 11 14:30:44] DEBUG[6976] devicestate.c: device 'Agent/0000' state '1' [Sep 11 14:30:44] DEBUG[6976] chan_agent.c: Checking availability of '0000' [Sep 11 14:30:44] DEBUG[757] app_queue.c: Device 'Agent/0000' changed to state '1' (Not in use) [Sep 11 14:30:44] DEBUG[758] manager.c: Examining event: Event: QueueMemberStatus Privilege: agent,all Queue: so_crm_5 Location: Agent/0000 MemberName: admin Membership: realtime Penalty: 0 CallsTaken: 5 LastCall: 1347391842 Status: 1 Paused: 0 [Sep 11 14:30:44] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:45] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:45] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:45] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:46] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:46] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:46] DEBUG[763] manager.c: Examining event: Event: Unlink Privilege: call,all Channel1: Agent/0000 Channel2: Local/4072674434@outbound_crm-8c88;1 Uniqueid1: 1347391810.311 Uniqueid2: 1347391825.312 CallerID1: 123 CallerID2: [Sep 11 14:30:46] DEBUG[763] manager.c: Examining event: Event: MusicOnHold Privilege: call,all State: Stop Channel: SIP/matt-000000b3 UniqueID: 1347391809.310 [Sep 11 14:30:46] DEBUG[763] manager.c: Examining event: Event: Newchannel Privilege: call,all Channel: Transfered/SIP/matt-000000b3 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: CallerIDName: AccountCode: Exten: Context: Uniqueid: 1347391842.315 [Sep 11 14:30:46] DEBUG[763] manager.c: Examining event: Event: Masquerade Privilege: call,all Clone: SIP/matt-000000b3 CloneState: Up Original: Transfered/SIP/matt-000000b3 OriginalState: Up [Sep 11 14:30:46] DEBUG[763] manager.c: Examining event: Event: Rename Privilege: call,all Channel: SIP/matt-000000b3 Newname: SIP/matt-000000b3 Uniqueid: 1347391809.310 [Sep 11 14:30:46] DEBUG[763] manager.c: Examining event: Event: Rename Privilege: call,all Channel: Transfered/SIP/matt-000000b3 Newname: SIP/matt-000000b3 Uniqueid: 1347391842.315 [Sep 11 14:30:46] DEBUG[763] manager.c: Examining event: Event: Rename Privilege: call,all Channel: SIP/matt-000000b3 Newname: Transfered/SIP/matt-000000b3 Uniqueid: 1347391809.310 [Sep 11 14:30:46] DEBUG[763] manager.c: Examining event: Event: NewCallerid Privilege: call,all Channel: SIP/matt-000000b3 CallerIDNum: matt CallerIDName: Matt Uniqueid: 1347391842.315 CID-CallingPres: 0 (Presentation Allowed, Not Screened) [Sep 11 14:30:46] DEBUG[763] manager.c: Examining event: Event: NewAccountCode Privilege: call,all Channel: Local/4072674434@outbound_crm-8c88;1 Uniqueid: 1347391825.312 AccountCode: OldAccountCode: [Sep 11 14:30:46] DEBUG[763] manager.c: Examining event: Event: Bridge Privilege: call,all Bridgestate: Link Bridgetype: core Channel1: SIP/matt-000000b3 Channel2: Local/4072674434@outbound_crm-8c88;1 Uniqueid1: 1347391842.315 Uniqueid2: 1347391825.312 CallerID1: matt CallerID2: [Sep 11 14:30:46] DEBUG[763] manager.c: Examining event: Event: MusicOnHold Privilege: call,all State: Start Channel: SIP/phono4-ext.voxeolabs.net-000000b2 UniqueID: 1347391798.309 Class: default [Sep 11 14:30:46] DEBUG[763] manager.c: Examining event: Event: Hangup Privilege: call,all Channel: Agent/0000 Uniqueid: 1347391810.311 CallerIDNum: 123 CallerIDName: ConnectedLineNum: matt ConnectedLineName: Matt Cause: 0 Cause-txt: Unknown [Sep 11 14:30:46] DEBUG[763] manager.c: Examining event: Event: Hangup Privilege: call,all Channel: Transfered/SIP/matt-000000b3 Uniqueid: 1347391809.310 CallerIDNum: CallerIDName: ConnectedLineNum: ConnectedLineName: Cause: 0 Cause-txt: Unknown [Sep 11 14:30:46] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:46] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:46] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:46] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:47] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:47] DEBUG[7022] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:30:47] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:47] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:47] DEBUG[6976] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:30:48] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:48] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:49] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:49] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:49] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:49] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:50] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:50] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:50] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:50] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:50] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:50] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:51] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:51] DEBUG[742] chan_sip.c: = Looking for Call ID: 4ultieponnfh (Checking From) --From tag 6kr6aom5h80k --To-tag as2885fbd6 [Sep 11 14:30:51] DEBUG[742] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [Sep 11 14:30:51] DEBUG[742] netsock2.c: Splitting '107.21.15.145:5060' into... [Sep 11 14:30:51] DEBUG[742] netsock2.c: ...host '107.21.15.145' and port '5060'. [Sep 11 14:30:51] DEBUG[742] chan_sip.c: Setting SIP_ALREADYGONE on dialog 4ultieponnfh [Sep 11 14:30:51] DEBUG[742] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x1f2bf98' [Sep 11 14:30:51] DEBUG[742] chan_sip.c: Received bye, issuing owner hangup [Sep 11 14:30:51] DEBUG[742] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 107.21.15.145:5060 [Sep 11 14:30:51] DEBUG[6976] channel.c: Set channel SIP/phono4-ext.voxeolabs.net-000000b2 to write format ulaw [Sep 11 14:30:51] DEBUG[6976] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 11 14:30:51] DEBUG[758] manager.c: Examining event: Event: Agentlogoff Privilege: agent,all Agent: 0000 Logintime: 48 Uniqueid: 1347391798.309 [Sep 11 14:30:51] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:51] DEBUG[6976] devicestate.c: device 'Agent/0000' state '5' [Sep 11 14:30:51] DEBUG[6976] pbx.c: Spawn extension (default,500,1) exited non-zero on 'SIP/phono4-ext.voxeolabs.net-000000b2' [Sep 11 14:30:51] DEBUG[6976] channel.c: Soft-Hanging up channel 'SIP/phono4-ext.voxeolabs.net-000000b2' [Sep 11 14:30:51] DEBUG[6976] channel.c: Hanging up channel 'SIP/phono4-ext.voxeolabs.net-000000b2' [Sep 11 14:30:51] DEBUG[6976] chan_sip.c: Hangup call SIP/phono4-ext.voxeolabs.net-000000b2, SIP callid 4ultieponnfh [Sep 11 14:30:51] DEBUG[6976] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x1f2bf98' [Sep 11 14:30:51] DEBUG[758] manager.c: Examining event: Event: Hangup Privilege: call,all Channel: SIP/phono4-ext.voxeolabs.net-000000b2 Uniqueid: 1347391798.309 CallerIDNum: a9bce45d-60a6-450e-865f-791103280c03 CallerIDName: ConnectedLineNum: ConnectedLineName: Cause: 0 Cause-txt: Unknown [Sep 11 14:30:51] DEBUG[758] manager.c: Examining event: Event: QueueMemberStatus Privilege: agent,all Queue: so_crm_5 Location: Agent/0000 MemberName: admin Membership: realtime Penalty: 0 CallsTaken: 5 LastCall: 1347391842 Status: 5 Paused: 0 [Sep 11 14:30:51] DEBUG[757] app_queue.c: Device 'Agent/0000' changed to state '5' (Unavailable) [Sep 11 14:30:51] DEBUG[6976] cdr_mysql.c: Inserting a CDR record. [Sep 11 14:30:51] DEBUG[6976] cdr_mysql.c: SQL command as follows: INSERT INTO cdr (`calldate`,`clid`,`src`,`dst`,`dcontext`,`channel`,`lastapp`,`duration`,`billsec`,`disposition`,`amaflags`,`uniqueid`) VALUES ('2012-09-11 14:29:58','a9bce45d-60a6-450e-865f-791103280c03','a9bce45d-60a6-450e-865f-791103280c03','500','default','SIP/phono4-ext.voxeolabs.net-000000b2','AgentLogin','53','53','ANSWERED','3','1347391798.309') [Sep 11 14:30:51] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:51] DEBUG[720] devicestate.c: No provider found, checking channel drivers for SIP - phono4-ext.voxeolabs.net [Sep 11 14:30:51] DEBUG[720] chan_sip.c: Checking device state for peer phono4-ext.voxeolabs.net [Sep 11 14:30:51] DEBUG[742] chan_sip.c: = Looking for Call ID: 3bed14f2-1d71dc38-f6eb436@70.167.153.136 (Checking From) --From tag 6c0d1054 --To-tag [Sep 11 14:30:51] DEBUG[742] acl.c: For destination '216.115.69.144', our source address is '50.22.175.70'. [Sep 11 14:30:51] DEBUG[742] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 50.22.175.70:5060 [Sep 11 14:30:51] DEBUG[742] chan_sip.c: Allocating new SIP dialog for 3bed14f2-1d71dc38-f6eb436@70.167.153.136 - OPTIONS (No RTP) [Sep 11 14:30:51] DEBUG[742] chan_sip.c: **** Received OPTIONS (3) - Command in SIP OPTIONS [Sep 11 14:30:51] DEBUG[742] netsock2.c: Splitting '50.22.175.70:5060' into... [Sep 11 14:30:51] DEBUG[742] netsock2.c: ...host '50.22.175.70' and port ''. [Sep 11 14:30:51] DEBUG[742] netsock2.c: Splitting 'invalid' into... [Sep 11 14:30:51] DEBUG[742] netsock2.c: ...host 'invalid' and port ''. [Sep 11 14:30:51] DEBUG[742] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 216.115.69.144:5060 [Sep 11 14:30:51] DEBUG[7022] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:30:52] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:52] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:52] DEBUG[720] devicestate.c: Changing state for SIP/phono4-ext.voxeolabs.net - state 4 (Invalid) [Sep 11 14:30:52] DEBUG[720] devicestate.c: device 'SIP/phono4-ext.voxeolabs.net' state '4' [Sep 11 14:30:53] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:53] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:53] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:53] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:54] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:54] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:54] DEBUG[757] app_queue.c: Device 'SIP/phono4-ext.voxeolabs.net' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Sep 11 14:30:54] DEBUG[763] manager.c: Examining event: Event: Hangup Privilege: call,all Channel: SIP/phono4-ext.voxeolabs.net-000000b2 Uniqueid: 1347391798.309 CallerIDNum: a9bce45d-60a6-450e-865f-791103280c03 CallerIDName: ConnectedLineNum: ConnectedLineName: Cause: 0 Cause-txt: Unknown [Sep 11 14:30:54] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:54] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:54] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:55] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:55] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:55] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:55] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:56] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:56] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:56] DEBUG[7022] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:30:57] DEBUG[742] chan_sip.c: Auto destroying SIP dialog '537a377-1508f823-45f4da7@216.115.69.131' [Sep 11 14:30:57] DEBUG[742] chan_sip.c: Destroying SIP dialog 537a377-1508f823-45f4da7@216.115.69.131 [Sep 11 14:30:57] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:57] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:57] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:57] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:58] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:58] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:30:58] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:58] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:58] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:30:58] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:30:59] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:30:59] DEBUG[742] chan_sip.c: SIP Registry sip.flowroute.com: refcount now 3 [Sep 11 14:30:59] DEBUG[742] netsock2.c: Splitting 'sip.flowroute.com' into... [Sep 11 14:30:59] DEBUG[742] netsock2.c: ...host 'sip.flowroute.com' and port ''. [Sep 11 14:30:59] DEBUG[742] netsock2.c: Splitting 'sip-nv1.flowroute.com' into... [Sep 11 14:30:59] DEBUG[742] netsock2.c: ...host 'sip-nv1.flowroute.com' and port ''. [Sep 11 14:30:59] DEBUG[742] chan_sip.c: SIP Registry sip.flowroute.com: refcount now 2 [Sep 11 14:30:59] DEBUG[742] chan_sip.c: Allocating new SIP dialog for 5ce7d06171800090670b55187fd10083@72.14.190.50 - REGISTER (No RTP) [Sep 11 14:30:59] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:31:00] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:31:00] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:31:00] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:31:00] DEBUG[742] chan_sip.c: SIP Registry sip.flowroute.com: refcount now 3 [Sep 11 14:31:00] DEBUG[742] acl.c: For destination '216.115.69.144', our source address is '50.22.175.70'. [Sep 11 14:31:00] DEBUG[742] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 50.22.175.70:5060 [Sep 11 14:31:00] DEBUG[742] chan_sip.c: SIP Registry sip.flowroute.com: refcount now 4 [Sep 11 14:31:00] DEBUG[742] chan_sip.c: Scheduled a registration timeout for sip.flowroute.com id #2009 [Sep 11 14:31:00] DEBUG[742] netsock2.c: Splitting 'sip.flowroute.com' into... [Sep 11 14:31:00] DEBUG[742] netsock2.c: ...host 'sip.flowroute.com' and port ''. [Sep 11 14:31:00] DEBUG[742] netsock2.c: Splitting 'sip.flowroute.com' into... [Sep 11 14:31:00] DEBUG[742] netsock2.c: ...host 'sip.flowroute.com' and port ''. [Sep 11 14:31:00] DEBUG[742] netsock2.c: Splitting 'sip.flowroute.com' into... [Sep 11 14:31:00] DEBUG[742] netsock2.c: ...host 'sip.flowroute.com' and port ''. [Sep 11 14:31:00] DEBUG[742] chan_sip.c: Initializing initreq for method REGISTER - callid 5ce7d06171800090670b55187fd10083@72.14.190.50 [Sep 11 14:31:00] DEBUG[742] chan_sip.c: REGISTER attempt 1 to 11729468@sip.flowroute.com [Sep 11 14:31:00] DEBUG[742] chan_sip.c: Trying to put 'REGISTER si' onto UDP socket destined for 216.115.69.144:5060 [Sep 11 14:31:00] DEBUG[742] chan_sip.c: SIP Registry sip.flowroute.com: refcount now 3 [Sep 11 14:31:00] DEBUG[742] chan_sip.c: = Looking for Call ID: 5ce7d06171800090670b55187fd10083@72.14.190.50 (Checking To) --From tag as69ec3ae5 --To-tag aa681f9fdf30149b00040f579a1d99c4.bb19 [Sep 11 14:31:00] DEBUG[742] chan_sip.c: Stopping retransmission on '5ce7d06171800090670b55187fd10083@72.14.190.50' of Request 190: Match Found [Sep 11 14:31:00] DEBUG[7022] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:31:01] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:31:01] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:31:01] DEBUG[742] chan_sip.c: SIP Registry sip.flowroute.com: refcount now 4 [Sep 11 14:31:01] DEBUG[742] netsock2.c: Splitting 'sip.flowroute.com' into... [Sep 11 14:31:01] DEBUG[742] netsock2.c: ...host 'sip.flowroute.com' and port ''. [Sep 11 14:31:01] DEBUG[742] netsock2.c: Splitting 'sip-nv1.flowroute.com' into... [Sep 11 14:31:01] DEBUG[742] netsock2.c: ...host 'sip-nv1.flowroute.com' and port ''. [Sep 11 14:31:01] DEBUG[742] chan_sip.c: SIP Registry sip.flowroute.com: refcount now 3 [Sep 11 14:31:01] DEBUG[742] netsock2.c: Splitting 'sip.flowroute.com' into... [Sep 11 14:31:01] DEBUG[742] netsock2.c: ...host 'sip.flowroute.com' and port ''. [Sep 11 14:31:01] DEBUG[742] netsock2.c: Splitting 'sip.flowroute.com' into... [Sep 11 14:31:01] DEBUG[742] netsock2.c: ...host 'sip.flowroute.com' and port ''. [Sep 11 14:31:01] DEBUG[742] netsock2.c: Splitting 'sip.flowroute.com' into... [Sep 11 14:31:01] DEBUG[742] netsock2.c: ...host 'sip.flowroute.com' and port ''. [Sep 11 14:31:01] DEBUG[742] chan_sip.c: Initializing already initialized SIP dialog 5ce7d06171800090670b55187fd10083@72.14.190.50 (presumably reinvite) [Sep 11 14:31:01] DEBUG[742] chan_sip.c: REGISTER attempt 2 to 11729468@sip.flowroute.com [Sep 11 14:31:01] DEBUG[742] chan_sip.c: Trying to put 'REGISTER si' onto UDP socket destined for 216.115.69.144:5060 [Sep 11 14:31:01] DEBUG[742] chan_sip.c: = Looking for Call ID: 5ce7d06171800090670b55187fd10083@72.14.190.50 (Checking To) --From tag as514b9859 --To-tag aa681f9fdf30149b00040f579a1d99c4.8b4a [Sep 11 14:31:01] DEBUG[742] chan_sip.c: Stopping retransmission on '5ce7d06171800090670b55187fd10083@72.14.190.50' of Request 191: Match Found [Sep 11 14:31:01] DEBUG[742] chan_sip.c: Registration successful [Sep 11 14:31:01] DEBUG[742] chan_sip.c: Cancelling timeout 2009 [Sep 11 14:31:01] DEBUG[742] chan_sip.c: SIP Registry sip.flowroute.com: refcount now 2 [Sep 11 14:31:01] DEBUG[742] chan_sip.c: SIP Registry sip.flowroute.com: refcount now 1 [Sep 11 14:31:01] DEBUG[742] chan_sip.c: SIP Registry sip.flowroute.com: refcount now 2 [Sep 11 14:31:01] DEBUG[758] manager.c: Examining event: Event: Registry Privilege: system,all ChannelType: SIP Domain: sip.flowroute.com Status: Registered [Sep 11 14:31:02] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:31:02] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:31:02] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:31:03] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:31:03] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:31:03] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:31:03] DEBUG[763] manager.c: Examining event: Event: Registry Privilege: system,all ChannelType: SIP Domain: sip.flowroute.com Status: Registered [Sep 11 14:31:03] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:31:03] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:31:03] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:31:04] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:31:04] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:31:04] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:31:05] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:31:05] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:31:05] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:31:05] DEBUG[7022] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:31:06] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:31:06] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:31:06] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:31:06] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:31:07] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:31:07] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:31:07] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:31:07] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:31:07] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:31:08] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:31:08] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:31:08] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:31:08] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:31:09] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:31:09] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:31:10] DEBUG[7022] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Sep 11 14:31:10] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:31:10] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:31:10] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:31:10] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:31:11] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:31:11] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:31:11] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:31:11] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:31:11] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:31:11] DEBUG[742] chan_sip.c: = Looking for Call ID: wrgXWVqrzCHmvkazADeRBqq1woeFZckN (Checking From) --From tag K.qPaFlcYPUaIoFE70xYTZOaCAt4tTw1 --To-tag as4e28c0d0 [Sep 11 14:31:11] DEBUG[742] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [Sep 11 14:31:11] DEBUG[742] netsock2.c: Splitting '10.0.1.15:62168' into... [Sep 11 14:31:11] DEBUG[742] netsock2.c: ...host '10.0.1.15' and port '62168'. [Sep 11 14:31:11] DEBUG[742] chan_sip.c: Setting SIP_ALREADYGONE on dialog wrgXWVqrzCHmvkazADeRBqq1woeFZckN [Sep 11 14:31:11] DEBUG[742] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f83e0043c48' [Sep 11 14:31:11] DEBUG[742] chan_sip.c: Session timer stopped: 1998 - wrgXWVqrzCHmvkazADeRBqq1woeFZckN [Sep 11 14:31:11] DEBUG[742] chan_sip.c: Received bye, issuing owner hangup [Sep 11 14:31:11] DEBUG[742] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 97.104.212.126:34077 [Sep 11 14:31:11] DEBUG[7022] channel.c: Didn't get a frame from channel: SIP/matt-000000b3 [Sep 11 14:31:11] DEBUG[7022] channel.c: Bridge stops bridging channels SIP/matt-000000b3 and Local/4072674434@outbound_crm-8c88;1 [Sep 11 14:31:11] DEBUG[758] manager.c: Examining event: Event: Unlink Privilege: call,all Channel1: SIP/matt-000000b3 Channel2: Local/4072674434@outbound_crm-8c88;1 Uniqueid1: 1347391842.315 Uniqueid2: 1347391825.312 CallerID1: matt CallerID2: [Sep 11 14:31:11] DEBUG[7007] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:31:11] DEBUG[7022] cdr_mysql.c: Inserting a CDR record. [Sep 11 14:31:11] DEBUG[7022] cdr_mysql.c: SQL command as follows: INSERT INTO cdr (`calldate`,`clid`,`src`,`dst`,`dcontext`,`channel`,`dstchannel`,`lastapp`,`lastdata`,`duration`,`billsec`,`disposition`,`amaflags`,`uniqueid`) VALUES ('2012-09-11 14:30:09','\"Matt\" ','matt','123','internal','SIP/matt-000000b3','Agent/0000','Transferred Call','Local/4072674434@outbound_crm-8c88;1','62','62','ANSWERED','3','1347391809.310') [Sep 11 14:31:12] DEBUG[7022] channel.c: Hanging up channel 'Local/4072674434@outbound_crm-8c88;1' [Sep 11 14:31:12] DEBUG[7007] channel.c: Didn't get a frame from channel: Local/4072674434@outbound_crm-8c88;2 [Sep 11 14:31:12] DEBUG[7007] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 11 14:31:12] DEBUG[758] manager.c: Examining event: Event: Hangup Privilege: call,all Channel: Local/4072674434@outbound_crm-8c88;1 Uniqueid: 1347391825.312 CallerIDNum: CallerIDName: ConnectedLineNum: matt ConnectedLineName: Matt Cause: 0 Cause-txt: Unknown [Sep 11 14:31:12] DEBUG[758] manager.c: Examining event: Event: Unlink Privilege: call,all Channel1: Local/4072674434@outbound_crm-8c88;2 Channel2: SIP/flowroute-000000b4 Uniqueid1: 1347391825.313 Uniqueid2: 1347391825.314 CallerID1: 123 CallerID2: 4072674434 [Sep 11 14:31:12] DEBUG[7007] channel.c: Bridge stops bridging channels Local/4072674434@outbound_crm-8c88;2 and SIP/flowroute-000000b4 [Sep 11 14:31:12] DEBUG[720] devicestate.c: No provider found, checking channel drivers for Local - 4072674434@outbound_crm [Sep 11 14:31:12] DEBUG[720] chan_local.c: Checking if extension 4072674434@outbound_crm exists (devicestate) [Sep 11 14:31:12] DEBUG[720] devicestate.c: Changing state for Local/4072674434@outbound_crm - state 1 (Not in use) [Sep 11 14:31:12] DEBUG[720] devicestate.c: device 'Local/4072674434@outbound_crm' state '1' [Sep 11 14:31:12] DEBUG[7022] channel.c: Hanging up channel 'SIP/matt-000000b3' [Sep 11 14:31:12] DEBUG[7022] chan_sip.c: Hangup call SIP/matt-000000b3, SIP callid wrgXWVqrzCHmvkazADeRBqq1woeFZckN [Sep 11 14:31:12] DEBUG[7022] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f83e0043c48' [Sep 11 14:31:12] DEBUG[758] manager.c: Examining event: Event: Hangup Privilege: call,all Channel: SIP/matt-000000b3 Uniqueid: 1347391842.315 CallerIDNum: matt CallerIDName: Matt ConnectedLineNum: matt ConnectedLineName: Matt Cause: 0 Cause-txt: Unknown [Sep 11 14:31:12] DEBUG[720] devicestate.c: No provider found, checking channel drivers for SIP - matt [Sep 11 14:31:12] DEBUG[720] chan_sip.c: Checking device state for peer matt [Sep 11 14:31:12] DEBUG[720] devicestate.c: Changing state for SIP/matt - state 1 (Not in use) [Sep 11 14:31:12] DEBUG[720] devicestate.c: device 'SIP/matt' state '1' [Sep 11 14:31:12] DEBUG[757] app_queue.c: Device 'Local/4072674434@outbound_crm' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 11 14:31:12] DEBUG[757] app_queue.c: Device 'SIP/matt' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 11 14:31:12] DEBUG[7007] cdr_mysql.c: Inserting a CDR record. [Sep 11 14:31:12] DEBUG[7007] cdr_mysql.c: SQL command as follows: INSERT INTO cdr (`calldate`,`clid`,`src`,`dst`,`dcontext`,`channel`,`dstchannel`,`lastapp`,`lastdata`,`duration`,`billsec`,`disposition`,`amaflags`,`uniqueid`) VALUES ('2012-09-11 14:30:25','123','123','4072674434','outbound_crm','Local/4072674434@outbound_crm-8c88;2','SIP/flowroute-000000b4','Dial','SIP/14072674434@flowroute','47','37','ANSWERED','3','1347391825.313') [Sep 11 14:31:12] DEBUG[7007] channel.c: Hanging up channel 'SIP/flowroute-000000b4' [Sep 11 14:31:12] DEBUG[7007] chan_sip.c: Hangup call SIP/flowroute-000000b4, SIP callid 44d277ab032e2cbd65a5d3c428c78b10@sip.flowroute.com [Sep 11 14:31:12] DEBUG[7007] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x1f0a558' [Sep 11 14:31:12] DEBUG[7007] netsock2.c: Splitting '216.115.69.144' into... [Sep 11 14:31:12] DEBUG[7007] netsock2.c: ...host '216.115.69.144' and port ''. [Sep 11 14:31:12] DEBUG[7007] chan_sip.c: Trying to put 'BYE sip:140' onto UDP socket destined for 216.115.69.144:5060 [Sep 11 14:31:12] DEBUG[758] manager.c: Examining event: Event: Hangup Privilege: call,all Channel: SIP/flowroute-000000b4 Uniqueid: 1347391825.314 CallerIDNum: 4072674434 CallerIDName: ConnectedLineNum: matt ConnectedLineName: Matt Cause: 16 Cause-txt: Normal Clearing [Sep 11 14:31:12] DEBUG[720] devicestate.c: No provider found, checking channel drivers for SIP - flowroute [Sep 11 14:31:12] DEBUG[720] chan_sip.c: Checking device state for peer flowroute [Sep 11 14:31:12] DEBUG[720] devicestate.c: Changing state for SIP/flowroute - state 1 (Not in use) [Sep 11 14:31:12] DEBUG[720] devicestate.c: device 'SIP/flowroute' state '1' [Sep 11 14:31:12] DEBUG[7007] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Sep 11 14:31:12] DEBUG[7007] pbx.c: Spawn extension (outbound_crm,4072674434,1) exited non-zero on 'Local/4072674434@outbound_crm-8c88;2' [Sep 11 14:31:12] DEBUG[7007] channel.c: Soft-Hanging up channel 'Local/4072674434@outbound_crm-8c88;2' [Sep 11 14:31:12] DEBUG[7007] channel.c: Hanging up channel 'Local/4072674434@outbound_crm-8c88;2' [Sep 11 14:31:12] DEBUG[720] devicestate.c: No provider found, checking channel drivers for Local - 4072674434@outbound_crm [Sep 11 14:31:12] DEBUG[720] chan_local.c: Checking if extension 4072674434@outbound_crm exists (devicestate) [Sep 11 14:31:12] DEBUG[720] devicestate.c: Changing state for Local/4072674434@outbound_crm - state 1 (Not in use) [Sep 11 14:31:12] DEBUG[720] devicestate.c: device 'Local/4072674434@outbound_crm' state '1' [Sep 11 14:31:12] DEBUG[757] app_queue.c: Device 'SIP/flowroute' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 11 14:31:12] DEBUG[757] app_queue.c: Device 'Local/4072674434@outbound_crm' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 11 14:31:12] DEBUG[758] manager.c: Examining event: Event: Dial Privilege: call,all SubEvent: End Channel: Local/4072674434@outbound_crm-8c88;2 UniqueID: 1347391825.313 DialStatus: ANSWER [Sep 11 14:31:12] DEBUG[758] manager.c: Examining event: Event: Hangup Privilege: call,all Channel: Local/4072674434@outbound_crm-8c88;2 Uniqueid: 1347391825.313 CallerIDNum: 123 CallerIDName: ConnectedLineNum: ConnectedLineName: Cause: 16 Cause-txt: Normal Clearing [Sep 11 14:31:12] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:31:12] DEBUG[742] chan_sip.c: = Looking for Call ID: 44d277ab032e2cbd65a5d3c428c78b10@sip.flowroute.com (Checking To) --From tag as1519f496 --To-tag 26061 [Sep 11 14:31:12] DEBUG[742] chan_sip.c: Stopping retransmission on '44d277ab032e2cbd65a5d3c428c78b10@sip.flowroute.com' of Request 104: Match Found [Sep 11 14:31:12] DEBUG[742] chan_sip.c: Destroying SIP dialog 44d277ab032e2cbd65a5d3c428c78b10@sip.flowroute.com [Sep 11 14:31:12] DEBUG[742] rtp_engine.c: Destroyed RTP instance '0x1f0a558' [Sep 11 14:31:12] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:31:12] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:31:12] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:31:13] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:31:13] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:31:14] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:31:14] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:31:14] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:31:14] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:31:15] DEBUG[763] manager.c: Examining event: Event: Unlink Privilege: call,all Channel1: SIP/matt-000000b3 Channel2: Local/4072674434@outbound_crm-8c88;1 Uniqueid1: 1347391842.315 Uniqueid2: 1347391825.312 CallerID1: matt CallerID2: [Sep 11 14:31:15] DEBUG[763] manager.c: Examining event: Event: Hangup Privilege: call,all Channel: Local/4072674434@outbound_crm-8c88;1 Uniqueid: 1347391825.312 CallerIDNum: CallerIDName: ConnectedLineNum: matt ConnectedLineName: Matt Cause: 0 Cause-txt: Unknown [Sep 11 14:31:15] DEBUG[763] manager.c: Examining event: Event: Unlink Privilege: call,all Channel1: Local/4072674434@outbound_crm-8c88;2 Channel2: SIP/flowroute-000000b4 Uniqueid1: 1347391825.313 Uniqueid2: 1347391825.314 CallerID1: 123 CallerID2: 4072674434 [Sep 11 14:31:15] DEBUG[763] manager.c: Examining event: Event: Hangup Privilege: call,all Channel: SIP/matt-000000b3 Uniqueid: 1347391842.315 CallerIDNum: matt CallerIDName: Matt ConnectedLineNum: matt ConnectedLineName: Matt Cause: 0 Cause-txt: Unknown [Sep 11 14:31:15] DEBUG[763] manager.c: Examining event: Event: Hangup Privilege: call,all Channel: SIP/flowroute-000000b4 Uniqueid: 1347391825.314 CallerIDNum: 4072674434 CallerIDName: ConnectedLineNum: matt ConnectedLineName: Matt Cause: 16 Cause-txt: Normal Clearing [Sep 11 14:31:15] DEBUG[763] manager.c: Examining event: Event: Dial Privilege: call,all SubEvent: End Channel: Local/4072674434@outbound_crm-8c88;2 UniqueID: 1347391825.313 DialStatus: ANSWER [Sep 11 14:31:15] DEBUG[763] manager.c: Examining event: Event: Hangup Privilege: call,all Channel: Local/4072674434@outbound_crm-8c88;2 Uniqueid: 1347391825.313 CallerIDNum: 123 CallerIDName: ConnectedLineNum: ConnectedLineName: Cause: 16 Cause-txt: Normal Clearing [Sep 11 14:31:15] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:31:15] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:31:15] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:31:15] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:31:15] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:31:16] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:31:16] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:31:16] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:31:16] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:31:17] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:31:17] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:31:18] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:31:18] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:31:18] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:31:18] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:31:19] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:31:19] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:31:19] DEBUG[763] manager.c: Running action 'Command' [Sep 11 14:31:19] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:31:19] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:31:19] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:31:20] DEBUG[742] chan_sip.c: = Looking for Call ID: 537a377-7909f823-b8f4da7@216.115.69.131 (Checking From) --From tag faadda78 --To-tag [Sep 11 14:31:20] DEBUG[742] acl.c: For destination '216.115.69.144', our source address is '50.22.175.70'. [Sep 11 14:31:20] DEBUG[742] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 50.22.175.70:5060 [Sep 11 14:31:20] DEBUG[742] chan_sip.c: Allocating new SIP dialog for 537a377-7909f823-b8f4da7@216.115.69.131 - OPTIONS (No RTP) [Sep 11 14:31:20] DEBUG[742] chan_sip.c: **** Received OPTIONS (3) - Command in SIP OPTIONS [Sep 11 14:31:20] DEBUG[742] netsock2.c: Splitting '50.22.175.70:5060' into... [Sep 11 14:31:20] DEBUG[742] netsock2.c: ...host '50.22.175.70' and port ''. [Sep 11 14:31:20] DEBUG[742] netsock2.c: Splitting 'invalid' into... [Sep 11 14:31:20] DEBUG[742] netsock2.c: ...host 'invalid' and port ''. [Sep 11 14:31:20] DEBUG[742] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 216.115.69.144:5060 [Sep 11 14:31:20] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:31:20] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:31:20] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf [Sep 11 14:31:21] DEBUG[758] manager.c: Running action 'Status' [Sep 11 14:31:21] DEBUG[758] manager.c: Running action 'CoreShowChannels' [Sep 11 14:31:22] DEBUG[763] app_queue.c: No queue_members defined in config extconfig.conf