I have addon the callcenter module, And configured the Queues
with member A1000,0 as Static agents ,and S1001,0 as Dynamic Members. "Ingoing Campaigns" configured, I selected agent 1000 with extension 1000 'log in' to the Callcenter , i clicked "Enter", extension 1000 ring, I pick up the phone 1000. it disconnect immediately. The same as agent 1001 ,Pls help!
Event: Newchannel
Privilege: call,all
Channel: SIP/5080-0000000e
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum: 5080
CallerIDName: 5080
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode:
Context: from-roomx
Exten: s
Priority: 1
Uniqueid: 1524389065.94
Linkedid: 1524389065.94
[2018-04-22 17:24:25] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/5080-0000000e
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum: 5080
CallerIDName: 5080
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode:
Context: from-roomx
Exten: s
Priority: 1
Uniqueid: 1524389065.94
Linkedid: 1524389065.94
Variable: SIPCALLID
Value: 07751e6460acdbc911876acc45ffb803@192.168.2.208:5060
[2018-04-22 17:24:25] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: Newexten
Privilege: call,all
Channel: SIP/5080-0000000e
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum: 5080
CallerIDName: 5080
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode:
Context: from-roomx
Exten:
Priority: 1
Uniqueid: 1524389065.94
Linkedid: 1524389065.94
Extension:
Application: AppDial2
AppData: (Outgoing Line)
[2018-04-22 17:24:25] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: NewCallerid
Privilege: call,all
Channel: SIP/5080-0000000e
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum: 5080
CallerIDName: Agent/50080 Login
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode:
Context: from-roomx
Exten:
Priority: 1
Uniqueid: 1524389065.94
Linkedid: 1524389065.94
CID-CallingPres: 0 (Presentation Allowed, Not Screened)
[2018-04-22 17:24:25] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: NewConnectedLine
Privilege: call,all
Channel: SIP/5080-0000000e
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum: 5080
CallerIDName: Agent/50080 Login
ConnectedLineNum: <unknown>
ConnectedLineName: Agent/50080 Login
Language: en
AccountCode:
Context: from-roomx
Exten:
Priority: 1
Uniqueid: 1524389065.94
Linkedid: 1524389065.94
[2018-04-22 17:24:25] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: DialBegin
Privilege: call,all
DestChannel: SIP/5080-0000000e
DestChannelState: 0
DestChannelStateDesc: Down
DestCallerIDNum: 5080
DestCallerIDName: Agent/50080 Login
DestConnectedLineNum: <unknown>
DestConnectedLineName: Agent/50080 Login
DestLanguage: en
DestAccountCode:
DestContext: from-roomx
DestExten:
DestPriority: 1
DestUniqueid: 1524389065.94
DestLinkedid: 1524389065.94
DialString: 5080
[2018-04-22 17:24:25] DEBUG[2350]: app_queue.c:2332 pending_members_remove: Removed 5080 from pending_members
[2018-04-22 17:24:25] DEBUG[2350]: app_queue.c:2557 extension_state_cb: Extension '5080@ext-local' changed to state '6' (Ringing)
[2018-04-22 17:24:25] DEBUG[2449]: app_queue.c:2485 device_state_cb: Device 'SIP/5080' changed to state '6' (Ringing) but we don't care because they're not a member of any queue.
[2018-04-22 17:24:25] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: ExtensionStatus
Privilege: call,all
Exten: 5080
Context: ext-local
Hint: SIP/5080,CustomPresence:5080
Status: 8
StatusText: Ringing
[2018-04-22 17:24:25] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: DeviceStateChange
Privilege: call,all
Device: SIP/5080
State: RINGING
[2018-04-22 17:24:25] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: QueueMemberStatus
Privilege: agent,all
Queue: 9001
MemberName: 5080
Interface: Agent/5080
StateInterface: hint:5080@ext-local
Membership: static
Penalty: 0
CallsTaken: 0
LastCall: 0
InCall: 0
Status: 6
Paused: 0
PausedReason:
Ringinuse: 1
[2018-04-22 17:24:25] DEBUG[2405]: chan_sip.c:9429 find_call: = Looking for Call ID: 07751e6460acdbc911876acc45ffb803@192.168.2.208:5060 (Checking To) --From tag as6a7f133f --To-tag 7333070a
[2018-04-22 17:24:25] DEBUG[2405]: chan_sip.c:4579 sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '07751e6460acdbc911876acc45ffb803@192.168.2.208:5060' Request 102: Found
[2018-04-22 17:24:25] DEBUG[2405]: chan_sip.c:23619 handle_response_invite: SIP response 180 to standard invite
[2018-04-22 17:24:25] DEBUG[2301]: devicestate.c:369 _ast_device_state: No provider found, checking channel drivers for SIP - 5080
[2018-04-22 17:24:25] DEBUG[2301]: chan_sip.c:30313 sip_devicestate: Checking device state for peer 5080
[2018-04-22 17:24:25] DEBUG[2301]: devicestate.c:474 do_state_change: Changing state for SIP/5080 - state 6 (Ringing)
[2018-04-22 17:24:25] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: Newstate
Privilege: call,all
Channel: SIP/5080-0000000e
ChannelState: 5
ChannelStateDesc: Ringing
CallerIDNum: 5080
CallerIDName: Agent/50080 Login
ConnectedLineNum: <unknown>
ConnectedLineName: Agent/50080 Login
Language: en
AccountCode:
Context: from-roomx
Exten:
Priority: 1
Uniqueid: 1524389065.94
Linkedid: 1524389065.94
-- SIP/5080-0000000e is ringing
[2018-04-22 17:24:27] DEBUG[2427]: res_pjsip_registrar_expire.c:78 check_expiration_thread: Woke up at 1524389067 Interval: 30
[2018-04-22 17:24:27] DEBUG[2427]: res_pjsip_registrar_expire.c:85 check_expiration_thread: Expiring 0 contacts
[2018-04-22 17:24:27] DEBUG[2420]: res_timing_timerfd.c:167 timerfd_timer_ack: Expected to acknowledge 1 ticks but got 33 instead
[2018-04-22 17:24:27] DEBUG[2420]: res_timing_timerfd.c:167 timerfd_timer_ack: Expected to acknowledge 1 ticks but got 2 instead
[2018-04-22 17:24:30] DEBUG[2405]: chan_sip.c:9429 __find_call: = Looking for Call ID: 07751e6460acdbc911876acc45ffb803@192.168.2.208:5060 (Checking To) --From tag as6a7f133f --To-tag 7333070a
[2018-04-22 17:24:30] DEBUG[3624]: res_rtp_asterisk.c:4713 ast_rtcp_interpret: Got RTCP report of 8 bytes from 192.168.2.118:9387
[2018-04-22 17:24:30] DEBUG[3624]: res_rtp_asterisk.c:4713 ast_rtcp_interpret: Got RTCP report of 72 bytes from 192.168.2.118:9387
[2018-04-22 17:24:30] DEBUG[3624]: res_rtp_asterisk.c:4728 ast_rtcp_interpret: 0x7f5548005900 -- RTCP from 192.168.2.118:9387: Failed first packet validity check
[2018-04-22 17:24:30] DEBUG[2442]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '192.168.2.118:9387' into...
[2018-04-22 17:24:30] DEBUG[2442]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '192.168.2.118' and port '9387'.
[2018-04-22 17:24:30] DEBUG[2442]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '127.0.0.1:13251' into...
[2018-04-22 17:24:30] DEBUG[2442]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '127.0.0.1' and port '13251'.
[2018-04-22 17:24:30] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: RTCPReceived
Privilege: reporting,all
Channel: SIP/5080-0000000e
ChannelState: 5
ChannelStateDesc: Ringing
CallerIDNum: 5080
CallerIDName: Agent/50080 Login
ConnectedLineNum: <unknown>
ConnectedLineName: Agent/50080 Login
Language: en
AccountCode:
Context: from-roomx
Exten:
Priority: 1
Uniqueid: 1524389065.94
Linkedid: 1524389065.94
To: 127.0.0.1:13251
From: 192.168.2.118:9387
RTT: 0.0000
SSRC: 0x4766821d
PT: 201(RR)
ReportCount: 0
[2018-04-22 17:24:30] DEBUG[2405]: chan_sip.c:4522 sip_ack: Acked pending invite 102
[2018-04-22 17:24:30] DEBUG[2405]: chan_sip.c:4538 sip_ack: Stopping retransmission on '07751e6460acdbc911876acc45ffb803@192.168.2.208:5060' of Request 102: Match Found
[2018-04-22 17:24:30] DEBUG[2405]: chan_sip.c:23619 handle_response_invite: SIP response 200 to standard invite
[2018-04-22 17:24:30] DEBUG[2405]: chan_sip.c:10339 process_sdp: Processing session-level SDP v=0... UNSUPPORTED OR FAILED.
[2018-04-22 17:24:30] DEBUG[2405]: chan_sip.c:10339 process_sdp: Processing session-level SDP o=- 97131245 97131252 IN IP4 192.168.2.118... OK.
[2018-04-22 17:24:30] DEBUG[2405]: chan_sip.c:10339 process_sdp: Processing session-level SDP s=eyeBeam... UNSUPPORTED OR FAILED.
[2018-04-22 17:24:30] DEBUG[2405]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '192.168.2.118' into...
[2018-04-22 17:24:30] DEBUG[2405]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '192.168.2.118' and port ''.
[2018-04-22 17:24:30] DEBUG[2405]: chan_sip.c:10339 process_sdp: Processing session-level SDP c=IN IP4 192.168.2.118... OK.
[2018-04-22 17:24:30] DEBUG[2405]: chan_sip.c:10339 process_sdp: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED.
[2018-04-22 17:24:30] DEBUG[2405]: rtp_engine.c:763 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 8 based on m type on 0x7f54f3b61110
[2018-04-22 17:24:30] DEBUG[2405]: rtp_engine.c:763 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 0 based on m type on 0x7f54f3b61110
[2018-04-22 17:24:30] DEBUG[2405]: rtp_engine.c:763 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 3 based on m type on 0x7f54f3b61110
[2018-04-22 17:24:30] DEBUG[2405]: rtp_engine.c:763 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 101 based on m type on 0x7f54f3b61110
[2018-04-22 17:24:30] DEBUG[2405]: chan_sip.c:10802 process_sdp: Processing media-level (audio) SDP a=alt:1 1 : 9224835F 3DAD1BD9 192.168.2.118 9386... UNSUPPORTED OR FAILED.
[2018-04-22 17:24:30] DEBUG[2405]: chan_sip.c:10802 process_sdp: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED.
[2018-04-22 17:24:30] DEBUG[2405]: chan_sip.c:10802 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK.
[2018-04-22 17:24:30] DEBUG[2405]: chan_sip.c:10802 process_sdp: Processing media-level (audio) SDP a=sendrecv... OK.
[2018-04-22 17:24:30] DEBUG[2405]: res_rtp_asterisk.c:981 ast_rtp_ice_set_role: Set role to CONTROLLING (0x7f55480041f0)
[2018-04-22 17:24:30] DEBUG[2405]: res_rtp_asterisk.c:984 ast_rtp_ice_set_role: Set role failed; no ice instance (0x7f55480041f0)
[2018-04-22 17:24:30] DEBUG[2405]: acl.c:957 ast_ouraddrfor: For destination '192.168.2.118', our source address is '192.168.2.208'.
[2018-04-22 17:24:30] DEBUG[2405]: res_rtp_asterisk.c:5933 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7f55480041f0'
> 0x7f5548005900 -- Strict RTP learning after remote address set to: 192.168.2.118:9386
[2018-04-22 17:24:30] DEBUG[2405]: rtp_engine.c:730 ast_rtp_codecs_payloads_copy: Copying payload 0 (0x15c80a8) from 0x7f54f3b61110 to 0x7f55480043b8
[2018-04-22 17:24:30] DEBUG[2405]: rtp_engine.c:730 ast_rtp_codecs_payloads_copy: Copying payload 3 (0x15c8458) from 0x7f54f3b61110 to 0x7f55480043b8
[2018-04-22 17:24:30] DEBUG[2405]: rtp_engine.c:730 ast_rtp_codecs_payloads_copy: Copying payload 8 (0x15c8418) from 0x7f54f3b61110 to 0x7f55480043b8
[2018-04-22 17:24:30] DEBUG[2405]: rtp_engine.c:730 ast_rtp_codecs_payloads_copy: Copying payload 101 (0x7f5550008178) from 0x7f54f3b61110 to 0x7f55480043b8
[2018-04-22 17:24:30] DEBUG[2405]: res_rtp_asterisk.c:5767 ast_rtp_prop_set: Ignoring duplicate RTCP property on RTP instance '0x7f55480041f0'
[2018-04-22 17:24:30] DEBUG[2405]: chan_sip.c:11097 process_sdp: We're settling with these formats: (alaw|gsm|ulaw)
[2018-04-22 17:24:30] DEBUG[2405]: chan_sip.c:11104 process_sdp: We have an owner, now see if we need to change this call
[2018-04-22 17:24:30] DEBUG[2405]: chan_sip.c:6768 update_call_counter: Updating call counter for outgoing call
[2018-04-22 17:24:30] DEBUG[2405]: chan_sip.c:3754 __sip_xmit: Trying to put 'ACK sip:508' onto UDP socket destined for 192.168.2.118:9373
[2018-04-22 17:24:30] DEBUG[2301]: devicestate.c:369 _ast_device_state: No provider found, checking channel drivers for SIP - 5080
[2018-04-22 17:24:30] DEBUG[2301]: chan_sip.c:30313 sip_devicestate: Checking device state for peer 5080
[2018-04-22 17:24:30] DEBUG[2301]: devicestate.c:474 do_state_change: Changing state for SIP/5080 - state 2 (In use)
[2018-04-22 17:24:30] DEBUG[2350]: app_queue.c:2332 pending_members_remove: Removed 5080 from pending_members
[2018-04-22 17:24:30] DEBUG[2350]: app_queue.c:2557 extension_state_cb: Extension '5080@ext-local' changed to state '2' (In use)
[2018-04-22 17:24:30] DEBUG[2449]: app_queue.c:2485 device_state_cb: Device 'SIP/5080' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[2018-04-22 17:24:30] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: ExtensionStatus
Privilege: call,all
Exten: 5080
Context: ext-local
Hint: SIP/5080,CustomPresence:5080
Status: 1
StatusText: InUse
[2018-04-22 17:24:30] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: DeviceStateChange
Privilege: call,all
Device: SIP/5080
State: INUSE
[2018-04-22 17:24:30] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: QueueMemberStatus
Privilege: agent,all
Queue: 9001
MemberName: 5080
Interface: Agent/5080
StateInterface: hint:5080@ext-local
Membership: static
Penalty: 0
CallsTaken: 0
LastCall: 0
InCall: 0
Status: 2
Paused: 0
PausedReason:
Ringinuse: 1
-- SIP/5080-0000000e answered
[2018-04-22 17:24:30] WARNING[3624]: pbx.c:7515 pbx_outgoing_exec: No such application 'AgentLogin'
[2018-04-22 17:24:30] DEBUG[2353]: cel_radius.c:199 radius_log: Unable to create RADIUS record. CEL not recorded!
[2018-04-22 17:24:31] DEBUG[2301]: devicestate.c:369 _ast_device_state: No provider found, checking channel drivers for SIP - 5080
[2018-04-22 17:24:31] DEBUG[2301]: chan_sip.c:30313 sip_devicestate: Checking device state for peer 5080
[2018-04-22 17:24:31] DEBUG[2301]: devicestate.c:474 do_state_change: Changing state for SIP/5080 - state 2 (In use)
[2018-04-22 17:24:31] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: Newstate
Privilege: call,all
Channel: SIP/5080-0000000e
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 5080
CallerIDName: Agent/50080 Login
ConnectedLineNum: <unknown>
ConnectedLineName: Agent/50080 Login
Language: en
AccountCode:
Context: from-roomx
Exten:
Priority: 1
Uniqueid: 1524389065.94
Linkedid: 1524389065.94
[2018-04-22 17:24:31] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: DialEnd
Privilege: call,all
DestChannel: SIP/5080-0000000e
DestChannelState: 6
DestChannelStateDesc: Up
DestCallerIDNum: 5080
DestCallerIDName: Agent/50080 Login
DestConnectedLineNum: <unknown>
DestConnectedLineName: Agent/50080 Login
DestLanguage: en
DestAccountCode:
DestContext: from-roomx
DestExten:
DestPriority: 1
DestUniqueid: 1524389065.94
DestLinkedid: 1524389065.94
DialStatus: ANSWER
[2018-04-22 17:24:31] DEBUG[3623]: channel.c:2681 ast_hangup: Channel 0x7f554800bad0 'SIP/5080-0000000e' hanging up. Refs: 3
[2018-04-22 17:24:31] DEBUG[3623]: chan_sip.c:7155 sip_hangup: Hangup call SIP/5080-0000000e, SIP callid 07751e6460acdbc911876acc45ffb803@192.168.2.208:5060
[2018-04-22 17:24:31] DEBUG[3623]: chan_sip.c:6768 update_call_counter: Updating call counter for outgoing call
[2018-04-22 17:24:31] DEBUG[3623]: chan_sip.c:3754 sip_xmit: Trying to put 'BYE sip:508' onto UDP socket destined for 192.168.2.118:9373
[2018-04-22 17:24:31] DEBUG[3623]: channel.c:2233 ast_channel_destructor: Channel 0x7f554800bad0 'SIP/5080-0000000e' destroying
[2018-04-22 17:24:31] DEBUG[2301]: devicestate.c:369 ast_device_state: No provider found, checking channel drivers for SIP - 5080
[2018-04-22 17:24:31] DEBUG[2301]: chan_sip.c:30313 sip_devicestate: Checking device state for peer 5080
[2018-04-22 17:24:31] DEBUG[2301]: devicestate.c:474 do_state_change: Changing state for SIP/5080 - state 1 (Not in use)
[2018-04-22 17:24:31] DEBUG[2301]: devicestate.c:369 ast_device_state: No provider found, checking channel drivers for SIP - 5080
[2018-04-22 17:24:31] DEBUG[2301]: chan_sip.c:30313 sip_devicestate: Checking device state for peer 5080
[2018-04-22 17:24:31] DEBUG[2301]: devicestate.c:474 do_state_change: Changing state for SIP/5080 - state 1 (Not in use)
[2018-04-22 17:24:31] DEBUG[2348]: cdr.c:1289 cdr_object_finalize: Finalized CDR for SIP/5080-0000000e - start 1524389065.574373 answer 1524389070.691161 end 1524389071.074155 dispo ANSWERED
[2018-04-22 17:24:31] DEBUG[2348]: cdr_radius.c:222 radius_log: Unable to create RADIUS record. CDR not recorded!
[2018-04-22 17:24:31] DEBUG[2420]: res_timing_timerfd.c:167 timerfd_timer_ack: Expected to acknowledge 1 ticks but got 19 instead
[2018-04-22 17:24:31] DEBUG[2353]: cel_radius.c:199 radius_log: Unable to create RADIUS record. CEL not recorded!
[2018-04-22 17:24:31] DEBUG[2353]: cel_radius.c:199 radius_log: Unable to create RADIUS record. CEL not recorded!
[2018-04-22 17:24:31] DEBUG[2353]: cel_radius.c:199 radius_log: Unable to create RADIUS record. CEL not recorded!
[2018-04-22 17:24:31] DEBUG[2405]: chan_sip.c:9429 find_call: = Looking for Call ID: 07751e6460acdbc911876acc45ffb803@192.168.2.208:5060 (Checking To) --From tag as6a7f133f --To-tag 7333070a
[2018-04-22 17:24:31] DEBUG[2405]: chan_sip.c:4538 __sip_ack: Stopping retransmission on '07751e6460acdbc911876acc45ffb803@192.168.2.208:5060' of Request 103: Match Found
[2018-04-22 17:24:31] DEBUG[2405]: chan_sip.c:6590 sip_pvt_dtor: Destroying SIP dialog 07751e6460acdbc911876acc45ffb803@192.168.2.208:5060
[2018-04-22 17:24:31] DEBUG[2405]: rtp_engine.c:402 instance_destructor: Destroyed RTP instance '0x7f55480041f0'
[2018-04-22 17:24:31] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: OriginateResponse
Privilege: call,all
ActionID: ECCP:1.0:3261:AgentLogin:Agent/50080
Response: Success
Channel: SIP/5080-0000000e
Application: AgentLogin
Data: 50080
Reason: 4
Uniqueid: 1524389065.94
CallerIDNum: <unknown>
CallerIDName: Agent/50080 Login
[2018-04-22 17:24:31] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/5080-0000000e
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 5080
CallerIDName: Agent/50080 Login
ConnectedLineNum: <unknown>
ConnectedLineName: Agent/50080 Login
Language: en
AccountCode:
Context: from-roomx
Exten:
Priority: 1
Uniqueid: 1524389065.94
Linkedid: 1524389065.94
Variable: RTPAUDIOQOS
Value: ssrc=767821608;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000
[2018-04-22 17:24:31] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/5080-0000000e
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 5080
CallerIDName: Agent/50080 Login
ConnectedLineNum: <unknown>
ConnectedLineName: Agent/50080 Login
Language: en
AccountCode:
Context: from-roomx
Exten:
Priority: 1
Uniqueid: 1524389065.94
Linkedid: 1524389065.94
Variable: RTPAUDIOQOSJITTER
Value: minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;
[2018-04-22 17:24:31] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/5080-0000000e
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 5080
CallerIDName: Agent/50080 Login
ConnectedLineNum: <unknown>
ConnectedLineName: Agent/50080 Login
Language: en
AccountCode:
Context: from-roomx
Exten:
Priority: 1
Uniqueid: 1524389065.94
Linkedid: 1524389065.94
Variable: RTPAUDIOQOSLOSS
Value: minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;
[2018-04-22 17:24:31] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/5080-0000000e
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 5080
CallerIDName: Agent/50080 Login
ConnectedLineNum: <unknown>
ConnectedLineName: Agent/50080 Login
Language: en
AccountCode:
Context: from-roomx
Exten:
Priority: 1
Uniqueid: 1524389065.94
Linkedid: 1524389065.94
Variable: RTPAUDIOQOSRTT
Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;
[2018-04-22 17:24:31] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/5080-0000000e
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 5080
CallerIDName: Agent/50080 Login
ConnectedLineNum: <unknown>
ConnectedLineName: Agent/50080 Login
Language: en
AccountCode:
Context: from-roomx
Exten:
Priority: 1
Uniqueid: 1524389065.94
Linkedid: 1524389065.94
Variable: RTPAUDIOQOS
Value: ssrc=767821608;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000
[2018-04-22 17:24:31] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: Hangup
Privilege: call,all
Channel: SIP/5080-0000000e
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 5080
CallerIDName: Agent/50080 Login
ConnectedLineNum: <unknown>
ConnectedLineName: Agent/50080 Login
Language: en
AccountCode:
Context: from-roomx
Exten:
Priority: 1
Uniqueid: 1524389065.94
Linkedid: 1524389065.94
Cause: 16
Cause-txt: Normal Clearing
[2018-04-22 17:24:31] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: DeviceStateChange
Privilege: call,all
Device: SIP/5080
State: NOT_INUSE
[2018-04-22 17:24:31] DEBUG[2350]: app_queue.c:2332 pending_members_remove: Removed 5080 from pending_members
[2018-04-22 17:24:31] DEBUG[2350]: app_queue.c:2557 extension_state_cb: Extension '5080@ext-local' changed to state '1' (Not in use)
[2018-04-22 17:24:31] DEBUG[2449]: app_queue.c:2485 device_state_cb: Device 'SIP/5080' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[2018-04-22 17:24:31] DEBUG[2348]: res_odbc.c:865 _ast_odbc_request_obj2: Reusing ODBC handle 0x7f552c7a86f0 from class 'asteriskcdrdb'
[2018-04-22 17:24:31] DEBUG[2348]: cdr_adaptive_odbc.c:740 odbc_log: Executing [INSERT INTO cdr (calldate,clid,src,dcontext,channel,lastapp,lastdata,duration,billsec,disposition,amaflags,uniqueid) VALUES ({ ts '2018-04-22 17:24:25' },'"Agent/50080 Login" <5080>','5080','from-roomx','SIP/5080-0000000e','AppDial2','(Outgoing Line)',5,0,'ANSWERED',3,'1524389065.94')]
[2018-04-22 17:24:31] DEBUG[2348]: res_odbc.c:714 ast_odbc_release_obj: Releasing ODBC handle 0x7f552c7a86f0 into pool
[2018-04-22 17:24:31] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: ExtensionStatus
Privilege: call,all
Exten: 5080
Context: ext-local
Hint: SIP/5080,CustomPresence:5080
Status: 0
StatusText: Idle
[2018-04-22 17:24:31] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: QueueMemberStatus
Privilege: agent,all
Queue: 9001
MemberName: 5080
Interface: Agent/5080
StateInterface: hint:5080@ext-local
Membership: static
Penalty: 0
CallsTaken: 0
LastCall: 0
InCall: 0
Status: 1
Paused: 0
PausedReason:
Ringinuse: 1
[2018-04-22 17:24:40] DEBUG[2420]: res_timing_timerfd.c:167 timerfd_timer_ack: Expected to acknowledge 1 ticks but got 37 instead
[2018-04-22 17:24:44] DEBUG[2405]: chan_sip.c:4362 sip_autodestruct: Auto destroying SIP dialog 'SPSYCVh3dQrCUtqkSQVH5g..'
[2018-04-22 17:24:44] DEBUG[2405]: chan_sip.c:6590 sip_pvt_dtor: Destroying SIP dialog SPSYCVh3dQrCUtqkSQVH5g..
[2018-04-22 17:24:51] DEBUG[3615]: threadpool.c:1137 worker_idle: Worker thread idle timeout reached. Dying.
[2018-04-22 17:24:51] DEBUG[2285]: threadpool.c:996 worker_thread_destroy: Destroying worker thread 102
[2018-04-22 17:24:57] DEBUG[2427]: res_pjsip_registrar_expire.c:78 check_expiration_thread: Woke up at 1524389097 Interval: 30
[2018-04-22 17:24:57] DEBUG[2427]: res_pjsip_registrar_expire.c:85 check_expiration_thread: Expiring 0 contacts
-- Remote UNIX connection
-- Remote UNIX connection disconnected
[2018-04-22 17:25:06] DEBUG[2405]: chan_sip.c:9429 find_call: = Looking for Call ID: SPSYCVh3dQrCUtqkSQVH5g.. (Checking From) --From tag 99b49769 --To-tag
[2018-04-22 17:25:06] DEBUG[2405]: acl.c:957 ast_ouraddrfor: For destination '192.168.2.108', our source address is '192.168.2.208'.
[2018-04-22 17:25:06] DEBUG[2405]: chan_sip.c:3911 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 192.168.2.208:5060
[2018-04-22 17:25:06] DEBUG[2405]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '192.168.2.108:44908' into...
[2018-04-22 17:25:06] DEBUG[2405]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '192.168.2.108' and port '44908'.
[2018-04-22 17:25:06] DEBUG[2405]: chan_sip.c:9016 sip_alloc: Allocating new SIP dialog for SPSYCVh3dQrCUtqkSQVH5g.. - REGISTER (No RTP)
[2018-04-22 17:25:06] DEBUG[2405]: chan_sip.c:28776 handle_incoming: * Received REGISTER (2) - Command in SIP REGISTER
[2018-04-22 17:25:06] DEBUG[2405]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '192.168.2.108:44908' into...
[2018-04-22 17:25:06] DEBUG[2405]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '192.168.2.108' and port '44908'.
[2018-04-22 17:25:06] DEBUG[2405]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '192.168.2.208' into...
[2018-04-22 17:25:06] DEBUG[2405]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '192.168.2.208' and port ''.
[2018-04-22 17:25:06] DEBUG[2405]: chan_sip.c:3754 sip_xmit: Trying to put 'SIP/2.0 401' onto UDP socket destined for 192.168.2.108:44908
[2018-04-22 17:25:06] DEBUG[2405]: chan_sip.c:9429 find_call: = Looking for Call ID: SPSYCVh3dQrCUtqkSQVH5g.. (Checking From) --From tag 99b49769 --To-tag
[2018-04-22 17:25:06] DEBUG[2405]: chan_sip.c:28776 handle_incoming: * Received REGISTER (2) - Command in SIP REGISTER
[2018-04-22 17:25:06] DEBUG[2405]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '192.168.2.108:44908' into...
[2018-04-22 17:25:06] DEBUG[2405]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '192.168.2.108' and port '44908'.
[2018-04-22 17:25:06] DEBUG[2405]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '192.168.2.208' into...
[2018-04-22 17:25:06] DEBUG[2405]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '192.168.2.208' and port ''.
[2018-04-22 17:25:06] DEBUG[2405]: chan_sip.c:16906 parse_register_contact: Store REGISTER's src-IP:port for call routing.
[2018-04-22 17:25:06] DEBUG[2405]: chan_sip.c:17070 build_path: build_path: do not use Path headers
[2018-04-22 17:25:06] DEBUG[2405]: chan_sip.c:9016 sip_alloc: Allocating new SIP dialog for 667a0b41344cf7727b2ac86135a66572@127.0.0.1:5060 - OPTIONS (No RTP)
[2018-04-22 17:25:06] DEBUG[2405]: acl.c:957 ast_ouraddrfor: For destination '192.168.2.108', our source address is '192.168.2.208'.
[2018-04-22 17:25:06] DEBUG[2405]: chan_sip.c:3911 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 192.168.2.208:5060
[2018-04-22 17:25:06] DEBUG[2405]: chan_sip.c:8801 change_callid_pvt: SIP call-id changed from '667a0b41344cf7727b2ac86135a66572@127.0.0.1:5060' to '5cae19ee290a631740f1b3f100bd1f15@192.168.2.208:5060'
[2018-04-22 17:25:06] DEBUG[2405]: chan_sip.c:3397 initialize_initreq: Initializing initreq for method OPTIONS - callid 5cae19ee290a631740f1b3f100bd1f15@192.168.2.208:5060
[2018-04-22 17:25:06] DEBUG[2405]: chan_sip.c:3754 sip_xmit: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.2.108:44908
[2018-04-22 17:25:06] DEBUG[2405]: chan_sip.c:3754 sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.2.108:44908
[2018-04-22 17:25:06] DEBUG[2405]: chan_sip.c:9016 sip_alloc: Allocating new SIP dialog for 0c8aa7bb5cf802df3d8b4c610014c248@127.0.0.1:5060 - NOTIFY (No RTP)
[2018-04-22 17:25:06] DEBUG[2405]: acl.c:957 ast_ouraddrfor: For destination '192.168.2.108', our source address is '192.168.2.208'.
[2018-04-22 17:25:06] DEBUG[2405]: chan_sip.c:3911 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 192.168.2.208:5060
[2018-04-22 17:25:06] DEBUG[2405]: chan_sip.c:8801 change_callid_pvt: SIP call-id changed from '0c8aa7bb5cf802df3d8b4c610014c248@127.0.0.1:5060' to '006b457f79ea43056365b99d21299faf@192.168.2.208:5060'
[2018-04-22 17:25:06] DEBUG[2405]: chan_sip.c:3397 initialize_initreq: Initializing initreq for method NOTIFY - callid 006b457f79ea43056365b99d21299faf@192.168.2.208:5060
[2018-04-22 17:25:06] DEBUG[2405]: chan_sip.c:3754 sip_xmit: Trying to put 'NOTIFY sip:' onto UDP socket destined for 192.168.2.108:44908
[2018-04-22 17:25:06] DEBUG[2285]: threadpool.c:517 grow: Increasing threadpool stasis-core's size by 1
[2018-04-22 17:25:06] DEBUG[2301]: devicestate.c:369 _ast_device_state: No provider found, checking channel drivers for SIP - 5088
[2018-04-22 17:25:06] DEBUG[2301]: chan_sip.c:30313 sip_devicestate: Checking device state for peer 5088
[2018-04-22 17:25:06] DEBUG[2301]: devicestate.c:474 do_state_change: Changing state for SIP/5088 - state 1 (Not in use)
[2018-04-22 17:25:06] DEBUG[3264]: manager.c:5927 match_filter: Examining AMI event:
Event: PeerStatus
Privilege: system,all
ChannelType: SIP
Peer: SIP/5088
PeerStatus: Registered
Address: 192.168.2.108:44908
[2018-04-22 17:25:07] DEBUG[2420]: res_timing_timerfd.c:167 timerfd_timer_ack: Expected to acknowledge 1 ticks but got 49 instead
[2018-04-22 17:25:07] DEBUG[2405]: chan_sip.c:9429 find_call: = Looking for Call ID: 5cae19ee290a631740f1b3f100bd1f15@192.168.2.208:5060 (Checking To) --From tag as3da09a40 --To-tag 5331987f
[2018-04-22 17:25:07] DEBUG[2405]: chan_sip.c:4538 sip_ack: Stopping retransmission on '5cae19ee290a631740f1b3f100bd1f15@192.168.2.208:5060' of Request 102: Match Found
[2018-04-22 17:25:07] DEBUG[2405]: chan_sip.c:4035 retrans_pkt: SIP timers: Rescheduling retransmission 2 to 200 ms (t1 100 ms (Retrans id #21))
[2018-04-22 17:25:07] DEBUG[2405]: chan_sip.c:3754 sip_xmit: Trying to put 'NOTIFY sip:' onto UDP socket destined for 192.168.2.108:44908
[2018-04-22 17:25:07] DEBUG[2405]: chan_sip.c:4035 retrans_pkt: SIP timers: Rescheduling retransmission 3 to 400 ms (t1 100 ms (Retrans id #21))
[2018-04-22 17:25:07] DEBUG[2405]: chan_sip.c:3754 sip_xmit: Trying to put 'NOTIFY sip:' onto UDP socket destined for 192.168.2.108:44908
[2018-04-22 17:25:07] DEBUG[2405]: chan_sip.c:9429 find_call: = Looking for Call ID: 006b457f79ea43056365b99d21299faf@192.168.2.208:5060 (Checking To) --From tag as19f5c6b8 --To-tag 58926641
[2018-04-22 17:25:07] DEBUG[2405]: chan_sip.c:4538 sip_ack: Stopping retransmission on '006b457f79ea43056365b99d21299faf@192.168.2.208:5060' of Request 102: Match Found
[2018-04-22 17:25:07] DEBUG[2405]: chan_sip.c:24173 handle_response_notify: Got 200 accepted on NOTIFY 006b457f79ea43056365b99d21299faf@192.168.2.208:5060
[2018-04-22 17:25:07] DEBUG[2405]: chan_sip.c:6590 sip_pvt_dtor: Destroying SIP dialog 5cae19ee290a631740f1b3f100bd1f15@192.168.2.208:5060
[2018-04-22 17:25:07] DEBUG[2405]: chan_sip.c:6590 sip_pvt_dtor: Destroying SIP dialog 006b457f79ea43056365b99d21299faf@192.168.2.208:5060
[2018-04-22 17:25:08] DEBUG[2405]: chan_sip.c:9429 find_call: = Looking for Call ID: 006b457f79ea43056365b99d21299faf@192.168.2.208:5060 (Checking To) --From tag as19f5c6b8 --To-tag 58926641
[2018-04-22 17:25:08] DEBUG[2405]: chan_sip.c:9601 find_call: That's odd... Got a response on a call we don't know about. Callid 006b457f79ea43056365b99d21299faf@192.168.2.208:5060
[2018-04-22 17:25:08] DEBUG[2405]: chan_sip.c:29052 handle_request_do: Invalid SIP message - rejected , no callid, len 392
[2018-04-22 17:25:08] DEBUG[2405]: chan_sip.c:9429 find_call: = Looking for Call ID: 006b457f79ea43056365b99d21299faf@192.168.2.208:5060 (Checking To) --From tag as19f5c6b8 --To-tag 58926641
[2018-04-22 17:25:08] DEBUG[2405]: chan_sip.c:9601 find_call: That's odd... Got a response on a call we don't know about. Callid 006b457f79ea43056365b99d21299faf@192.168.2.208:5060
[2018-04-22 17:25:08] DEBUG[2405]: chan_sip.c:29052 handle_request_do: Invalid SIP message - rejected , no callid, len 392
issabel*CLI> quit