[Home]

Summary:ASTERISK-08110: T.38 Fallback fails
Reporter:jeffery palmer (darren1713)Labels:
Date Opened:2006-11-10 16:41:26.000-0600Date Closed:2011-06-07 14:02:42
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Channels/chan_sip/T.38
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) Full_Debug_T38_SVN-trunk-r47382M.txt
( 1) RTP_Debug_T38_SVN-trunk-r47382M.txt
( 2) RTP_Full_Debug_T38_SVN-trunk-r47382M.txt
( 3) T38_debug_SVN-trunk-r47382M.txt
Description:I have an incoming call via IAX that connects to a SIP gateway, and so faxing should occur strictly via ulaw and no T.38. Asterisk gets 90% of the way there, but as soon as the T.38 Invite comes back from the SIP gateway, all of the audio drops off. The behavior is the same whether t38pt_udptl is false or yes. It goes like this:

(OK) Call via IAX connects to SIP gateway
(OK) SIP gateway rings
(OK) SIP gateway answers and recognized fax machine at it's end
(OK) SIP gateway sends T.38 offer
(OK) Asterisk rejects offer with 488
(OK) SIP gateway responds OK with proper audio port #
(BAD)Asterisk doesn't pick up audio from the offered port and all audio ceases


The trace is below:

   -- Executing [870600719795@satdirect-dial:1] Dial("IAX2/jnctn-outbound-1", "SIP/870600719795@telnor") in new stack
Audio is at 216.219.244.206 port 15238
Adding codec 0x4 (ulaw) to SDP
Adding non-codec 0x1 (telephone-event) to SDP
Reliably Transmitting (no NAT) to 63.110.124.53:5060:
INVITE sip:870600719795@63.110.124.53 SIP/2.0
Via: SIP/2.0/UDP 216.219.244.206:5060;branch=z9hG4bK7ea147ac;rport
Max-Forwards: 70
From: "19547072498" <sip:19547072498@216.219.244.206>;tag=as3e0beb1f
To: <sip:870600719795@63.110.124.53>
Contact: <sip:19547072498@216.219.244.206>
Call-ID: 3cbc0de75b7bdc3a349fc1d056667364@216.219.244.206
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Date: Fri, 10 Nov 2006 22:28:26 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Type: application/sdp
Content-Length: 244

v=0
o=root 9840 9840 IN IP4 216.219.244.206
s=session
c=IN IP4 216.219.244.206
t=0 0
m=audio 15238 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

---
   -- Called 870600719795@telnor

<--- SIP read from 63.110.124.53:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 216.219.244.206:5060;branch=z9hG4bK7ea147ac;rport
From: "19547072498" <sip:19547072498@216.219.244.206>;tag=as3e0beb1f
To: <sip:870600719795@63.110.124.53>
Call-ID: 3cbc0de75b7bdc3a349fc1d056667364@216.219.244.206
CSeq: 102 INVITE
Content-Length: 0


<------------->
--- (7 headers 0 lines) ---

<--- SIP read from 63.110.124.53:5060 --->
SIP/2.0 180 Ringing
To: <sip:870600719795@63.110.124.53>;tag=3372186745-43354
From: "19547072498" <sip:19547072498@216.219.244.206>;tag=as3e0beb1f
Call-ID: 3cbc0de75b7bdc3a349fc1d056667364@216.219.244.206
CSeq: 102 INVITE
Contact: sip:870600719795@63.110.124.53:5060
Via: SIP/2.0/UDP 216.219.244.206:5060;branch=z9hG4bK7ea147ac;rport
Content-Length: 0


<------------->
--- (8 headers 0 lines) ---
   -- SIP/telnor-085c32b0 is ringing
[New Thread 1212444 (LWP 9909)]
[Thread 1212444 (LWP 9909) exited]
[New Thread 1228828 (LWP 9911)]
[Thread 1228828 (LWP 9911) exited]
Really destroying SIP dialog '36a6ccf020f34d6520d6d6e77210e096@216.219.244.206' Method: OPTIONS

<--- SIP read from 63.110.124.53:5060 --->
SIP/2.0 200 OK
To: <sip:870600719795@63.110.124.53>;tag=3372186745-43354
From: "19547072498" <sip:19547072498@216.219.244.206>;tag=as3e0beb1f
Call-ID: 3cbc0de75b7bdc3a349fc1d056667364@216.219.244.206
CSeq: 102 INVITE
Contact: sip:870600719795@63.110.124.53:5060
Content-Type: application/sdp
Via: SIP/2.0/UDP 216.219.244.206:5060;branch=z9hG4bK7ea147ac;rport
Content-Length: 227

v=0
o=shbysbc2 0 0 IN IP4 63.110.124.53
s=sip call
c=IN IP4 63.110.124.49
t=0 0
m=audio 10852 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=silenceSupp:off - - - -
a=ptime:20

<------------->
--- (9 headers 11 lines) ---
Found RTP audio format 0
Found RTP audio format 101
Peer audio RTP is at port 63.110.124.49:10852
Found description format PCMU for ID 0
Found description format telephone-event for ID 101
Got unsupported a:fmtp in SDP offer
Got unsupported a:ptime in SDP offer
Capabilities: us - 0x4 (ulaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
Peer audio RTP is at port 63.110.124.49:10852
--- set_address_from_contact host '63.110.124.53'
list_route: hop: <sip:870600719795@63.110.124.53:5060>
set_destination: Parsing <sip:870600719795@63.110.124.53:5060> for address/port to send to
set_destination: set destination to 63.110.124.53, port 5060
Transmitting (no NAT) to 63.110.124.53:5060:
ACK sip:870600719795@63.110.124.53:5060 SIP/2.0
Via: SIP/2.0/UDP 216.219.244.206:5060;branch=z9hG4bK37c13810;rport
Max-Forwards: 70
From: "19547072498" <sip:19547072498@216.219.244.206>;tag=as3e0beb1f
To: <sip:870600719795@63.110.124.53>;tag=3372186745-43354
Contact: <sip:19547072498@216.219.244.206>
Call-ID: 3cbc0de75b7bdc3a349fc1d056667364@216.219.244.206
CSeq: 102 ACK
User-Agent: Asterisk PBX
Content-Length: 0


---
   -- SIP/telnor-085c32b0 answered IAX2/jnctn-outbound-1
[New Thread 1245212 (LWP 9927)]
[Thread 1245212 (LWP 9927) exited]

<--- SIP read from 63.110.124.53:5060 --->
INVITE sip:19547072498@216.219.244.206 SIP/2.0
Max-Forwards: 69
Session-Expires: 3600;Refresher=uac
Supported: timer
To: "19547072498" <sip:19547072498@216.219.244.206>;tag=as3e0beb1f
From: <sip:870600719795@63.110.124.53>;tag=3372186745-43354
Call-ID: 3cbc0de75b7bdc3a349fc1d056667364@216.219.244.206
CSeq: 2 INVITE
Via: SIP/2.0/UDP 63.110.124.53:5060;branch=z9hG4bK82a3c142a57f20d149eccc6ea8eea8e6
Contact: sip:870600719795@63.110.124.53:5060
Content-Type: application/sdp
Content-Length: 348

v=0
o=shbysbc2 0 1 IN IP4 63.110.124.53
s=sip call
c=IN IP4 63.110.124.49
t=0 0
m=image 10852 udptl t38
a=T38FaxVersion:0
a=T38MaxBitRate:9600
a=T38FaxFillBitRemoval:0
a=T38FaxTranscodingMMR:0
a=T38FaxTranscodingJBIG:0
a=T38FaxRateManagement:transferredTCF
a=T38FaxMaxBuffer:200
a=T38FaxMaxDatagram:72
a=T38FaxUdpEC:t38UDPRedundancy

<------------->
--- (12 headers 15 lines) ---
Sending to 63.110.124.53 : 5060 (no NAT)
Got T.38 offer in SDP in dialog 3cbc0de75b7bdc3a349fc1d056667364@216.219.244.206
T38 state changed to 4 on channel SIP/telnor-085c32b0
Peer doesn't provide audio
Capabilities: us - 0x4 (ulaw), peer - audio=0x0 (nothing)/video=0x0 (nothing), combined - 0x0 (nothing)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing)

<--- Reliably Transmitting (no NAT) to 63.110.124.53:5060 --->
SIP/2.0 488 Not acceptable here
Via: SIP/2.0/UDP 63.110.124.53:5060;branch=z9hG4bK82a3c142a57f20d149eccc6ea8eea8e6;received=63.110.124.53
From: <sip:870600719795@63.110.124.53>;tag=3372186745-43354
To: "19547072498" <sip:19547072498@216.219.244.206>;tag=as3e0beb1f
Call-ID: 3cbc0de75b7bdc3a349fc1d056667364@216.219.244.206
CSeq: 2 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16


<------------>
Scheduling destruction of SIP dialog '3cbc0de75b7bdc3a349fc1d056667364@216.219.244.206' in 32000 ms (Method: INVITE)

<--- SIP read from 63.110.124.53:5060 --->
ACK sip:19547072498@216.219.244.206 SIP/2.0
Max-Forwards: 69
From: <sip:870600719795@63.110.124.53>;tag=3372186745-43354
To: "19547072498" <sip:19547072498@216.219.244.206>;tag=as3e0beb1f
Call-ID: 3cbc0de75b7bdc3a349fc1d056667364@216.219.244.206
CSeq: 2 ACK
Via: SIP/2.0/UDP 63.110.124.53:5060;branch=z9hG4bK82a3c142a57f20d149eccc6ea8eea8e6
Content-Length: 0


<------------->
--- (8 headers 0 lines) ---

<--- SIP read from 63.110.124.53:5060 --->
INVITE sip:19547072498@216.219.244.206 SIP/2.0
Max-Forwards: 69
Session-Expires: 3600;Refresher=uac
Supported: timer
To: "19547072498" <sip:19547072498@216.219.244.206>;tag=as3e0beb1f
From: <sip:870600719795@63.110.124.53>;tag=3372186745-43354
Call-ID: 3cbc0de75b7bdc3a349fc1d056667364@216.219.244.206
CSeq: 3 INVITE
Via: SIP/2.0/UDP 63.110.124.53:5060;branch=z9hG4bK004333154a9ed591cfc977f3f5c6c0e4
Contact: sip:870600719795@63.110.124.53:5060
Content-Type: application/sdp
Content-Length: 159

v=0
o=shbysbc2 0 2 IN IP4 63.110.124.53
s=sip call
c=IN IP4 63.110.124.49
t=0 0
m=audio 10852 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=silenceSupp:off - - - -

<------------->
--- (12 headers 8 lines) ---
Sending to 63.110.124.53 : 5060 (no NAT)
Found RTP audio format 0
Peer audio RTP is at port 63.110.124.49:10852
Found description format PCMU for ID 0
Capabilities: us - 0x4 (ulaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing)
Peer audio RTP is at port 63.110.124.49:10852
Audio is at 216.219.244.206 port 15238
Adding codec 0x4 (ulaw) to SDP

<--- Reliably Transmitting (no NAT) to 63.110.124.53:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 63.110.124.53:5060;branch=z9hG4bK004333154a9ed591cfc977f3f5c6c0e4;received=63.110.124.53
From: <sip:870600719795@63.110.124.53>;tag=3372186745-43354
To: "19547072498" <sip:19547072498@216.219.244.206>;tag=as3e0beb1f
Call-ID: 3cbc0de75b7bdc3a349fc1d056667364@216.219.244.206
CSeq: 3 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:19547072498@216.219.244.206>
Content-Type: application/sdp
Content-Length: 188

v=0
o=root 9840 9841 IN IP4 216.219.244.206
s=session
c=IN IP4 216.219.244.206
t=0 0
m=audio 15238 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

<------------>

<--- SIP read from 63.110.124.53:5060 --->
ACK sip:19547072498@216.219.244.206 SIP/2.0
Max-Forwards: 69
To: "19547072498" <sip:19547072498@216.219.244.206>;tag=as3e0beb1f
From: <sip:870600719795@63.110.124.53>;tag=3372186745-43354
Call-ID: 3cbc0de75b7bdc3a349fc1d056667364@216.219.244.206
CSeq: 3 ACK
Via: SIP/2.0/UDP 63.110.124.53:5060;branch=z9hG4bKaef3f790911838a02c968d18ef7f0bf7
Contact: sip:870600719795@63.110.124.53:5060
Content-Length: 0


<------------->
--- (9 headers 0 lines) ---
***
***
***
***
*** I hangup here since there is no audio
***
***
***
***
*CLI> Scheduling destruction of SIP dialog '3cbc0de75b7bdc3a349fc1d056667364@216.219.244.206' in 32000 ms (Method: ACK)
set_destination: Parsing <sip:870600719795@63.110.124.53:5060> for address/port to send to
set_destination: set destination to 63.110.124.53, port 5060
Reliably Transmitting (no NAT) to 63.110.124.53:5060:
BYE sip:870600719795@63.110.124.53:5060 SIP/2.0
Via: SIP/2.0/UDP 216.219.244.206:5060;branch=z9hG4bK7356e469;rport
Max-Forwards: 70
From: "19547072498" <sip:19547072498@216.219.244.206>;tag=as3e0beb1f
To: <sip:870600719795@63.110.124.53>;tag=3372186745-43354
Call-ID: 3cbc0de75b7bdc3a349fc1d056667364@216.219.244.206
CSeq: 103 BYE
User-Agent: Asterisk PBX
Content-Length: 0


---
 == Spawn extension (satdirect-dial, 870600719795, 1) exited non-zero on 'IAX2/jnctn-outbound-1'
   -- Executing [h@satdirect-dial:1] Hangup("IAX2/jnctn-outbound-1", "") in new stack
 == Spawn extension (satdirect-dial, h, 1) exited non-zero on 'IAX2/jnctn-outbound-1'
[New Thread 1261596 (LWP 9954)]
[Thread 1261596 (LWP 9954) exited]
   -- Hungup 'IAX2/jnctn-outbound-1'
[Thread 1179675 (LWP 9840) exited]

<--- SIP read from 63.110.124.53:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 216.219.244.206:5060;branch=z9hG4bK7356e469;rport
From: "19547072498" <sip:19547072498@216.219.244.206>;tag=as3e0beb1f
To: <sip:870600719795@63.110.124.53>;tag=3372186745-43354
Call-ID: 3cbc0de75b7bdc3a349fc1d056667364@216.219.244.206
CSeq: 103 BYE
Content-Length: 0


<------------->
--- (7 headers 0 lines) ---
SIP Response message for INCOMING dialog BYE arrived
[New Thread 1277979 (LWP 9955)]
Really destroying SIP dialog '3cbc0de75b7bdc3a349fc1d056667364@216.219.244.206' Method: ACK
[Thread 1277979 (LWP 9955) exited]
Comments:By: Olle Johansson (oej) 2006-11-12 08:52:36.000-0600

Please don't add debug output inline in the bug report, it needs to be an attachment.

So the story here goes like this:

1. We set up an audio call
2. We get a re-invite to T.38 that we deny, which means that the current call should be on
  Observe that Asterisk has a bug here and schedules a destruction of the call
3. We get a re-invite back to audio, but since Asterisk has destroyed the call, we're gone.

In summary: If we deny a T38 re-invite, go back to the original invite and don't hang up the call or destruct the bridge/RTP/RTCP.
By: Olle Johansson (oej) 2006-11-12 09:03:01.000-0600

Would you be able to see if you have the same behaviour in 1.4?
By: Olle Johansson (oej) 2006-11-12 09:28:05.000-0600

Committed changes to rev 47509 of Asterisk 1.4 and to trunk. Please test!

basically
- Don't destruct (hangup) the call if a T38 re-invite fails
- Keep RTP audio running even if we get a T38 re-invite, so we can fallback.
By: jeffery palmer (darren1713) 2006-11-13 22:09:06.000-0600

The call no longer schedules for destruction, but the audio still drops out.

Should the rtp stream for audio possibly stay active until a successful T.38 negotiation is completed instead of reconnecting?
By: Olle Johansson (oej) 2006-11-14 03:49:58.000-0600

Can you please take a full log with debug=4 and verbose=4 and sip debug turned on? Upload the file as an attachment to the bug report. thanks.
By: jeffery palmer (darren1713) 2006-11-14 07:38:32.000-0600

The new debug is already attached as a file. Do you want another one?
By: Olle Johansson (oej) 2006-11-14 07:49:45.000-0600

Sorry, did not see that. You need to enable debug output in logger conf, then set debug and verbose to 4 and capture everything. thanks.
By: Olle Johansson (oej) 2006-11-14 07:49:45.000-0600

Sorry, did not see that. You need to enable debug output in logger conf, then set debug and verbose to 4 and capture everything. thanks.
By: jeffery palmer (darren1713) 2006-11-14 12:23:36.000-0600

Full debug file has been uploaded.

I'm going to do some packet traces to see what the network traffic says about this.
By: Olle Johansson (oej) 2006-11-15 02:39:59.000-0600

try enabling rtp debug to see what's going on in that layer too.
By: jeffery palmer (darren1713) 2006-11-15 07:58:52.000-0600

It appears as though the rtp stream from the sip gateway to * stops after the T.38  offer is refused and ACK'd from the sip gateway.

Does * stop reading the stream or the gateway stop sending?
By: Olle Johansson (oej) 2006-11-15 15:32:06.000-0600

Seems like the gateway is stopping the stream to me. Please check with a sniffer.
By: jeffery palmer (darren1713) 2006-11-16 10:13:24.000-0600

I'm awaiting feedback from the manufacturer. Their equipment is a Nextone SBC. Do you know of any quirks with their hardware?
By: Serge Vecher (serge-v) 2007-01-09 12:56:42.000-0600

what's the status of this issue with the latest 1.4 branch code?
By: Tilghman Lesher (tilghman) 2007-02-05 15:56:55.000-0600

Given that you're waiting for a hardware vendor to respond, I'm going to suspend this bug for now.  Please feel free to reopen this bug when you have a response.