[asterisk-bugs] [JIRA] (ASTERISK-27064) Wrapup doesn't work time-to-time.

Michael L. Young (JIRA) noreply at issues.asterisk.org
Mon Jun 19 08:39:57 CDT 2017


    [ https://issues.asterisk.org/jira/browse/ASTERISK-27064?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=237477#comment-237477 ] 

Michael L. Young commented on ASTERISK-27064:
---------------------------------------------

Per the Asterisk versions page [1], the maintenance (bug fix) support for the Asterisk branch you are using has ended. For continued maintenance support please move to a supported branch of Asterisk. After testing with a supported branch, if you find this problem has not been resolved, please open a new issue against the latest version of that Asterisk branch.

Thanks!

[1] https://wiki.asterisk.org/wiki/display/AST/Asterisk+Versions

You might also check out these issues that deal with wrap-up time.  They have already been fixed in newer versions of Asterisk.

https://issues.asterisk.org/jira/browse/ASTERISK-26399

https://issues.asterisk.org/jira/browse/ASTERISK-26400

https://issues.asterisk.org/jira/browse/ASTERISK-26715

https://issues.asterisk.org/jira/browse/ASTERISK-26975

> Wrapup doesn't work time-to-time.
> ---------------------------------
>
>                 Key: ASTERISK-27064
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-27064
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>          Components: Applications/app_queue
>    Affects Versions: 11.22.0
>         Environment: Centos 6.8, Digium, Inc. Wildcard TE420P
>            Reporter: vladimir shmagin
>            Severity: Minor
>
> Operators complain about absense of wrapup in 5% of calls. 
> *The following query was used to detect the problem:*
> {noformat}
> select * from
> (select
> a.time,a.agent,
> min(TIMESTAMPDIFF(SECOND,a.time,b.time)) as dif,
> substr(a.time,12,8) as atime,a.event as event1,
> substr(b.time,12,8) as btime,b.event as event2 from queue_log b,
> (select time,agent,event from queue_log where time between '2017-06-19 11:00' and '2017-06-19 14:59'
> and queuename='LoK'
> and (event='COMPLETECALLER' or event='COMPLETEAGENT' or event='TRANSFER')) a
> where
> b.time between '2017-06-19 11:00' and b.time<'2017-06-19 14:59'
> and b.queuename='LoK'
> and b.agent=a.agent
> and b.event not in ('COMPLETECALLER','COMPLETEAGENT','TRANSFER',
> 'PAUSE','UNPAUSE','PAUSEREASON','INFO','REMOVEMEMBER')
> and b.time>a.time
> group by a.agent,a.time)
> c where dif<19;
> {noformat}
> *Here are some results:*
> {noformat}
> +----------------------------+----------------+------+----------+---------------+----------+--------------+
> | time                       | agent          | dif  | atime    | event1        | btime    | event2       |
> +----------------------------+----------------+------+----------+---------------+----------+--------------+
> | 2017-06-13 16:13:39.534337 | SIP/76012:1100 |    3 | 16:13:39 | COMPLETEAGENT | 16:13:42 | CONNECT      |
> | 2017-06-13 16:34:57.905027 | SIP/76012:1100 |    1 | 16:34:57 | COMPLETEAGENT | 16:34:59 | CONNECT      |
> | 2017-06-13 16:35:34.452925 | SIP/76012:1100 |    1 | 16:35:34 | COMPLETEAGENT | 16:35:36 | CONNECT      |
> | 2017-06-13 18:18:49.578981 | SIP/76012:1100 |    1 | 18:18:49 | COMPLETEAGENT | 18:18:51 | CONNECT      |
> | 2017-06-13 18:27:05.776445 | SIP/76012:1100 |   15 | 18:27:05 | COMPLETEAGENT | 18:27:20 | RINGNOANSWER |
> | 2017-06-14 20:06:29.005467 | SIP/76012:1064 |    6 | 20:06:29 | COMPLETEAGENT | 20:06:35 | CONNECT      |
> | 2017-06-14 21:25:19.682858 | SIP/76012:1064 |    2 | 21:25:19 | COMPLETEAGENT | 21:25:22 | CONNECT      |
> +----------------------------+----------------+------+----------+---------------+----------+--------------+
> +----------------------------+----------------+------+----------+----------------+----------+--------------+
> | time                       | agent          | dif  | atime    | event1         | btime    | event2       |
> +----------------------------+----------------+------+----------+----------------+----------+--------------+
> | 2017-06-15 10:51:41.651903 | SIP/76010:1686 |    1 | 10:51:41 | COMPLETEAGENT  | 10:51:43 | CONNECT      |
> | 2017-06-15 12:56:41.267282 | SIP/76010:1686 |    0 | 12:56:41 | COMPLETEAGENT  | 12:56:41 | RINGNOANSWER |
> | 2017-06-15 13:44:48.022416 | SIP/76010:1686 |    6 | 13:44:48 | COMPLETEAGENT  | 13:44:54 | CONNECT      |
> | 2017-06-15 13:45:58.245652 | SIP/76010:1686 |    2 | 13:45:58 | COMPLETEAGENT  | 13:46:00 | CONNECT      |
> | 2017-06-15 14:58:00.714293 | SIP/76010:1686 |    1 | 14:58:00 | COMPLETECALLER | 14:58:02 | CONNECT      |
> | 2017-06-15 18:21:29.909289 | SIP/76010:1686 |    5 | 18:21:29 | COMPLETECALLER | 18:21:35 | CONNECT      |
> | 2017-06-15 18:22:28.093244 | SIP/76010:1686 |    1 | 18:22:28 | COMPLETEAGENT  | 18:22:30 | CONNECT      |
> +----------------------------+----------------+------+----------+----------------+----------+--------------+
> {noformat}
> As we noted the problems occurs more often when call finishs with event "COMPLETEAGENT". Operators were instructed to wait abonent hangup.
> Today  we ran 'core set debug 5 app_queue.so'  to collect more information. *The problem has repeated:*
> {noformat}
> +----------------------------+----------------+------+----------+---------------+----------+--------------+
> | time                       | agent          | dif  | atime    | event1        | btime    | event2       |
> +----------------------------+----------------+------+----------+---------------+----------+--------------+
> | 2017-06-19 11:33:28.931312 | SIP/76008:8867 |    0 | 11:33:28 | COMPLETEAGENT | 11:33:29 | RINGNOANSWER |
> +----------------------------+----------------+------+----------+---------------+----------+--------------+
> +-----------+----------------------------+------------------+-----------+----------------+---------------+-------+-------
> | id        | time                       | callid           | queuename | agent          | event         | data1 | data2 
> +-----------+----------------------------+------------------+-----------+----------------+---------------+-------+-------
> | 225402899 | 2017-06-19 11:33:28.931312 | 1497860837.9768  | LoK       | SIP/76008:8867 | COMPLETEAGENT | 9     | 346   
> | 225402902 | 2017-06-19 11:33:29.258446 | 1497861158.10136 | LoK       | SIP/76008:8867 | RINGNOANSWER  | 0     |       
> +-----------+----------------------------+------------------+-----------+----------------+---------------+-------+-------
> {noformat}
> *Device state log is the following:*
> {noformat}
> [Jun 19 11:27:40] DEBUG[31277] app_queue.c: Device 'SIP/76008' changed to state '6' (Ringing)
> [Jun 19 11:27:42] DEBUG[31277] app_queue.c: Device 'SIP/76008' changed to state '3' (Busy)
> [Jun 19 11:30:40] DEBUG[31277] app_queue.c: Device 'SIP/76008' changed to state '3' (Busy)
> [Jun 19 11:33:29] DEBUG[31277] app_queue.c: Device 'SIP/76008' changed to state '1' (Not in use)
> [Jun 19 11:33:29] DEBUG[31277] app_queue.c: Device 'SIP/76008' changed to state '6' (Ringing)
> [Jun 19 11:33:29] DEBUG[31277] app_queue.c: Device 'SIP/76008' changed to state '1' (Not in use)
> {noformat}
> *The part of call trace is the following:*
> {noformat}
> [Jun 19 11:27:40] VERBOSE[19891][C-00000ee1] app_queue.c:     -- SIP/76008-00001cff is ringing
> [Jun 19 11:27:42] VERBOSE[19891][C-00000ee1] app_queue.c:     -- SIP/76008-00001cff answered DAHDI/i2/9818262527-3e4
> [Jun 19 11:27:42] DEBUG[19891][C-00000ee1] app_queue.c: Next is 'SIP/76027' with metric 1027
> [Jun 19 11:27:42] VERBOSE[19891][C-00000ee1] res_musiconhold.c:     -- Stopped music on hold on DAHDI/i2/9818262527-3e4
> [Jun 19 11:27:42] DEBUG[19891][C-00000ee1] app_queue.c: Queue 'LoK' Leave, Channel 'DAHDI/i2/9818262527-3e4'
> [Jun 19 11:27:42] DEBUG[19891][C-00000ee1] app_queue.c: Marked member SIP/76008:8867 as in_call 
> [Jun 19 11:33:29] DEBUG[19891][C-00000ee1] app_queue.c: Marked member SIP/76008:8867 as NOT in_call. Lastcall time: 1497861209 
> +-----------------------------+
> | FROM_UNIXTIME('1497861209') |
> +-----------------------------+
> | 2017-06-19 11:33:29         |
> +-----------------------------+
> {noformat}
> *Then we see the next try to call 76008:*
> {noformat}
> [Jun 19 11:33:29] DEBUG[20475][C-00000f55] app_queue.c: Trying 'SIP/76017' with metric 25
> [Jun 19 11:33:29] DEBUG[20475][C-00000f55] app_queue.c: SIP/76017 not available, can't receive call
> [Jun 19 11:33:29] DEBUG[20475][C-00000f55] app_queue.c: Trying 'SIP/76008' with metric 26
> [Jun 19 11:33:29] VERBOSE[20475][C-00000f55] netsock2.c:   == Using SIP RTP CoS mark 5
> [Jun 19 11:33:29] DEBUG[31277] app_queue.c: Device 'SIP/76008' changed to state '6' (Ringing)
> [Jun 19 11:33:29] DEBUG[31277] app_queue.c: Device 'Queue:LoK_avail' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
> [Jun 19 11:33:29] VERBOSE[31251][C-00000f55] chan_sip.c:     -- Got SIP response 486 "Busy Here" back from 172.30.0.92:5060
> [Jun 19 11:33:29] VERBOSE[20475][C-00000f55] app_queue.c:     -- SIP/76008-00001e71 is busy
> [Jun 19 11:33:29] VERBOSE[20475][C-00000f55] app_queue.c:     -- Nobody picked up in 0 ms
> [Jun 19 11:33:29] DEBUG[31277] app_queue.c: Device 'SIP/76008' changed to state '1' (Not in use)
> {noformat}



--
This message was sent by Atlassian JIRA
(v6.2#6252)



More information about the asterisk-bugs mailing list