[Home]

Summary:ASTERISK-24143: pjsip: Outbound call to WebRTC UA fails to transmit ACK on received 200 OK
Reporter:Aleksei Kulakov (Each)Labels:
Date Opened:2014-07-31 02:06:37Date Closed:2014-08-24 14:37:08
Priority:MajorRegression?
Status:Closed/CompleteComponents:Channels/chan_pjsip Resources/res_pjsip_transport_websocket
Versions:12.4.0 Frequency of
Occurrence		Constant
Related
Issues:
Environment:Ubuntu 14.04 PJProject(https://github.com/asterisk/pjproject 06/JUN/14) --enable-shared --disable-sound --disable-resample --disable-video --disable-opencore-amr --with-external-srtp CFLAGS="-g -DNDEBUG" chromium 35.0.1916.153(rev274914) (launch options: --use-fake-ui-for-media-stream --disable-webrtc-encryption) SIPml-api.js?svn=224Attachments:( 0) 354ChromeConsole.log
( 1) debuglog.1
( 2) pjsip.conf
Description:1. WebRTC callee accepts call from caller of any type.
2. Caller hangup.
3. WebRTC callee does not get BYE sip packet(staying "in call" forever) and asterisk dumps following message to log:
{quote}
WARNING[348] pjsip: tsx0xb68399d4 ...Failed to send Request msg BYE/cseq=9511 (tdta0xb6804798)! err=320053 (DNS "Name Error" (PJLIB_UTIL_EDNS_NXDOMAIN))
{quote}
Comments:By: Aleksei Kulakov (Each) 2014-07-31 02:21:45.935-0500

debuglog.1 - I dismissed call manually on WebRTC callee side at [Jul 31 10:24:09]
http.conf,  extensions.conf - default changes need to make webrtc calls possible
rtp.conf - unchanged
By: Abhay Gupta (agupta) 2014-08-07 07:25:20.145-0500

I am also facing the same issue and call remains Incall
By: Rusty Newton (rnewton) 2014-08-11 18:42:38.300-0500

Did you post the wrong configuration? I don't see any endpoints configured for a websocket transport in your config.

My comment on your other issue applies to this one as well. Regarding DTLS-SRTP encryption being mandated for WebRTC; can you reproduce this issue with encryption enabled?


By: Aleksei Kulakov (Each) 2014-08-12 04:05:54.396-0500

>>I don't see any endpoints configured for a websocket transport in your config.
You're wrong, 354 and 355 configured as webrtc endpoints using [endpoint-web] template, 6001 configured for sip-softphone using [endpoint-std] template.

*Reproduced with same results using DTLS(at aster and chrome sides) on latest Chrome stable and unstable(38.0.2114.2 dev)*

PS: You guys don't intended to support(work on) "no encryption" case for webrtc? Or you just want to be sure that it is not encryption related?


By: Abhay Gupta (agupta) 2014-08-12 04:54:29.467-0500

{noformat}
[101]
type=endpoint
disallow=all
allow=ulaw
context=default
auth=101
aors=101
media_encryption=dtls
dtls_verify=fingerprint
dtls_cert_file=/etc/asterisk/keys/asterisk.pem
dtls_ca_file=/etc/asterisk/keys/ca.crt
dtls_setup=actpass
use_avpf=yes
ice_support=yes
media_use_received_transport=yes

[101]
type=aor
max_contacts=2
remove_existing=yes

[101]
type=auth
auth_type=userpass
password=101
username=101
{noformat}

I am using encryption as voice does not go if encryption is not enabled . But the problem comes only when the call is disconnected from the callee end . If caller disconnects then both legs close normally .
By: Abhay Gupta (agupta) 2014-08-12 05:06:01.944-0500

Problem  terminated call log -

{noformat}
- Executing [101@default:1] NoOp("PJSIP/102-0000000c", "") in new stack
   -- Executing [101@default:2] Dial("PJSIP/102-0000000c", "PJSIP/101") in new stack
   -- Called PJSIP/101
   -- PJSIP/101-0000000d is ringing
   -- PJSIP/101-0000000d answered PJSIP/102-0000000c
   -- Channel PJSIP/102-0000000c joined 'simple_bridge' basic-bridge <bf9ca495-f20a-4fed-a6fc-2a131b777e7c>
   -- Channel PJSIP/101-0000000d joined 'simple_bridge' basic-bridge <bf9ca495-f20a-4fed-a6fc-2a131b777e7c>
[Aug 12 15:34:37] ERROR[2565]: pjsip:0 <?>: icess0x7f1c0c0 ..Error sending STUN request: Invalid argument
      > 0x7f1c08086390 -- Probation passed - setting RTP source address to 192.168.1.242:54869
      > 0x7f1c08067ef0 -- Probation passed - setting RTP source address to 192.168.1.161:49200
   -- Channel PJSIP/102-0000000c left 'simple_bridge' basic-bridge <bf9ca495-f20a-4fed-a6fc-2a131b777e7c>
 == Spawn extension (default, 101, 2) exited non-zero on 'PJSIP/102-0000000c'
   -- Channel PJSIP/101-0000000d left 'simple_bridge' basic-bridge <bf9ca495-f20a-4fed-a6fc-2a131b777e7c>
[Aug 12 15:35:10] WARNING[2547]: pjsip:0 <?>: tsx0x7f1c08014 ...Failed to send Request msg BYE/cseq=6421 (tdta0x7f1c08004130)! err=320053 (DNS "Name Error" (PJLIB_UTIL_EDNS_NXDOMAIN))
{noformat}
By: Abhay Gupta (agupta) 2014-08-12 05:09:02.234-0500

This is when the other end disconnects and call is properly terminated

{noformat}
-- Executing [101@default:1] NoOp("PJSIP/102-0000000e", "") in new stack
   -- Executing [101@default:2] Dial("PJSIP/102-0000000e", "PJSIP/101") in new stack
   -- Called PJSIP/101
   -- PJSIP/101-0000000f is ringing
   -- PJSIP/101-0000000f answered PJSIP/102-0000000e
   -- Channel PJSIP/102-0000000e joined 'simple_bridge' basic-bridge <6ba61987-c5d4-49db-9cea-a2e2987f1cf3>
   -- Channel PJSIP/101-0000000f joined 'simple_bridge' basic-bridge <6ba61987-c5d4-49db-9cea-a2e2987f1cf3>
      > 0x7f1c0809e9b0 -- Probation passed - setting RTP source address to 192.168.1.242:61054
[Aug 12 15:36:50] ERROR[2565]: pjsip:0 <?>: icess0x7f1c0c0 ..Error sending STUN request: Invalid argument
      > 0x7f1c080785b0 -- Probation passed - setting RTP source address to 192.168.1.161:58556
   -- Channel PJSIP/101-0000000f left 'simple_bridge' basic-bridge <6ba61987-c5d4-49db-9cea-a2e2987f1cf3>
   -- Channel PJSIP/102-0000000e left 'simple_bridge' basic-bridge <6ba61987-c5d4-49db-9cea-a2e2987f1cf3>
 == Spawn extension (default, 101, 2) exited non-zero on 'PJSIP/102-0000000e'
{noformat}
By: Matt Jordan (mjordan) 2014-08-14 09:52:23.346-0500

The root cause of this problem appears to be Asterisk failing to respond to the 200 OK received from the websocket client. The root cause of this appears to be the resolver attempting to resolve an invalid hostname (which is expected with WebRTC requests/responses):

{noformat}
[Jul 31 10:23:59] DEBUG[348] pjsip: inv0xb6812c94 ....Received Response msg 200/INVITE/cseq=9510 (rdata0xb683f30c), sending ACK
[Jul 31 10:23:59] DEBUG[348] pjsip:      endpoint ....Request msg ACK/cseq=9510 (tdta0xb6843280) created.
[Jul 31 10:23:59] DEBUG[348] pjsip: dlg0xb6812c94 .....Sending Request msg ACK/cseq=9510 (tdta0xb6843280)
[Jul 31 10:23:59] DEBUG[348] pjsip: sip_resolve.c .....Starting async DNS SRV query: target=_sip._udp.df7jal23ls0d.invalid, transport=WS, port=0
[Jul 31 10:23:59] DEBUG[348] pjsip: _sip._udp.df7j .....Starting async DNS SRV query_job: target=_sip._udp.df7jal23ls0d.invalid:5060
[Jul 31 10:23:59] DEBUG[348] pjsip:    resolver.c .....Nameserver 127.0.1.1:53 state changed Active --> Probing
[Jul 31 10:23:59] DEBUG[348] pjsip:    resolver.c .....Transmitting 48 bytes to NS 0 (127.0.1.1:53): DNS SRV query for _sip._udp.df7jal23ls0d.invalid: Success
[Jul 31 10:23:59] DEBUG[348] res_pjsip_session.c: Function session_inv_on_state_changed called on event TX_MSG
[Jul 31 10:23:59] DEBUG[348] res_pjsip_session.c: The state change pertains to the session with 354
[Jul 31 10:23:59] DEBUG[348] res_pjsip_session.c: The inv session still has an invite_tsx (0xb68399d4)
[Jul 31 10:23:59] DEBUG[348] res_pjsip_session.c: There is no transaction involved in this state change
[Jul 31 10:23:59] DEBUG[348] res_pjsip_session.c: The current inv state is CONFIRMED
[Jul 31 10:23:59] DEBUG[348] res_pjsip_session.c: Sending request
[Jul 31 10:23:59] DEBUG[348] res_pjsip_session.c: Method is ACK
[Jul 31 10:23:59] DEBUG[348] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Jul 31 10:23:59] DEBUG[348] res_pjsip_session.c: The state change pertains to the session with 354
[Jul 31 10:23:59] DEBUG[348] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[Jul 31 10:23:59] DEBUG[348] res_pjsip_session.c: The transaction involved in this state change is 0xb68399d4
[Jul 31 10:23:59] DEBUG[348] res_pjsip_session.c: The current transaction state is Terminated
[Jul 31 10:23:59] DEBUG[348] res_pjsip_session.c: The transaction state change event is RX_MSG
[Jul 31 10:23:59] DEBUG[348] res_pjsip_session.c: The current inv state is CONFIRMED
{noformat}

Unfortunately, {{res_pjsip_session}} is wrong: the ACK request is never actually sent.

By the time we get the BYE request from the WebRTC client (who initiates the hangup), things are now off the rails.