1. Another user logs into this conference somehow. Don't think this happened because that conference wasn't INVITEd until 3 minutes later.
2. Emergency logout of the agent. Checked the admin logs and no emergency logout was performed.
3. The call was longer than the recording limit (or 60 minutes). This was not the case for this call. It was about 21 minutes in and our recording limit is 60.
4. The AST_conf_update.pl killed the conference -- maybe???
The relevant part of the Asterisk logs:
- Code: Select all
[Jan 14 09:41:06] VERBOSE[14508] manager.c: [Jan 14 09:41:06] == Manager 'sendcron' logged on from 127.0.0.1
[Jan 14 09:41:06] VERBOSE[14508] manager.c: [Jan 14 09:41:06] == Manager 'sendcron' logged off from 127.0.0.1
[Jan 14 09:41:06] VERBOSE[6809] asterisk.c: [Jan 14 09:41:06] -- Remote UNIX connection
[Jan 14 09:41:06] VERBOSE[14513] asterisk.c: [Jan 14 09:41:06] -- Remote UNIX connection disconnected
[Jan 14 09:41:07] VERBOSE[14551] manager.c: [Jan 14 09:41:07] == Manager 'sendcron' logged on from 127.0.0.1
[Jan 14 09:41:07] VERBOSE[14552] manager.c: [Jan 14 09:41:07] == Manager 'sendcron' logged on from 127.0.0.1
[Jan 14 09:41:07] VERBOSE[14553] pbx.c: [Jan 14 09:41:07] -- Executing [55558600054@default:1] MeetMeAdmin("Local/55558600054@default-000178bb;2", "8600054,K") in new stack
[Jan 14 09:41:07] VERBOSE[14553] pbx.c: [Jan 14 09:41:07] -- Executing [55558600054@default:2] Hangup("Local/55558600054@default-000178bb;2", "") in new stack
[Jan 14 09:41:07] VERBOSE[14553] pbx.c: [Jan 14 09:41:07] == Spawn extension (default, 55558600054, 2) exited non-zero on 'Local/55558600054@default-000178bb;2'
[Jan 14 09:41:07] VERBOSE[14553] pbx.c: [Jan 14 09:41:07] -- Executing [h@default:1] AGI("Local/55558600054@default-000178bb;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----
----------") in new stack
[Jan 14 09:41:07] VERBOSE[12935] file.c: [Jan 14 09:41:07] -- <SIP/bandwidthcom-0000aed5> Playing 'conf-kicked.gsm' (language 'en')
[Jan 14 09:41:07] VERBOSE[14553] res_agi.c: [Jan 14 09:41:07] -- <Local/55558600054@default-000178bb;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------- completed, returning 0
[Jan 14 09:41:07] VERBOSE[12976] file.c: [Jan 14 09:41:07] -- <IAX2/127.0.0.1:40569-6785> Playing 'conf-kicked.gsm' (language 'en')
We can see in the action_full log the following:
- Code: Select all
2015-01-14 9:41:07|995788|0|1|
Action: Hangup
Channel:
|
2015-01-14 9:41:07|995789|0|1|
Action: Originate
Channel: Local/55558600054@default
Context: default
Exten: 8300
Priority: 1
Callerid: ULGH34581421257267
action_process
- Code: Select all
----END NEW COMMAND----
|
2015-01-14 9:40:54|SQL_QUERY|UPDATE vicidial_manager set status='SENT' where man_id='995787'||
2015-01-14 9:41:07|SQL_QUERY|SELECT man_id,uniqueid,entry_date,status,response,server_ip,channel,action,callerid,cmd_line_b,cmd_line_c,cmd_line_d,cmd_line_e,cmd_line_f,cmd_line_g,cmd_line_h,cmd_line_i,cmd_line_j,cmd_line_k FROM vicidial_manager where server_ip = '192.168.0.35' and status = 'QUEUE' order by man_id limit 1||
2015-01-14 9:41:07|2015-01-14 9:41:07|2015-01-14 09:41:07|995788|||Hangup|ULGH34591421257267|
2015-01-14 9:41:07|----BEGIN NEW COMMAND----
CallerID: ULGH34591421257267
Action: Hangup
Channel:
----END NEW COMMAND----
|
2015-01-14 9:41:07|SQL_QUERY|UPDATE vicidial_manager set status='SENT' where man_id='995788'||
2015-01-14 9:41:07|SQL_QUERY|SELECT man_id,uniqueid,entry_date,status,response,server_ip,channel,action,callerid,cmd_line_b,cmd_line_c,cmd_line_d,cmd_line_e,cmd_line_f,cmd_line_g,cmd_line_h,cmd_line_i,cmd_line_j,cmd_line_k FROM vicidial_manager where server_ip = '192.168.0.35' and status = 'QUEUE' order by man_id limit 1||
2015-01-14 9:41:07|2015-01-14 9:41:07|2015-01-14 09:41:07|995789|||Originate|ULGH34581421257267|
2015-01-14 9:41:07|----BEGIN NEW COMMAND----
CallerID: ULGH34581421257267
Action: Originate
Channel: Local/55558600054@default
Context: default
Exten: 8300
Priority: 1
Callerid: ULGH34581421257267
----END NEW COMMAND----
action_send
- Code: Select all
2015-01-14 9:41:07|1|995788|
Action: Hangup
Channel:
2015-01-14 9:41:07|1|995789|
Action: Originate
Channel: Local/55558600054@default
Context: default
Exten: 8300
Priority: 1
Callerid: ULGH34581421257267
Finally, we did a grep on that Callerid within the other logs:
- Code: Select all
action_launch.2015-01-14:2015-01-14 9:41:07|/usr/share/astguiclient/AST_send_action_child.pl --SYSLOG --PATHlogs=%2Fvar%2Flog%2Fastguiclient --telnet_host=localhost --telnet_port=5038 --ASTmgrUSERNAME=cron --ASTmgrSECRET=1234 --ASTmgrUSERNAMEsend=sendcron --man_id=995789 --action=Originate --cmd_line_b=Channel%3A%20Local%2F55558600054%40default --cmd_line_c=Context%3A%20default --cmd_line_d=Exten%3A%208300 --cmd_line_e=Priority%3A%201 --cmd_line_f=Callerid%3A%20ULGH34581421257267 ULGH34581421257267 |
Note it does not appear in the congested:
- Code: Select all
2015-01-15 9:40:01|SUBRT|killing_congest|KC|START||
2015-01-15 9:41:01|SUBRT|killing_congest|KC|START||
We are NOT using the 3way conf update script (AST_conf_update_3way.pl) should we be? Is this the new way to clear the 3 way conferences? It seems like the most likely cause of the issue is that the AST_conf_update is killing the conference but we aren't sure why this would be the case. Neither of the two previously mentioned scripts generates logs so perhaps we'll need to add some logging here to determine what's going on.
Any other thoughts/suggestions?