Summary:	ASTERISK-22718: Devstate caching mangled after local channel optimization
Reporter:	Walter Doekes (wdoekes)	Labels:
Date Opened:	2013-10-16 09:06:55	Date Closed:	2013-10-18 09:47:01
Priority:	Major	Regression?	Yes
Status:	Closed/Complete	Components:
Versions:		Frequency of Occurrence
Related Issues:	must be completed before resolving ASTERISK-22561 Open blockers for 1.8.24.0 must be completed before resolving ASTERISK-22562 Open blockers for 11.6.0 is duplicated by ASTERISK-22720 devstate incorrectly cached on transfer of a DAHDI to SIP call.
Environment:		Attachments:	( 0) issueA22718_masq_copy_disable_devstate_flag.diff
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@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.)
Comments:	By: Matt Jordan (mjordan) 2013-10-17 14:28:33.191-0500 Repasting from asterisk-dev for posterity: (02:25:21 PM) ***mjordan looks (02:26:30 PM) mjordan: wdoekes: so in that example, the SIP channel has been masqueraded into the Local channel, and as a result got the non-caching status of the Local channel (02:27:04 PM) mjordan: ew (02:28:03 PM) wdoekes: that's right (02:28:08 PM) mjordan: I can't imagine that we would ever want to lose the caching status of the channel. That's an intrinsic property that should always be preserved - so yeah. Ship It.