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

Tue Apr 2 07:29:47 CDT 2019

    [ https://issues.asterisk.org/jira/browse/ASTERISK-28370?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=246752#comment-246752 ] 

Asterisk Team commented on ASTERISK-28370:
------------------------------------------

Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution.

A good first step is for you to review the [Asterisk Issue Guidelines|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines] if you haven't already. The guidelines detail what is expected from an Asterisk issue report.

Then, if you are submitting a patch, please review the [Patch Contribution Process|https://wiki.asterisk.org/wiki/display/AST/Patch+Contribution+Process].

Please note that once your issue enters an open state it has been accepted. As Asterisk is an open source project there is no guarantee or timeframe on when your issue will be looked into. If you need expedient resolution you will need to find and pay a suitable developer. Asking for an update on your issue will not yield any progress on it and will not result in a response. All updates are posted to the issue when they occur.

> 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
>
> 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

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