[Home]

Summary:ASTERISK-15560: Audio loop reports T38 switchover but t38state != T38_STATE_NEGOTIATED
Reporter:iskatel (iskatel)Labels:
Date Opened:2010-02-02 01:32:31.000-0600Date Closed:2011-07-27 13:42:29
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Applications/app_fax
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) sendfax.log
( 1) t38_1.log
Description:SendFax not working with t38

Path of call
Asterisk(1.1.1.1) -> Cisco AS5300(2.2.2.2) -> PSTN

app_fax.c was applied from
http://svnview.digium.com/svn/asterisk/branches/1.6.2?view=revision&revision=225871

After re-INVITE has been received from Cisco, asterisk sends 200 OK, then ERROR appears and asterisk breaks the call. ReceiveFax works.    
Comments:By: iskatel (iskatel) 2010-02-02 01:35:53.000-0600

spandsp ver: spandsp-0.0.6pre17.tgz
By: Kristijan Vrban (vrban) 2010-02-02 02:37:06.000-0600

hello, try to remove the Playback and Wait commands before SendFAX. Any difference?
By: iskatel (iskatel) 2010-02-02 04:29:55.000-0600

hello, vrban

Same problem... in one of my attempts i added one more Wait() application before SendFax and behavior of session was such:
1) receive re-INVITE with t38
2) asterisk send 488 Not acceptable
3) receive re-INVITE with alaw codec
4) asterisk send 200 OK
5) fax transmitted successfully through alaw  
no errors detected.
As i comment this Wait(), 200 OK was sent to Cisco with t38 but ERROR appears
By: Leif Madsen (lmadsen) 2010-02-16 13:12:49.000-0600

As the T.38 code is extremely dynamic right now, I'd like to ask you to try out 1.6.2.3-rc2, or even the latest 1.6.2 code from the branch directly to see if this issue has already been resolved prior to assigning any resources to this issue.

Thanks!
By: jamhed (jamhed) 2010-02-17 03:26:42.000-0600

I've got the same message while trying to receive fax.
The scheme is: AS5350 -> Kamailio -> Asterisk.

Asterisk 1.6.2.3-rc2
By: Leif Madsen (lmadsen) 2010-03-02 15:29:04.000-0600

Can you provide logging from the version you're running? (i.e. 1.6.2.3-rc2 or from the 1.6.2 branch directly)

This presumes that the logs would look any different from what you've already uploaded.
By: iskatel (iskatel) 2010-03-03 04:31:16.000-0600

astreisk 1.6.2.4
After asterisk send 200 ?? on re-INVITE asterisk crashes
Log "sendfax.log" in attached files

Log t38_1.log was for 1.6.2.1
By: iskatel (iskatel) 2010-03-24 09:58:47

astreisk 1.6.2.6 crashes too
By: iskatel (iskatel) 2010-03-25 09:32:09

I am sorry i had reinstalled asterisk 1.6.2.6 and try the latest version of spandsp and problem the same "Audio loop reports T38 switchover but t38state != T38_STATE_NEGOTIATED". No crashes. Sorry one more time.
By: Antoine Reversat (areversat) 2010-06-04 14:41:23

I have the same problem here. Channel negogiates T.38 and then I get Audio loop reports T38 switchover but t38state != T38_STATE_NEGOTIATED. From what I can see in the code it's as if the channel driver didn't have the time to update it's t.38 state.

Version of asterisk is 1.6.2.9-rc1 and this doesn't happen for every fax. Just some of them but I couldn't find what the failing fax have in common.

               res = transmit_audio(s);
               if (res > 0) {
                       /* transmit_audio reports switchover to T38. Update t38state */
                       s->t38state = ast_channel_get_t38_state(s->chan);
                       if (s->t38state != T38_STATE_NEGOTIATED) {

Here is the relevant log snippet :

[Jun  4 15:02:32] DEBUG[5163] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[Jun  4 15:02:32] DEBUG[5163] app_fax.c: frame 4/-1, len=0
[Jun  4 15:02:32] DEBUG[5163] app_fax.c: frame 4/20, len=0
[Jun  4 15:02:32] DEBUG[5163] app_fax.c: frame 4/24, len=24
[Jun  4 15:02:32] DEBUG[5163] app_fax.c: T38 request received, accepting
[Jun  4 15:02:32] DEBUG[5163] app_fax.c: frame 4/20, len=0
[Jun  4 15:02:32] DEBUG[5163] app_fax.c: frame 4/24, len=24
[Jun  4 15:02:32] DEBUG[5163] app_fax.c: T38 negotiated, finishing audio loop
[Jun  4 15:02:32] DEBUG[5163] app_fax.c: Loop finished, res=1
[Jun  4 15:02:32] DEBUG[5163] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Jun  4 15:02:32] DEBUG[5163] app_fax.c: FLOW T.30 Changing from state 18 to 32
[Jun  4 15:02:32] DEBUG[5163] app_fax.c: FLOW T.30 Changing from phase T30_PHASE_A_CNG to T30_PHASE_CALL_FINISHED
[Jun  4 15:02:32] DEBUG[5163] app_fax.c: FLOW FAX Set rx type 8
[Jun  4 15:02:32] DEBUG[5163] app_fax.c: FLOW FAX FAX exchange complete
[Jun  4 15:02:32] DEBUG[5163] app_fax.c: FLOW FAX Set tx type 8
[Jun  4 15:02:32] DEBUG[5163] app_fax.c: FLOW FAX FAX exchange complete
[Jun  4 15:02:32] ERROR[5163] app_fax.c: Audio loop reports T38 switchover but t38state != T38_STATE_NEGOTIATED
[Jun  4 15:02:32] WARNING[5163] app_fax.c: Transmission error


By: alexr1 (alexr1) 2010-06-08 09:49:53

I can send faxes successfully from the 1.6 machine thru the 1.4 machine to a T38Gateway, but not from the 1.6 machine thru the 1.4 machine back to the original 1.6 machine. (Internal users faxing each other).

It results in the error: Audio loop reports T38 switchover but t38state != T38_STATE_NEGOTIATED

Trying to send from AST1.6.2.8 to AST1.4.25(passthru) back to the same AST1.6.2.8 machine. (These two machines have 1 trunk between them with ONLY ulaw enabled)

I noticed things like
"Have T.38 but no audio"
and
"Done building SDP. Settling with this capability: 0x0 (nothing)."

Both ends fail to get to T38 mode and end up in Audio mode but then fail after "Transmission Error". Of course, it is hard to tell the sending and receiving CLI messages apart because they are both on the same box, so tomorrow I'll setup a 2nd box and attempt to replicate it on there (and capture distinct, separate CLI outputs of SENDING & RECEIVING ends)

I'm sending the faxes from call files which look like this:
Channel: Local/1731@fax-out
WaitTime: 30
Maxretries: 0
RetryTime: 30
Callerid: Fax<60001>
Set: LOCALSTATIONID=0700000000
Set: LOCALHEADERINFO=
Set: T38CALL=1
Set: T38TXDETECT=yes
Set: FAXFILE=/tmp/sendfax/1731.tif
Set: FAXID=1731
Context: fax-send
Extension: s
Priority: 1
StartRetry: 8202 1 (1275985281)

I'm not sure if it is related to the existing issue.
By: alexr1 (alexr1) 2010-06-08 18:40:05

Doesn't seem to be entirely related, but while trying to troubleshoot my problem (above), I changed the codecs on the trunk between the servers to just "ulaw".

This morning I noticed normal faxes through the T38 Gateway -> AST1.4 -> AST 1.6 (and vice versa) were no longer working! I added "alaw" back in to both servers SIP.conf and then it began working. Without the "alaw" it still went into T38 switchover, but had errors like "Disconnected after permitted number of retries". Could this be related? When I see "Settling with this capability (nothing)" (for my original issue), it makes me think its codec related...
By: Antoine Reversat (areversat) 2010-06-11 08:50:35

Ok I tracked down the issue to this : chan_local doesn't have a queryoption method. Therefore it cannot report whether or not it is in t.38 mode. The quick fix is to not use a local channel.

The long fix would be to implement the queryoption function in chan_local and make it report the t.38 status of the underlying sip channel.
By: Jamuel Starkey (jamuel) 2010-06-21 16:14:46

When testing with 1.6.2.9 this issue seems to only appear when the local channel is flagged to not optimize (/n) without the /n sendfax works just fine via T.38.
By: iskatel (iskatel) 2010-07-08 01:59:12

I can confirm that if using 1.6.2.9 and spandsp 0.0.6 then everthing works well (and transmit and receive).

Only one thing, during transmitting at the end of transmission all the time such message appears
"WARNING[17074]: app_fax.c:817 transmit: Transmission error"
but ${FAXSTATUS}, ${FAXERROR} and ${FAXPAGES} shows correct significance.
By: iskatel (iskatel) 2010-07-08 02:44:20

And yes, i forgot, as reported Jamuel it's working without /n in local channels
By: Russell Bryant (russell) 2011-07-27 13:42:23.429-0500

Per the Asterisk maintenance timeline page at http://www.asterisk.org/asterisk-versions maintenance (bug) support for the 1.4 and 1.6.x branches has ended. For continued maintenance support please move to the 1.8 branch which is a long term support (LTS) branch. For more information about branch support, please see https://wiki.asterisk.org/wiki/display/AST/Asterisk+Versions

If this is still an issue, please open a new issue so it can be re-triaged appropriately. Thanks!