[asterisk-bugs] [JIRA] (ASTERISK-28370) Asterisk 16.x/PJSIP not accepting Audio Re-invite after T.38 rejection

Shane Short (JIRA) noreply at issues.asterisk.org
Tue Apr 2 07:31:47 CDT 2019


     [ https://issues.asterisk.org/jira/browse/ASTERISK-28370?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Shane Short updated ASTERISK-28370:
-----------------------------------

    Description: 
When sending an audio based fax, asterisk rejects any re-invites (including back to audio after a T.38 rejection). Call flow is as follows:

- Normal call setup using G711A
- Upstream detects Fax Preamble and sends T.38 re-invite
- As I have T.38 disabled (due to crashes which I shall report in future), we reject the re-invite with 488.
- The Upstream then re-invites us with G711A 
- Asterisk rejects this re-invite with another 488. 
- The upstream then sends a BYE.

I've tested this behavior using the same upstream and target number on Asterisk 11 w/chan-sip, and the call flow proceeds as you would expect. 

I have attached debug logging.

A successful Asterisk 11/chan-sip Negotiation with the same upstream peer: http://short.id.au/files/sip_trace_11.txt

  was:
When sending an audio based fax, asterisk rejects any re-invites (including back to audio after a T.38 rejection). Call flow is as follows:

- Normal call setup using G711A
- Upstream detects Fax Preamble and sends T.38 re-invite
- As I have T.38 disabled (due to crashes which I shall report in future), we reject the re-invite with 488.
- The Upstream then re-invites us with G711A 
- Asterisk rejects this re-invite with another 488. 
- The upstream then sends a BYE.

I've tested this behavior using the same upstream and target number on Asterisk 11 w/chan-sip, and the call flow proceeds as you would expect. 

Here is some debugging output from my debug logs showing the issue:

[Mar 25 19:06:35] VERBOSE[15371] res_pjsip_logger.c: <--- Received SIP request (921 bytes) from UDP:125.254.48.7:5060 --->
INVITE sip:asterisk at 10.128.0.166:5060 SIP/2.0
Via: SIP/2.0/UDP 125.254.48.7:5060;branch=z9hG4bK37124400;rport
Max-Forwards: 70
From: <sip:61862446791 at 125.254.48.7>;tag=as2e5a7ef3
To: "TOT_BIB_193_2" <sip:TOT_BIB_193_2 at 10.128.0.166>;tag=d8f37122-a185-4e74-a703-d76146f95cfb
Contact: <sip:61862446791 at 125.254.48.7:5060>
Call-ID: 233a19a3-fe96-484e-80a4-04b35dfbe46e
CSeq: 102 INVITE
User-Agent: VirtutelDevel-AST
Session-Expires: 1800;refresher=uac
Min-SE: 90
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 278

v=0
o=VirtutelDevel 1921351248 1921351249 IN IP4 125.254.48.7
s=VirtutelDevel-AST
c=IN IP4 125.254.48.7
t=0 0
m=image 12776 udptl t38
a=T38FaxVersion:0
a=T38MaxBitRate:14400
a=T38FaxRateManagement:transferredTCF
a=T38FaxMaxDatagram:393
a=T38FaxUdpEC:t38UDPRedundancy

[Mar 25 19:06:35] DEBUG[15371] netsock2.c: Splitting '125.254.48.7:5060' into...
[Mar 25 19:06:35] DEBUG[15371] netsock2.c: ...host '125.254.48.7' and port '5060'.
[Mar 25 19:06:35] DEBUG[15371] netsock2.c: Splitting '10.128.0.166:5060' into...
[Mar 25 19:06:35] DEBUG[15371] netsock2.c: ...host '10.128.0.166' and port '5060'.
[Mar 25 19:06:35] DEBUG[15371] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7f2e10018488 for Request msg INVITE/cseq=102 (rdata0x7f2e30007f38)
[Mar 25 19:06:35] DEBUG[15371] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/virtutel-syd-000000a1 associated with dialog dlg0x7f2e10018488
[Mar 25 19:06:35] DEBUG[16554] res_pjsip_t38.c: Not deferring incoming SDP stream: T.38 not enabled on PJSIP/virtutel-syd-00000047
[Mar 25 19:06:35] DEBUG[16554] res_pjsip_session.c: Negotiating incoming SDP media stream 'image' using image SDP handler
[Mar 25 19:06:35] DEBUG[16554] res_pjsip_t38.c: Declining; T.38 not enabled on session
[Mar 25 19:06:35] DEBUG[16554] res_pjsip_session.c: Declining incoming SDP media stream 'image' at position '0'
[Mar 25 19:06:35] DEBUG[16554] netsock2.c: Splitting '125.254.48.7' into...
[Mar 25 19:06:35] DEBUG[16554] netsock2.c: ...host '125.254.48.7' and port ''.
[Mar 25 19:06:35] DEBUG[16554] netsock2.c: Splitting '10.128.0.166:5060' into...
[Mar 25 19:06:35] DEBUG[16554] netsock2.c: ...host '10.128.0.166' and port '5060'.
[Mar 25 19:06:35] DEBUG[16554] netsock2.c: Splitting '125.254.48.7:5060' into...
[Mar 25 19:06:35] DEBUG[16554] netsock2.c: ...host '125.254.48.7' and port '5060'.
[Mar 25 19:06:35] VERBOSE[16554] res_pjsip_logger.c: <--- Transmitting SIP response (679 bytes) to UDP:125.254.48.7:5060 --->
SIP/2.0 488 Not Acceptable Here
Via: SIP/2.0/UDP 125.254.48.7:5060;rport=5060;received=125.254.48.7;branch=z9hG4bK37124400
Call-ID: 233a19a3-fe96-484e-80a4-04b35dfbe46e
From: <sip:61862446791 at 125.254.48.7>;tag=as2e5a7ef3
To: "TOT_BIB_193_2" <sip:TOT_BIB_193_2 at 10.128.0.166>;tag=d8f37122-a185-4e74-a703-d76146f95cfb
CSeq: 102 INVITE
Accept: application/simple-message-summary, application/pidf+xml, application/dialog-info+xml, application/xpidf+xml, application/cpim-pidf+xml, application/simple-message-summary, application/pidf+xml, application/dialog-info+xml, application/sdp, message/sipfrag;version=2.0
Server: Asterisk PBX 16.2.1~dfsg-0~ppa2
Content-Length:  0


INVITE sip:asterisk at 10.128.0.166:5060 SIP/2.0
Via: SIP/2.0/UDP 125.254.48.7:5060;branch=z9hG4bK17c4547d;rport
Max-Forwards: 70
From: <sip:61862446791 at 125.254.48.7>;tag=as2e5a7ef3
To: "TOT_BIB_193_2" <sip:TOT_BIB_193_2 at 10.128.0.166>;tag=d8f37122-a185-4e74-a703-d76146f95cfb
Contact: <sip:61862446791 at 125.254.48.7:5060>
Call-ID: 233a19a3-fe96-484e-80a4-04b35dfbe46e
CSeq: 103 INVITE
User-Agent: VirtutelDevel-AST
Session-Expires: 1800;refresher=uac
Min-SE: 90
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 242

v=0
o=VirtutelDevel 1921351248 1921351250 IN IP4 125.254.48.7
s=VirtutelDevel-AST
c=IN IP4 125.254.48.7
t=0 0
m=audio 12254 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

[Mar 25 19:06:35] DEBUG[15371] netsock2.c: Splitting '125.254.48.7:5060' into...
[Mar 25 19:06:35] DEBUG[15371] netsock2.c: ...host '125.254.48.7' and port '5060'.
[Mar 25 19:06:35] DEBUG[15371] netsock2.c: Splitting '10.128.0.166:5060' into...
[Mar 25 19:06:35] DEBUG[15371] netsock2.c: ...host '10.128.0.166' and port '5060'.
[Mar 25 19:06:35] DEBUG[15371] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7f2e10018488 for Request msg INVITE/cseq=103 (rdata0x7f2e30007f38)
[Mar 25 19:06:35] DEBUG[15371] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/virtutel-syd-000000a1 associated with dialog dlg0x7f2e10018488
[Mar 25 19:06:35] DEBUG[16554] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Mar 25 19:06:35] DEBUG[16554] res_pjsip_session.c: The state change pertains to the endpoint 'virtutel-syd(PJSIP/virtutel-syd-00000047)'
[Mar 25 19:06:35] DEBUG[16554] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f2e10052c58)
[Mar 25 19:06:35] DEBUG[16554] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f2e10052c58
[Mar 25 19:06:35] DEBUG[16554] res_pjsip_session.c: The current transaction state is Confirmed
[Mar 25 19:06:35] DEBUG[16554] res_pjsip_session.c: The transaction state change event is RX_MSG
[Mar 25 19:06:35] DEBUG[16554] res_pjsip_session.c: The current inv state is CONFIRMED
[Mar 25 19:06:35] DEBUG[16554] res_pjsip_session.c: Received request
[Mar 25 19:06:35] DEBUG[16554] res_pjsip_session.c: Method is ACK
[Mar 25 19:06:35] DEBUG[16554] res_pjsip_session.c: Negotiating incoming SDP media stream 'image' using audio SDP handler
[Mar 25 19:06:35] DEBUG[16554] res_pjsip_sdp_rtp.c: Endpoint has no codecs for media type 'image', declining stream
[Mar 25 19:06:35] DEBUG[16554] res_pjsip_session.c: Declining incoming SDP media stream 'audio' at position '0'
[Mar 25 19:06:35] DEBUG[16554] netsock2.c: Splitting '125.254.48.7' into...
[Mar 25 19:06:35] DEBUG[16554] netsock2.c: ...host '125.254.48.7' and port ''.
[Mar 25 19:06:35] DEBUG[16554] netsock2.c: Splitting '10.128.0.166:5060' into...
[Mar 25 19:06:35] DEBUG[16554] netsock2.c: ...host '10.128.0.166' and port '5060'.
[Mar 25 19:06:35] DEBUG[16554] netsock2.c: Splitting '125.254.48.7:5060' into...
[Mar 25 19:06:35] DEBUG[16554] netsock2.c: ...host '125.254.48.7' and port '5060'.
[Mar 25 19:06:35] VERBOSE[16554] res_pjsip_logger.c: <--- Transmitting SIP response (679 bytes) to UDP:125.254.48.7:5060 --->
SIP/2.0 488 Not Acceptable Here
Via: SIP/2.0/UDP 125.254.48.7:5060;rport=5060;received=125.254.48.7;branch=z9hG4bK17c4547d
Call-ID: 233a19a3-fe96-484e-80a4-04b35dfbe46e
From: <sip:61862446791 at 125.254.48.7>;tag=as2e5a7ef3
To: "TOT_BIB_193_2" <sip:TOT_BIB_193_2 at 10.128.0.166>;tag=d8f37122-a185-4e74-a703-d76146f95cfb
CSeq: 103 INVITE
Accept: application/simple-message-summary, application/pidf+xml, application/dialog-info+xml, application/xpidf+xml, application/cpim-pidf+xml, application/simple-message-summary, application/pidf+xml, application/dialog-info+xml, application/sdp, message/sipfrag;version=2.0
Server: Asterisk PBX 16.2.1~dfsg-0~ppa2
Content-Length:  0

A successful Asterisk 11/chan-sip Negotiation with the same upstream peer: http://short.id.au/files/sip_trace_11.txt


> Asterisk 16.x/PJSIP not accepting Audio Re-invite after T.38 rejection
> ----------------------------------------------------------------------
>
>                 Key: ASTERISK-28370
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-28370
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>          Components: pjproject/pjsip
>    Affects Versions: 16.2.1
>         Environment: Asterisk Version: Asterisk 16.2.1
> Operationg System: Ubuntu 18.04.1 
> Kernel: 4.15.0-44-generic
> PJSIP Version: PJPROJECT version currently running against: 2.8
>            Reporter: Shane Short
>              Labels: fax, pjsip
>         Attachments: debug, pjsip.conf
>
>
> When sending an audio based fax, asterisk rejects any re-invites (including back to audio after a T.38 rejection). Call flow is as follows:
> - Normal call setup using G711A
> - Upstream detects Fax Preamble and sends T.38 re-invite
> - As I have T.38 disabled (due to crashes which I shall report in future), we reject the re-invite with 488.
> - The Upstream then re-invites us with G711A 
> - Asterisk rejects this re-invite with another 488. 
> - The upstream then sends a BYE.
> I've tested this behavior using the same upstream and target number on Asterisk 11 w/chan-sip, and the call flow proceeds as you would expect. 
> I have attached debug logging.
> A successful Asterisk 11/chan-sip Negotiation with the same upstream peer: http://short.id.au/files/sip_trace_11.txt



--
This message was sent by Atlassian JIRA
(v6.2#6252)



More information about the asterisk-bugs mailing list