[asterisk-bugs] [Asterisk 0017067]: [patch] chan_dahdi/fxs really needringing

Fri Apr 30 17:22:46 CDT 2010

A NOTE has been added to this issue. 
====================================================================== 
https://issues.asterisk.org/view.php?id=17067 
====================================================================== 
Reported By:                tzafrir
Assigned To:                
====================================================================== 
Project:                    Asterisk
Issue ID:                   17067
Category:                   Channels/chan_dahdi
Reproducibility:            always
Severity:                   minor
Priority:                   normal
Status:                     acknowledged
Asterisk Version:           SVN 
JIRA:                       SWP-1130 
Regression:                 No 
Reviewboard Link:            
SVN Branch (only for SVN checkouts, not tarball releases): 1.6.2 
SVN Revision (number only!): 253158 
Request Review:              
====================================================================== 
Date Submitted:             2010-03-21 05:33 CDT
Last Modified:              2010-04-30 17:22 CDT
====================================================================== 
Summary:                    [patch] chan_dahdi/fxs really needringing
Description: 
Symptom: an analog phone connected to an FXS device (see more below on the
FXS device). Asterisk rings to the phone. If the call is answered before
the end of the first ring, the channel is in state Ringing rather than in
state Up.

(needringing is one of the boolean flags included in the pvt struct of
chan_dahdi).

Details:
Our DAHDI driver may delay sending PCM until the first ring. This seems to
trigger a strange bug in DAHDI where the driver apparently remains in state
Ringing rather than switching to Up if the phone was picked up before the
first ring.

Looking deeper into this we see that the state is set to 'Up' but right
afterward set back to Ringing.

In the following cases I generated a call to the phone and picked it up
before the end of the first ring. Line numbers are affected by the heavy
patching for extra debug messages. See attached patches.

Looking at how needsringing is set and used, I see that the state is set
to RINGING 3 times:

1. Right after setting needringing to 1 in dahdi_call().
2. When needringing is "consumed" in dahdi_read(), the state is set to
RINGING.
3. And in the same place a control frame is put to set the state to
RINGING.

(3) is the one that cases the delay setting of state which triggers
(triggers? causes?) the bug.

However as I assume that there's something here I don't fully understand,
I tried the simplest fix: unset needringing if we already answered.

Without the fix:
morgan*CLI> originate DAHDI/4 application echo
[Mar 21 12:11:42] DEBUG[21563]: chan_dahdi.c:10977 dahdi_request: Using
channel 4
[Mar 21 12:11:44] DEBUG[21563]: chan_dahdi.c:6702 __dahdi_exception:
Exception on 18, channel 4
[Mar 21 12:11:44] DEBUG[21563]: chan_dahdi.c:5735 dahdi_handle_event: Got
event Ring/Answered(2) on channel 4 (index 0)
[Mar 21 12:11:44] DEBUG[21563]: chan_dahdi.c:2686 dahdi_enable_ec: Enabled
echo cancellation on channel 4
[Mar 21 12:11:44] DEBUG[21563]: chan_dahdi.c:2705 dahdi_train_ec: No echo
training requested
[Mar 21 12:11:44] DEBUG[21563]: chan_dahdi.c:6077 dahdi_handle_event:
channel 4 answered
    -- Launching echo() on DAHDI/4-1
[Mar 21 12:11:44] DEBUG[22602]: chan_dahdi.c:6801 dahdi_read: subchan
needringing: adding frame RINGING
[Mar 21 12:11:44] DEBUG[22602]: channel.c:3474 ast_write: ast_write: chan
DAHDI/4-1, indication 3
[Mar 21 12:11:44] DEBUG[22602]: chan_dahdi.c:7185 dahdi_indicate:
Requested indication 3 on channel DAHDI/4-1

A trace after the fix:
morgan*CLI> originate DAHDI/4 application echo
[Mar 21 11:54:35] DEBUG[21563]: chan_dahdi.c:10977 dahdi_request: Using
channel 4
[Mar 21 11:54:37] DEBUG[21563]: chan_dahdi.c:6702 __dahdi_exception:
Exception on 18, channel 4
[Mar 21 11:54:37] DEBUG[21563]: chan_dahdi.c:5735 dahdi_handle_event: Got
event Ring/Answered(2) on channel 4 (index 0)
[Mar 21 11:54:37] DEBUG[21563]: chan_dahdi.c:2686 dahdi_enable_ec: Enabled
echo cancellation on channel 4
[Mar 21 11:54:37] DEBUG[21563]: chan_dahdi.c:2705 dahdi_train_ec: No echo
training requested
[Mar 21 11:54:37] DEBUG[21563]: chan_dahdi.c:6077 dahdi_handle_event:
channel 4 answered
    -- Launching echo() on DAHDI/4-1
morgan*CLI>

(Initially tested on 1.6.2 as it is what we work with and the code in
trunk is quite reshuffled. trunk seems to have the same symptoms.

Patches:
* needsringing.diff: the fix I mentioned. vs. 1.6.2. Older versions should
be similar.
* needsringing_debugmessages.diff: extra debug messages I added to trace
the issue.
====================================================================== 

---------------------------------------------------------------------- 
 (0121255) svnbot (reporter) - 2010-04-30 17:22
 https://issues.asterisk.org/view.php?id=17067#c121255 
---------------------------------------------------------------------- 
Repository: asterisk
Revision: 260434

U   branches/1.4/channels/chan_dahdi.c

------------------------------------------------------------------------
r260434 | jpeeler | 2010-04-30 17:22:46 -0500 (Fri, 30 Apr 2010) | 11
lines

Ensure channel state is not incorrectly set in the case of a very early
answer.

The needringing bit was being read in dahdi_read after answering thereby
setting the state to ringing from up. This clears needringing upon
answering
so that is no longer possible.

(closes issue https://issues.asterisk.org/view.php?id=17067)
Reported by: tzafrir
Patches: 
      needringing.diff uploaded by tzafrir (license 46)

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=260434 

Issue History 
Date Modified    Username       Field                    Change               
====================================================================== 
2010-04-30 17:22 svnbot         Checkin                                      
2010-04-30 17:22 svnbot         Note Added: 0121255                          
======================================================================