[asterisk-bugs] [JIRA] (ASTERISK-22718) Devstate caching mangled after local channel optimization

[Walter Doekes (JIRA)]

     [ https://issues.asterisk.org/jira/browse/ASTERISK-22718?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Walter Doekes updated ASTERISK-22718:
-------------------------------------

    Description: 
ASTERISK-20175 introduced a {{AST_FLAG_DISABLE_DEVSTATE_CACHE}} flag that tells the devstate system to not cache certain channel states.

https://code.asterisk.org/code/changelog/asterisk?cs=378303

It looks to me like this goes awry when channels get optimized away. And then especially in the following scenario:

* Local/queuemember gets called (devstate caching disabled)
* SIP/endpoint gets called (devstate caching enabled) and picks up (state of SIP/endpoint is now IN_USE)
* Local-queuemember channel gets optimized away (turns into SIP-endpoint)
* SIP/endpoint hangs up (state of SIP/endpoint is now AVAILABLE), except *it isn't cached* because devstate caching is disabled on this channel.

End result: SIP/endpoint is apparently IN_USE and the queue has no available members anymore.

According to Matt, Local channels should never have caching. So I added this check to {{devstate.c}}:
{noformat}
--- a/main/devicestate.c
+++ b/main/devicestate.c
@@ -473,6 +473,12 @@ int ast_devstate_changed_literal(enum ast_device_state state, enum ast_devstate_
 {
        struct state_change *change;
 
+       if (!strncmp(device, "Local/", 6) != !cachable) {
+               ast_log(LOG_ERROR, "device=%s has cachable=%d for state=%d (see debug 1 for bt)\n",
+                               device, cachable, state);
+               ast_backtrace();
+       }
+               
        /*
         * If we know the state change (how nice of the caller of this function!)
         * then we can just generate a device state event.
{noformat}

On pickup, I get this:

{noformat}
device=Local/ID12 at queuemember has cachable=1 for state=0
{noformat}

On hangup, I get this:

{noformat}
device=SIP/endpoint has cachable=0 for state=0 (*) (see debug 1 for bt)
{noformat}

\(*) State is 0 instead of AVAILABLE because of an unrelated issue with realtime. Ignore that for now.

When I add the attached patch {{issueA22718_masq_copy_disable_devstate_flag.diff}}, the ERRORs go away. And, above all, the queue starts behaving again.

(Regression since r378303.)

  was:
ASTERISK-20175 introduced a {{AST_FLAG_DISABLE_DEVSTATE_CACHE}} flag that tells the devstate system to not cache certain channel states.

https://code.asterisk.org/code/changelog/asterisk?cs=378303

It looks to me like this goes awry when channels get optimized away. And then especially in the following scenario:

* Local/queuemember gets called (devstate caching disabled)
* SIP/endpoint gets called (devstate caching enabled) and picks up (state of SIP/endpoint is now IN_USE)
* Local-queuemember channel gets optimized away (turns into SIP-endpoint)
* SIP/endpoint hangs up (state of SIP/endpoint is now AVAILABLE), except *it isn't cached* because devstate caching is disabled on this channel.

End result: SIP/endpoint is apparently IN_USE and the queue has no available members anymore.

According to Matt, Local channels should never have caching. So I added this check to {{devstate.c}}:
{noformat}
--- a/main/devicestate.c
+++ b/main/devicestate.c
@@ -473,6 +473,12 @@ int ast_devstate_changed_literal(enum ast_device_state state, enum ast_devstate_
 {
        struct state_change *change;
 
+       if (!strncmp(device, "Local/", 6) != !cachable) {
+               ast_log(LOG_ERROR, "device=%s has cachable=%d for state=%d (see debug 1 for bt)\n",
+                               device, cachable, state);
+               ast_backtrace();
+       }
+               
        /*
         * If we know the state change (how nice of the caller of this function!)
         * then we can just generate a device state event.
{noformat}

On pickup, I get this:

{noformat}
device=Local/ID12 at queuemember has cachable=1 for state=0
{noformat}

On hangup, I get this:

{noformat}
device=SIP/endpoint has cachable=0 for state=0 (*) (see debug 1 for bt)
{noformat}

\(*) State is 0 instead of AVAILABLE because of an unrelated issue with realtime. Ignore that for now.

When I add the attached patch FIXME, the ERRORs go away. And, above all, the queue starts behaving again.

(Regression since r378303.)

    
> Devstate caching mangled after local channel optimization
> ---------------------------------------------------------
>
>                 Key: ASTERISK-22718
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-22718
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>            Reporter: Walter Doekes
>         Attachments: issueA22718_masq_copy_disable_devstate_flag.diff
>
>
> ASTERISK-20175 introduced a {{AST_FLAG_DISABLE_DEVSTATE_CACHE}} flag that tells the devstate system to not cache certain channel states.
> https://code.asterisk.org/code/changelog/asterisk?cs=378303
> It looks to me like this goes awry when channels get optimized away. And then especially in the following scenario:
> * Local/queuemember gets called (devstate caching disabled)
> * SIP/endpoint gets called (devstate caching enabled) and picks up (state of SIP/endpoint is now IN_USE)
> * Local-queuemember channel gets optimized away (turns into SIP-endpoint)
> * SIP/endpoint hangs up (state of SIP/endpoint is now AVAILABLE), except *it isn't cached* because devstate caching is disabled on this channel.
> End result: SIP/endpoint is apparently IN_USE and the queue has no available members anymore.
> According to Matt, Local channels should never have caching. So I added this check to {{devstate.c}}:
> {noformat}
> --- a/main/devicestate.c
> +++ b/main/devicestate.c
> @@ -473,6 +473,12 @@ int ast_devstate_changed_literal(enum ast_device_state state, enum ast_devstate_
>  {
>         struct state_change *change;
>  
> +       if (!strncmp(device, "Local/", 6) != !cachable) {
> +               ast_log(LOG_ERROR, "device=%s has cachable=%d for state=%d (see debug 1 for bt)\n",
> +                               device, cachable, state);
> +               ast_backtrace();
> +       }
> +               
>         /*
>          * If we know the state change (how nice of the caller of this function!)
>          * then we can just generate a device state event.
> {noformat}
> On pickup, I get this:
> {noformat}
> device=Local/ID12 at queuemember has cachable=1 for state=0
> {noformat}
> On hangup, I get this:
> {noformat}
> device=SIP/endpoint has cachable=0 for state=0 (*) (see debug 1 for bt)
> {noformat}
> \(*) State is 0 instead of AVAILABLE because of an unrelated issue with realtime. Ignore that for now.
> When I add the attached patch {{issueA22718_masq_copy_disable_devstate_flag.diff}}, the ERRORs go away. And, above all, the queue starts behaving again.
> (Regression since r378303.)

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.asterisk.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira