[asterisk-dev] HANGUPCAUSE variable wrong

[Mark Michelson]

On 07/30/2012 10:57 PM, Pavel Troller wrote:
> Hi!
>    My systems started to show strange behaviour recently (1.8 branch). It seems
> to be related to on of the latest updates, but I was not able to track it down
> yet.
>    The problem appears in the following scenario:
>    - There is a call attempt to a destination, which rejects the call
>      (the Dial() command return with some clear cause, for example 38).
>    - So there is another connection attempt to another destination, which is
>      successful and the call is established
>    - This secondary destination is of the DAHDI/PRI type
>    - The call is then released by the CALLED party
>    - The dialplan continues (Dial() with 'g' option)
>    In this case, the HANGUPCAUSE pseudo variable is not updated with the proper
> cause (16) and still uses the one from the first connection (38).
>    The following snippet from the debug log illustrates the problem, it shows the
> clearing part of the connection:
>
> [Jul 30 20:27:11] DEBUG[23000] channel.c: Didn't get a frame from channel: DAHDI/i2/602376534-a
> [Jul 30 20:27:11] DEBUG[23000] res_rtp_asterisk.c: Changing ssrc from 546686679 to 1038239072 due to a source change
> [Jul 30 20:27:11] DEBUG[23000] channel.c: Bridge stops bridging channels SCCP/2151-00000048 and DAHDI/i2/602376534-a
> [Jul 30 20:27:11] DEBUG[23000] pbx.c: Evaluating 'CDR(xsrc)' (from 'CDR(xsrc)}|${CDR(xdst)}|${CDR(sentno)}|${CDR(billno)}|${CDR(channel)}|${CDR(dstchannel)}|${CDR(sclass)}|${CDR(dclass)}|${CDR(start)}|${CDR(duration)}|${CDR(billsec)}|${CDR(cause)}|${CDR(disposition)}|${CDR(uniqueid)}|${CDR(src)}
> ' len 9)
> [Jul 30 20:27:11] DEBUG[23000] pbx.c: Function result is '2151'
> ... A lot of CDR evaluations skipped
> [Jul 30 20:27:11] DEBUG[23000] channel.c: Hanging up channel 'DAHDI/i2/602376534-a'
> [Jul 30 20:27:11] DEBUG[23000] chan_dahdi.c: dahdi_hangup(DAHDI/i2/602376534-a)
> [Jul 30 20:27:11] DEBUG[23000] chan_dahdi.c: Set option AUDIO MODE, value: ON(1) on DAHDI/i2/602376534-a
> [Jul 30 20:27:11] DEBUG[23000] sig_pri.c: sig_pri_hangup 32
> [Jul 30 20:27:11] DEBUG[23000] sig_pri.c: Not yet hungup...  Calling hangup with cause 16, and clearing call
> [Jul 30 20:27:11] DEBUG[23000] chan_dahdi.c: Disabled echo cancellation on channel 32
> [Jul 30 20:27:11] DEBUG[23000] chan_dahdi.c: Set option TDD MODE, value: OFF(0) on DAHDI/i2/602376534-a
> [Jul 30 20:27:11] DEBUG[23000] chan_dahdi.c: Updated conferencing on 32, with 0 conference users
> [Jul 30 20:27:11] DEBUG[23000] chan_dahdi.c: Set option AUDIO MODE, value: OFF(0) on DAHDI/i2/602376534-a
> [Jul 30 20:27:11] DEBUG[23000] app_dial.c: Exiting with DIALSTATUS=ANSWER.
> [Jul 30 20:27:11] DEBUG[23000] app_macro.c: Executed application: Dial
> [Jul 30 20:27:11] DEBUG[27171] devicestate.c: No provider found, checking channel drivers for DAHDI - i2/602376534
> [Jul 30 20:27:11] DEBUG[23000] pbx.c: Result of 'HANGUPCAUSE' is '38'
> [Jul 30 20:27:11] DEBUG[23000] pbx.c: Launching 'Set'
> [Jul 30 20:27:11] DEBUG[23000] app_macro.c: Executed application: Set
> [Jul 30 20:27:11] DEBUG[27171] devicestate.c: Changing state for DAHDI/i2/602376534 - state 0 (Unknown)
> [Jul 30 20:27:11] DEBUG[23000] pbx.c: Result of 'DIALSTATUS' is 'ANSWER'
> [Jul 30 20:27:11] DEBUG[27171] devicestate.c: device 'DAHDI/i2/602376534' state '0'
> [Jul 30 20:27:11] DEBUG[23000] pbx.c: Result of 'HANGUPCAUSE' is '38'
>
>    You can see that the clear cause is 16 in our case, but HANGUPCAUSE returns
> 38 (the result from the first connection).
>    If the second connection attempt fails too (with another cause, say 17),
> it is properly copied to the HANGUPCAUSE pseudo variable.
>    As the HANGUPCAUSE is just reading of the hangupcause member of the channel
> structure, it seems that this member is not updated in the scenario described
> above.
>    It seems from the debug log, that the clear is not initiated by the DSS1
> signalling (DISC/REL messages), but by the lack of incoming frames from the
> channel. May be this is the reason ?
>    I would like to track this issue by myself to learn more of the Asterisk
> internal logic, so please could you just point me to a place, where the clear
> cause is to be written to the calling channel struct ? I will make some
> debugging, find the cause and possibly write a patch. I will open the issue
> then.
>    With regards,
>      Pavel
Thanks for taking the initiative to try to learn some Asterisk code!

The problem with the hangupcause of a channel is that it can be set in 
*a lot* of places throughout the code. What you're interested in is the 
hangupcause of the inbound channel for a Dial() attempt. Most channel 
drivers are going to set the hangupcause for the outbound channel, and 
that value will get copied to the inbound channel within app_dial.c 
itself. Most of the time, this happens during wait_for_answer(), when 
we're waiting for the outbound leg of the call to be answered.

Given that you're seeing the cause get set properly on the outbound 
channel, my guess is that it simply is not being copied to the inbound 
channel properly. You should be able to limit your search for 
hangupcause setting in app_dial.c.

You have already figured out that if the second call is rejected, then 
the hangupcause is copied properly to the inbound channel, so the key 
here is finding out what is different for the case where the call is 
answered. Also, it would be a good idea to see if your options to Dial() 
are affecting things.

Regarding your observation about the lack of incoming frames, this is 
typically the way that Asterisk indicates that the call has been hung 
up, so I think it is unlikely that this is the root cause of the 
problem. I think that what you need to do is look through app_dial and 
find places where the hangupcause is and is not set. There may be some 
code path where it is not set and it should be. For calls that are 
answered, you should look in dial_exec_full() after the call to 
ast_bridge_call() to find where the hangupcause for the inbound channel 
gets set.

Hopefully that will set you on the proper path!
Mark Michelson