[Home]

Summary:ASTERISK-08439: Asterisk does not reinvite peer for G.711 after T.38 negotiated failed with a "488" Event
Reporter:Alexander Tull (alex-911)Labels:
Date Opened:2006-12-27 08:13:13.000-0600Date Closed:2010-02-22 15:35:17.000-0600
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Channels/chan_sip/T.38
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) G.711passthru-asterisk1.4-20061227.txt
( 1) sip_debug_full_20061227.txt
( 2) sip_full_debug_20070112.txt
( 3) sip-full-debug-1.4.2_20070324.txt
Description:I have a linksys ATA connected to asterisk, configured for G.711 fax passthru. asterisk is connected to a Cisco PSTN gateway. the default fax protocol of the PSTN gateway is T.38, so if the Cisco media gateway detects faxtone, there is a reinvite for T.38.
asterisk passes the reinvite down to the ATA. the ATA answers correctly with a "488 not acceptable here".
instead of passing the 488 up to the proxy, asterisk seems to stop here. it receives the retransmit of the reinvite and answers with a "503 Unavailable".
I would expect asterisk to pass the 488 up what would trigger another reinvite for T.30 fax (G.711 passthru).

I'll post the simple call flow and the console log below. let me know if more details are required.
10.10.10.23: ATA
172.16.16.111: *
172.16.16.155: SIP Proxy

****** ADDITIONAL INFORMATION ******

No.     Time        Source                Destination           Protocol Info
     5 5.356307    10.10.10.23           172.16.16.111            SIP/SDP  Request: INVITE sip:0123123123@172.16.16.111, with session description
     6 5.357615    172.16.16.111            10.10.10.23           SIP      Status: 407 Proxy Authentication Required
     7 5.381047    10.10.10.23           172.16.16.111            SIP      Request: ACK sip:0123123123@172.16.16.111
     8 5.390935    10.10.10.23           172.16.16.111            SIP/SDP  Request: INVITE sip:0123123123@172.16.16.111, with session description
     9 5.391966    172.16.16.111            10.10.10.23           SIP      Status: 100 Trying
    10 5.403665    172.16.16.111            172.16.16.155            SIP/SDP  Request: INVITE sip:0123123123@172.16.16.155, with session description
    11 5.405310    172.16.16.155            172.16.16.111            SIP      Status: 100 Trying
    12 6.928163    172.16.16.155            172.16.16.111            SIP/SDP  Status: 183 Session Progress, with session description
    13 6.929269    172.16.16.111            10.10.10.23           SIP/SDP  Status: 183 Session Progress, with session description
    14 8.255266    172.16.16.155            172.16.16.111            SIP      Status: 180 Ringing
    15 8.256324    172.16.16.111            10.10.10.23           SIP      Status: 180 Ringing
    19 13.687874   172.16.16.155            172.16.16.111            SIP/SDP  Status: 200 Ok, with session description
    20 13.688658   172.16.16.111            172.16.16.155            SIP      Request: ACK sip:0123123123@172.16.16.155:5060;transport=udp
    21 13.689368   172.16.16.111            10.10.10.23           SIP/SDP  Status: 200 OK, with session description
    22 13.722535   10.10.10.23           172.16.16.111            SIP      Request: ACK sip:0123123123@172.16.16.111
    23 15.020462   10.10.10.23           172.16.16.111            SIP      Request: NOTIFY sip:172.16.16.111
    24 15.021198   172.16.16.111            10.10.10.23           SIP      Status: 489 Bad event
    25 15.290506   10.10.10.23           172.16.16.111            SIP      Request: NOTIFY sip:172.16.16.111
    26 15.290735   172.16.16.111            10.10.10.23           SIP      Status: 489 Bad event
    27 21.399485   172.16.16.155            172.16.16.111            SIP/SDP  Request: INVITE sip:0123456789@172.16.16.111, with session description
    28 21.400398   172.16.16.111            10.10.10.23           SIP/SDP  Request: INVITE sip:123456789@10.10.10.23:7261, with session description
    29 21.431743   10.10.10.23           172.16.16.111            SIP      Status: 488 Not Acceptable Here
    30 21.432093   172.16.16.111            10.10.10.23           SIP      Request: ACK sip:123456789@10.10.10.23:7261
    31 21.899660   172.16.16.155            172.16.16.111            SIP/SDP  Request: INVITE sip:0123456789@172.16.16.111, with session description
    32 21.900178   172.16.16.111            172.16.16.155            SIP      Status: 503 Unavailable
    33 21.901425   172.16.16.155            172.16.16.111            SIP      Request: ACK sip:0123456789@172.16.16.111
    34 21.901717   172.16.16.111            172.16.16.155            SIP      Request: BYE sip:0123123123@172.16.16.155:5060;transport=udp
    35 22.901888   172.16.16.111            172.16.16.155            SIP      Request: BYE sip:0123123123@172.16.16.155:5060;transport=udp
    36 22.998172   172.16.16.155            172.16.16.111            SIP      Status: 200 Ok


ASTERISK CONSOLE LOG:
=======================================================================

   -- Executing [0123123123@privileged:1] Dial("SIP/123456789-081e4e98", "SIP/0123123123@172.16.16.155") in new stack
   -- Called 0123123123@172.16.16.155
   -- SIP/172.16.16.155-081e8e00 is making progress passing it to SIP/123456789-081e4e98
   -- SIP/172.16.16.155-081e8e00 is ringing
   -- SIP/172.16.16.155-081e8e00 answered SIP/123456789-081e4e98
   -- Native bridging SIP/123456789-081e4e98 and SIP/172.16.16.155-081e8e00
   -- Got SIP response 488 "Not Acceptable Here" back from 10.10.10.23
 == Spawn extension (privileged, 0123123123, 1) exited non-zero on 'SIP/123456789-081e4e98'
[Dec 27 14:37:17] NOTICE[4367]: chan_sip.c:13479 handle_request_invite: Unable to create/find SIP channel for this INVITE
Comments:By: Olle Johansson (oej) 2006-12-27 08:29:37.000-0600

I need to see a full SIP debug log thank you. (According to the bug guidelines).
By: Alexander Tull (alex-911) 2006-12-27 08:51:50.000-0600

full SIP debug attached.
By: Olle Johansson (oej) 2006-12-27 10:33:35.000-0600

There's no DEBUG channel output here. Try again.
By: Serge Vecher (serge-v) 2006-12-27 15:20:59.000-0600

alex-911: this will help ya:

1) Prepare test environment (reduce the amount of unrelated traffic on the server);
2) Make sure your logger.conf has the following line:
  console => notice,warning,error,debug
3) restart Asterisk with the following command:
  'asterisk -Tvvvvvdddddngc | tee /tmp/verbosedebug.txt'
4) Enable SIP transaction logging with the following CLI commands:
set debug 4
set verbose 4
sip debug
5) Trim startup information and attach verbosedebug.txt to the issue.
By: Alexander Tull (alex-911) 2006-12-27 17:02:09.000-0600

please see sip_debug_full_20061227.txt for the requested debug output.
By: Olle Johansson (oej) 2007-01-08 07:37:25.000-0600

THank you for the debug file, now I know a bit more on where to look.
By: Olle Johansson (oej) 2007-01-08 07:38:06.000-0600

I guess you should not configure T.38 support on the device that receives the re-invite and the problem will be gone. Doesn't change the bug status though, it's still a bug.
By: Olle Johansson (oej) 2007-01-08 08:19:13.000-0600

I've added output to the ERROR log about mis-configured device. Can't easily figure out a way to tell the INCOMING channel that we're going back to audio.
By: Olle Johansson (oej) 2007-01-09 06:30:33.000-0600

Please test again with latest 1.4 from svn. Thanks.
By: Alexander Tull (alex-911) 2007-01-12 15:11:59.000-0600

I upgraded to SVN-trunk-r50603 and repeated the test. no big difference but a BYE from asterisk to the ATA after the 488.
sip debug attached.
By: Alexander Tull (alex-911) 2007-01-12 15:16:57.000-0600

regarding your comment: "I guess you should not configure T.38 support on the device that receives the re-invite and the problem will be gone."

I wanted to force G.711 for this test so T.38 support on the device is disabled on purpose. or do you mean the T.38 support for that device in sip.conf of asterisk?
By: Olle Johansson (oej) 2007-02-15 15:35:15.000-0600

I mean that your asterisk configuration should follow the device configuration. If you have no T.38 support on the device (disabled) - why do you enable it in the device configuration on the asterisk side?

Good for testing though. At least we hangup the call properly now. Later we need to fix going back to an audio call, but that's a feature request.
By: Serge Vecher (serge-v) 2007-03-07 12:55:36.000-0600

alex-911, where are we with this report?
By: Alexander Tull (alex-911) 2007-03-22 03:42:48

still the same with SVN-trunk-r59083.
I'll give it a try again after the upgrade to 1.4.2
By: Serge Vecher (serge-v) 2007-03-22 08:31:14

ok, don't forget to attach a new console debug please.
By: Alexander Tull (alex-911) 2007-03-24 13:50:21

same results with 1.4.2

console log attached: verbosity 5, debug 5, sip debug
call setup as above
By: Olle Johansson (oej) 2007-11-15 06:42:03.000-0600

This is a feature request, not really a bug report for 1.4. This was never implemented in the T.38 passthrough code.

File is working with some major changes to the T.38 support that includes this new feature. Stay tuned. It will be based on Trunk though.
By: Digium Subversion (svnbot) 2008-03-10 14:56:28

Repository: asterisk
Revision: 107157

U   trunk/channels/chan_sip.c

------------------------------------------------------------------------
r107157 | file | 2008-03-10 14:56:24 -0500 (Mon, 10 Mar 2008) | 4 lines

If we receive a 488 on a T38 request reinvite back to audio. As well reinvite across a bridge back to audio if one side doesn't negotiate to T38.
(closes issue ASTERISK-8439)
Reported by: alex-911

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

http://svn.digium.com/view/asterisk?view=rev&revision=107157
By: Digium Subversion (svnbot) 2008-03-12 17:48:58

Repository: asterisk
Revision: 108354

_U  branches/1.6.0/
U   branches/1.6.0/channels/chan_sip.c

------------------------------------------------------------------------
r108354 | russell | 2008-03-12 17:48:57 -0500 (Wed, 12 Mar 2008) | 12 lines

Merged revisions 107157 via svnmerge from
https://origsvn.digium.com/svn/asterisk/trunk

........
r107157 | file | 2008-03-10 15:00:21 -0500 (Mon, 10 Mar 2008) | 4 lines

If we receive a 488 on a T38 request reinvite back to audio. As well reinvite across a bridge back to audio if one side doesn't negotiate to T38.
(closes issue ASTERISK-8439)
Reported by: alex-911

........

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

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