QueueMetrics forum

QueueMetrics => Running QueueMetrics => Topic started by: gopal2k on August 30, 2013, 20:22:52

Title: Call Status
Post by: gopal2k on August 30, 2013, 20:22:52: Hi,

I have a working Queue metrics where my data is stored in MySQL DB, Now we have a report of caller disconnection and agent disconnection. But for some entries i see that both COMPLETEAGENT and COMPLETECALLER presents. It supposed to be either agent disconnect has to update or caller disconnect has to update. Because of this our reporting is not correct.

what could be the scenario that these both fields will get stored in Queuemetrics.

Regards,
Gopal.
Title: Re: Call Status
Post by: QueueMetrics on September 02, 2013, 10:32:00: We would expect only one call closure record to appear for each call - can you post an example?
Title: Re: Call Status
Post by: gopal2k on September 02, 2013, 18:19:39: Our database in Queuelog has this,

mysql> select * from queue_log where call_id = '1376084184.1515690'; +-----------+---------------------+------------+--------------------+-----------+-----------+----------------+-------+--------------------+-------+-------+-------+----------+------------------+
| partition | EntryTime | time_id | call_id | queue | agent | verb | data1 | data2 | data3 | data4 | data5 | serverid | unique_row_count |
+-----------+---------------------+------------+--------------------+-----------+-----------+----------------+-------+--------------------+-------+-------+-------+----------+------------------+
| P001 | 2013-08-09 14:43:59 | 1376084191 | 1376084184.1515690 | project | SIP/10821 | COMPLETEAGENT | 0 | 5 | | | | | 1 |
| P001 | 2013-08-09 14:44:08 | 1376084647 | 1376084184.1515690 | project | SIP/10821 | COMPLETECALLER | 0 | 461 | 1 | | | | 2 |
| P001 | 2013-08-09 14:36:26 | 1376084186 | 1376084184.1515690 | project | SIP/10821 | CONNECT | 0 | 1376084186.1515691 | 0 | | | | 2 |
| P001 | 2013-08-09 14:36:26 | 1376084186 | 1376084184.1515690 | project | NONE | ENTERQUEUE | | anonymous | 1 | | | | 1 |
+-----------+---------------------+------------+--------------------+-----------+-----------+----------------+-------+--------------------+-------+-------+-------+----------+------------------+
4 rows in set (0.06 sec)

In the queue_log file all we have is only this,
1376084186|1376084184.1515690|project|NONE|ENTERQUEUE||anonymous|1
1376084186|1376084184.1515690|project|SIP/10821|CONNECT|0|1376084186.1515691|0
1376084647|1376084184.1515690|project|SIP/10821|COMPLETECALLER|0|461|1
Title: Re: Call Status
Post by: gopal2k on September 04, 2013, 21:48:29: Any updates would be much appreciated.

Regardd,
Gopal
Title: Re: Call Status
Post by: QueueMetrics on September 06, 2013, 15:31:29: The queue_log is correct but the datatabase has one log line too many: Do you use qloader to upload data to the database?
l.

Quote from: gopal2k on September 02, 2013, 18:19:39
Our database in Queuelog has this,

mysql> select * from queue_log where call_id = '1376084184.1515690'; +-----------+---------------------+------------+--------------------+-----------+-----------+----------------+-------+--------------------+-------+-------+-------+----------+------------------+
| partition | EntryTime | time_id | call_id | queue | agent | verb | data1 | data2 | data3 | data4 | data5 | serverid | unique_row_count |
+-----------+---------------------+------------+--------------------+-----------+-----------+----------------+-------+--------------------+-------+-------+-------+----------+------------------+
| P001 | 2013-08-09 14:43:59 | 1376084191 | 1376084184.1515690 | project | SIP/10821 | COMPLETEAGENT | 0 | 5 | | | | | 1 |
| P001 | 2013-08-09 14:44:08 | 1376084647 | 1376084184.1515690 | project | SIP/10821 | COMPLETECALLER | 0 | 461 | 1 | | | | 2 |
| P001 | 2013-08-09 14:36:26 | 1376084186 | 1376084184.1515690 | project | SIP/10821 | CONNECT | 0 | 1376084186.1515691 | 0 | | | | 2 |
| P001 | 2013-08-09 14:36:26 | 1376084186 | 1376084184.1515690 | project | NONE | ENTERQUEUE | | anonymous | 1 | | | | 1 |
+-----------+---------------------+------------+--------------------+-----------+-----------+----------------+-------+--------------------+-------+-------+-------+----------+------------------+
4 rows in set (0.06 sec)

In the queue_log file all we have is only this,
1376084186|1376084184.1515690|project|NONE|ENTERQUEUE||anonymous|1
1376084186|1376084184.1515690|project|SIP/10821|CONNECT|0|1376084186.1515691|0
1376084647|1376084184.1515690|project|SIP/10821|COMPLETECALLER|0|461|1
Title: Re: Call Status
Post by: gopal2k on September 07, 2013, 04:04:51: yes we are using qloader to upload to database....

Regards,
Gopal
Title: Re: Call Status
Post by: QueueMetrics on September 09, 2013, 10:29:10: This is weird as qloaderd does not create new lines but only inserts existing ones... does this happen all of the time?
Title: Re: Call Status
Post by: gopal2k on September 09, 2013, 16:23:38: yes... it happens for some records, we took some output for 6 days, around 1500 record was there in that the duplicate is for around 13 records.

Basically when the COMPLETEAGENT will get updated?

What does this mean?

Regards,
Gopal.
Title: Re: Call Status
Post by: QueueMetrics on September 10, 2013, 12:17:45: This is a good question - a call is supposed to have either a COMPLETEAGENT or a COMPLETECALLER but not both. If both appear, it is a bug in Asterisk :)
Title: Re: Call Status
Post by: gopal2k on September 10, 2013, 13:28:28: If it is bug in the Asterisk, then queue_log file also need to have both COMPLETEAGENT and COMPLETECALLER if am not wrong.

This is happening only in database, and database is populated via qloaderd application.

Please correct me if am wrong.

Regards,
gopal.
Title: Re: Call Status
Post by: QueueMetrics on September 11, 2013, 13:44:03: Yes the database is populated via qloaderd (I guess) but qloaderd does not create records. So I guess they come from somewhere else.....
Title: Re: Call Status
Post by: gopal2k on October 11, 2013, 20:53:36: Hi,

We explored little bit and found Asterisk is populating data correctly. For example, a particular record is updated in CEL table, where CEL table has detailed information about a call.

Let's consider the following example from queue_log table,
mysql> select * from queue_log where call_id ='1375644053.1307271';
+-----------+---------------------+------------+--------------------+-----------+-----------+----------------+-------+--------------------+-------+-------+-------+----------+------------------+
| partition | EntryTime | time_id | call_id | queue | agent | verb | data1 | data2 | data3 | data4 | data5 | serverid | unique_row_count |
+-----------+---------------------+------------+--------------------+-----------+-----------+----------------+-------+--------------------+-------+-------+-------+----------+------------------+
| P001 | 2013-08-04 12:38:06 | 1375645085 | 1375644053.1307271 | NONE | SIP/10857 | CALLSTATUS | dc | | | | | | 2 |
| P001 | 2013-08-04 12:33:41 | 1375644060 | 1375644053.1307271 | XSS_SALES | SIP/10857 | COMPLETEAGENT | 1 | 5 | | | | | 1 |
| P001 | 2013-08-04 12:41:34 | 1375645293 | 1375644053.1307271 | XSS_SALES | SIP/10857 | COMPLETECALLER | 1 | 1238 | 1 | | | | 2 |
| P001 | 2013-08-04 12:20:55 | 1375644055 | 1375644053.1307271 | XSS_SALES | SIP/10857 | CONNECT | 1 | 1375644054.1307273 | 0 | | | | 1 |
| P001 | 2013-08-04 12:20:55 | 1375644054 | 1375644053.1307271 | XSS_SALES | NONE | ENTERQUEUE | | 7135763000 | 1 | | | | 1 |
+-----------+---------------------+------------+--------------------+-----------+-----------+----------------+-------+--------------------+-------+-------+-------+----------+------------------+
5 rows in set (0.03 sec)

and for the same unique ID, if we see in the CEL table,
mysql> select * from cel where uniqueid like '1375644053.1307271%' or linkedid like '1375644053.1307271%';
+----------+--------------+---------------------+-------------+------------+------------+------------+-----------+------------+------------+---------------+--------------------+----------+----------------------------------------------+----------+-------------+-------------+--------------------+--------------------+-----------+--------------------+
| id | eventtype | eventtime | userdeftype | cid_name | cid_num | cid_ani | cid_rdnis | cid_dnid | exten | context | channame | appname | appdata | amaflags | accountcode | peeraccount | uniqueid | linkedid | userfield | peer |
+----------+--------------+---------------------+-------------+------------+------------+------------+-----------+------------+------------+---------------+--------------------+----------+----------------------------------------------+----------+-------------+-------------+--------------------+--------------------+-----------+--------------------+
| 32798068 | CHAN_START | 2013-08-04 12:20:53 | | HOUSTON TX | 7135763000 | | | | 5108242149 | trunk-inbound | SIP/US-000b6368 | | | 3 | | | 1375644053.1307271 | 1375644053.1307271 | | |
| 32798069 | ANSWER | 2013-08-04 12:20:53 | | HOUSTON TX | 7135763000 | 7135763000 | | 5108242149 | 5108242149 | project | SIP/US-000b6368 | Answer | | 3 | | | 1375644053.1307271 | 1375644053.1307271 | | |
| 32798078 | CHAN_START | 2013-08-04 12:20:54 | | ComCast | 5108242149 | | | | s | xss-call-out | SIP/10857-000b636a | | | 3 | 10857 | 10857 | 1375644054.1307273 | 1375644053.1307271 | | |
| 32798079 | ANSWER | 2013-08-04 12:20:54 | | ComCast | 5108242149 | 5108242149 | | | 5108242149 | xss-call-out | SIP/10857-000b636a | AppQueue | (Outgoing Line) | 3 | 10857 | 10857 | 1375644054.1307273 | 1375644053.1307271 | | |
| 32798082 | BRIDGE_START | 2013-08-04 12:20:55 | | HOUSTON TX | 7135763000 | 7135763000 | | 5108242149 | 5108242149 | project | SIP/US-000b6368 | Queue | XSS_SALES,t,,,3600,queue_log.agi,macro(beep) | 3 | | | 1375644053.1307271 | 1375644053.1307271 | | SIP/10857-000b636a |
| 32803212 | BRIDGE_END | 2013-08-04 12:41:33 | | HOUSTON TX | 7135763000 | 7135763000 | | 5108242149 | 5108242149 | project | SIP/US-000b6368 | Queue | XSS_SALES,t,,,3600,queue_log.agi,macro(beep) | 3 | | | 1375644053.1307271 | 1375644053.1307271 | | SIP/10857-000b636a |
| 32803213 | HANGUP | 2013-08-04 12:41:33 | | ComCast | 5108242149 | 5108242149 | | | 5108242149 | xss-call-out | SIP/10857-000b636a | AppQueue | (Outgoing Line) | 3 | | | 1375644054.1307273 | 1375644053.1307271 | | |
| 32803214 | CHAN_END | 2013-08-04 12:41:33 | | ComCast | 5108242149 | 5108242149 | | | 5108242149 | xss-call-out | SIP/10857-000b636a | AppQueue | (Outgoing Line) | 3 | | | 1375644054.1307273 | 1375644053.1307271 | | |
| 32803215 | HANGUP | 2013-08-04 12:41:33 | | HOUSTON TX | 7135763000 | 7135763000 | | 5108242149 | 5108242149 | project | SIP/US-000b6368 | | | 3 | | | 1375644053.1307271 | 1375644053.1307271 | | |
| 32803216 | CHAN_END | 2013-08-04 12:41:33 | | HOUSTON TX | 7135763000 | 7135763000 | | 5108242149 | 5108242149 | project | SIP/US-000b6368 | | | 3 | | | 1375644053.1307271 | 1375644053.1307271 | | |
| 32803217 | LINKEDID_END | 2013-08-04 12:41:33 | | HOUSTON TX | 7135763000 | 7135763000 | | 5108242149 | 5108242149 | project | SIP/US-000b6368 | | | 3 | | | 1375644053.1307271 | 1375644053.1307271 | | |
+----------+--------------+---------------------+-------------+------------+------------+------------+-----------+------------+------------+---------------+--------------------+----------+----------------------------------------------+----------+-------------+-------------+--------------------+--------------------+-----------+--------------------+
11 rows in set (54.81 sec)

In the above said example, 'COMPLETECALLER ' date is properly updated in CEL table as "BRIDGE_END", so this states that Asterisk is pushing data fine.

Any other way that we can find out, whether qloaderd is getting any input and that is getting pushed to database? because queue_log file is also fine there is no COMPLETEAGENT, whereas in DB both resides.

Thanks in advance.

Regards
Title: Re: Call Status
Post by: QueueMetrics on October 21, 2013, 11:07:58: I would be looking at the queue_log file versus the queue_log table on the database.
Title: Re: Call Status
Post by: gopal2k on November 15, 2013, 16:12:33: One more example I have,

Following is the Queuelog file,
Caller Disconnected
1384520637|1384520630.119824|TEST|NONE|ENTERQUEUE||1008|1
1384520637|1384520630.119824|TEST|SIP/1007|CONNECT|0|1384520637.119825|0
1384520660|1384520630.119824|TEST|SIP/1007|COMPLETECALLER|0|23|1

Agent Disconnected
1384520675|1384520669.119826|TEST|NONE|ENTERQUEUE||1008|1
1384520676|1384520669.119826|TEST|SIP/1007|CONNECT|1|1384520675.119827|0
1384520682|1384520669.119826|TEST|SIP/1007|COMPLETECALLER|1|6|1

And below is the queue_log table,
mysql> select * from queue_log where call_id = '1384520669.119826';
+-----------+------------+-------------------+-------+----------+----------------+-------+-------------------+-------+-------+-------+----------+------------------+
| partition | time_id | call_id | queue | agent | verb | data1 | data2 | data3 | data4 | data5 | serverid | unique_row_count |
+-----------+------------+-------------------+-------+----------+----------------+-------+-------------------+-------+-------+-------+----------+------------------+
| P001 | 1384520675 | 1384520669.119826 | TEST | NONE | ENTERQUEUE | | 1008 | 1 | | | | 1 |
| P001 | 1384520676 | 1384520669.119826 | TEST | SIP/1007 | CONNECT | 1 | 1384520675.119827 | 0 | | | | 1 |
| P001 | 1384520682 | 1384520669.119826 | TEST | SIP/1007 | COMPLETECALLER | 1 | 6 | 1 | | | | 1 |
+-----------+------------+-------------------+-------+----------+----------------+-------+-------------------+-------+-------+-------+----------+------------------+
3 rows in set (2.90 sec)

mysql> select * from queue_log where call_id = '1384520630.119824';
+-----------+------------+-------------------+-------+----------+----------------+-------+-------------------+-------+-------+-------+----------+------------------+
| partition | time_id | call_id | queue | agent | verb | data1 | data2 | data3 | data4 | data5 | serverid | unique_row_count |
+-----------+------------+-------------------+-------+----------+----------------+-------+-------------------+-------+-------+-------+----------+------------------+
| P001 | 1384520637 | 1384520630.119824 | TEST | NONE | ENTERQUEUE | | 1008 | 1 | | | | 1 |
| P001 | 1384520637 | 1384520630.119824 | TEST | SIP/1007 | CONNECT | 0 | 1384520637.119825 | 0 | | | | 2 |
| P001 | 1384520660 | 1384520630.119824 | TEST | SIP/1007 | COMPLETECALLER | 0 | 23 | 1 | | | | 1 |
+-----------+------------+-------------------+-------+----------+----------------+-------+-------------------+-------+-------+-------+----------+------------------+
3 rows in set (1.28 sec)

And FYI: the calls are inbound calls... while checking in extensions_queuemetrics.conf file I see the COMPLETESTATUS is mentioned only for outbound call context. Will this be applicable for Inbound call as well?

Thanks.
Title: Re: Call Status
Post by: QueueMetrics on November 18, 2013, 10:25:13: Looks like Asterisk is tracking all your calls as COMPLETECALLER.
Title: Re: Call Status
Post by: gopal2k on November 18, 2013, 17:54:03: So do we need to do anything in the dialplan?

Regards
Title: Re: Call Status
Post by: QueueMetrics on November 20, 2013, 18:02:03: I'd try and follow the call route (like if you have macros or anything) that have the call always complete in the same way. It's inbound calls, correct?
Title: Re: Call Status
Post by: gopal2k on November 21, 2013, 12:39:57: Yes, its an Inbound call. And following is the simple example which am using for my inbound calls,

exten => _X.,1,Answer()
exten => _X.,n,Set(QUEUE_NAME=TESTQUEUE)
exten => _X.,n,Set(START_TIME=${STRFTIME(${EPOCH},,%Y-%m-%d_%H-%M-%S)})
exten => _X.,n,Set(MONITOR_FILENAME=TESTQUEUE/IN/${STRFTIME(${EPOCH},,%Y-%m)}/${STRFTIME(${EPOCH},,%d)}/${CALLERID(number)}-${START_TIME}-${EXTEN}-IN)
exten => _X.,n,Queue(TESTQUEUE,t,,,30000,queue_log.agi,macro(beep))
exten => _X.,n,NoOp(${QUEUESTATUS})
exten => _X.,n,GotoIf($["${QUEUESTATUS}" = "TIMEOUT"]?lbl_project_0:)
exten => _X.,n,GotoIf($["${QUEUESTATUS}" = "FULL"]?lbl_project_0:)
exten => _X.,n,GotoIf($["${QUEUESTATUS}" = "JOINEMPTY"]?lbl_project_0:)
exten => _X.,n,GotoIf($["${QUEUESTATUS}" = "LEAVEEMPTY"]?lbl_project_0:)
exten => _X.,n,GotoIf($["${QUEUESTATUS}" = "JOINUNAVAIL"]?lbl_project_0:)
exten => _X.,n,GotoIf($["${QUEUESTATUS}" = "LEAVEUNAVAIL"]?lbl_project_0:)
exten => _X.,n(lbl_project_0),Hangup()

Thanks.
Title: Re: Call Status
Post by: QueueMetrics on November 22, 2013, 10:23:09: Maybe it is because you have a macro and/or an AGI. Try creating a "simple" queue and see if this happens. Then try adding the macro and the agi and see where things start going wrong. Unfortunately this is an issue with Asterisk - we report on what Asterisk logs, and if the logs are incorrect we cannot do anything else.