One way audio when calling one person and two way audio when calling another, same setup on my end

2,677 views
Skip to first unread message

Shaun

unread,
Apr 3, 2013, 4:50:12 PM4/3/13
to discuss...@googlegroups.com
So when I call person A, it works great and I see in the Chrome debug logs something like this:

[1794:9495:0403/134418:VERBOSE4:port.cc(1091)] Jingle:Conn[audio:EIgstJEu:1:0:local:udp:10.0.1.3:65002->:1:0:local:udp:198.61.XX.XX:13798|CRWS|1305]: Sending STUN ping AkPJcNIzcHme at 9652099
[1794:9495:0403/134418:VERBOSE4:port.cc(1021)] Jingle:Conn[audio:EIgstJEu:1:0:local:udp:10.0.1.3:65002->:2:0:local:udp:198.61.XX.XX:13799|CRWS|1305]: UpdateState(): pings_since_last_response_=, rtt=2610, now=9652099
[1794:9495:0403/134418:VERBOSE4:port.cc(1091)] Jingle:Conn[audio:EIgstJEu:1:0:local:udp:10.0.1.3:65002->:2:0:local:udp:198.61.XX.XX:13799|CRWS|1305]: Sending STUN ping clrH3WZximtY at 9652099
[1794:9495:0403/134419:VERBOSE4:port.cc(868)] Jingle:Conn[audio:EIgstJEu:1:0:local:udp:10.0.1.3:65002->:1:0:local:udp:198.61.XX.XX:13798|CRWS|1305]: set_state
[1794:9495:0403/134419:VERBOSE4:port.cc(1172)] Jingle:Conn[audio:EIgstJEu:1:0:local:udp:10.0.1.3:65002->:1:0:local:udp:198.61.XX.XX:13798|CRWS|1305]: Received STUN ping response AkPJcNIzcHme, pings_since_last_response_=9652099 , rtt=61
[1794:9495:0403/134419:VERBOSE4:port.cc(868)] Jingle:Conn[audio:EIgstJEu:1:0:local:udp:10.0.1.3:65002->:2:0:local:udp:198.61.XX.XX:13799|CRWS|1305]: set_state
[1794:9495:0403/134419:VERBOSE4:port.cc(1172)] Jingle:Conn[audio:EIgstJEu:1:0:local:udp:10.0.1.3:65002->:2:0:local:udp:198.61.XX.XX:13799|CRWS|1305]: Received STUN ping response clrH3WZximtY, pings_since_last_response_=9652099 , rtt=61
[1883:1799:0403/134419:VERBOSE1:chrome_v8_context.cc(126)] Could not execute chrome hidden method: dispatchOnUnload
[1883:1799:0403/134419:VERBOSE1:dispatcher.cc(873)] Num tracked contexts: 0
[1883:18951:0403/134419:VERBOSE1:ipc_sync_channel.cc(385)] Canceling pending sends
[1794:9495:0403/134419:VERBOSE4:port.cc(1021)] Jingle:Conn[audio:EIgstJEu:1:0:local:udp:10.0.1.3:65002->:1:0:local:udp:198.61.XX.XX:13798|CRWS|994]: UpdateState(): pings_since_last_response_=, rtt=1988, now=9652580
[1794:9495:0403/134419:VERBOSE4:port.cc(1091)] Jingle:Conn[audio:EIgstJEu:1:0:local:udp:10.0.1.3:65002->:1:0:local:udp:198.61.XX.XX:13798|CRWS|994]: Sending STUN ping XxjRNCl6UQ2x at 9652580
[1794:9495:0403/134419:VERBOSE4:port.cc(1021)] Jingle:Conn[audio:EIgstJEu:1:0:local:udp:10.0.1.3:65002->:2:0:local:udp:198.61.XX.XX:13799|CRWS|994]: UpdateState(): pings_since_last_response_=, rtt=1988, now=9652580

When I call person B, I see something like this:

[1794:9495:0403/134116:VERBOSE1:port.cc(289)] Jingle:Port[audio:1:0::Net[en0:10.0.1.3/32]]: Received non-STUN packet from unknown address (198.61.XX.XX:11036)
[1794:9495:0403/134116:VERBOSE1:port.cc(289)] Jingle:Port[audio:1:0::Net[en0:10.0.1.3/32]]: Received non-STUN packet from unknown address (198.61.XX.XX:11036)
[1794:9495:0403/134116:VERBOSE1:port.cc(289)] Jingle:Port[audio:1:0::Net[en0:10.0.1.3/32]]: Received non-STUN packet from unknown address (198.61.XX.XX:11036)
[1794:9495:0403/134116:VERBOSE1:port.cc(289)] Jingle:Port[audio:1:0::Net[en0:10.0.1.3/32]]: Received non-STUN packet from unknown address (198.61.XX.XX:11036)
[1794:9495:0403/134116:VERBOSE1:port.cc(289)] Jingle:Port[audio:1:0::Net[en0:10.0.1.3/32]]: Received non-STUN packet from unknown address (198.61.XX.XX:11036)
[1794:9495:0403/134116:VERBOSE1:port.cc(289)] Jingle:Port[audio:1:0::Net[en0:10.0.1.3/32]]: Received non-STUN packet from unknown address (198.61.XX.XX:11036)
[1794:9495:0403/134116:VERBOSE1:port.cc(289)] Jingle:Port[audio:1:0::Net[en0:10.0.1.3/32]]: Received non-STUN packet from unknown address (198.61.XX.XX:11036)
[1794:9495:0403/134116:VERBOSE1:port.cc(289)] Jingle:Port[audio:1:0::Net[en0:10.0.1.3/32]]: Received non-STUN packet from unknown address (198.61.XX.XX:11036)
[1794:9495:0403/134116:VERBOSE1:port.cc(289)] Jingle:Port[audio:1:0::Net[en0:10.0.1.3/32]]: Received non-STUN packet from unknown address (198.61.XX.XX:11036)
[1794:9495:0403/134116:VERBOSE1:port.cc(289)] Jingle:Port[audio:1:0::Net[en0:10.0.1.3/32]]: Received non-STUN packet from unknown address (198.61.XX.XX:11036)
[1794:9495:0403/134116:VERBOSE1:port.cc(289)] Jingle:Port[audio:1:0::Net[en0:10.0.1.3/32]]: Received non-STUN packet from unknown address (198.61.XX.XX:11036)
[1794:9495:0403/134116:VERBOSE1:port.cc(289)] Jingle:Port[audio:1:0::Net[en0:10.0.1.3/32]]: Received non-STUN packet from unknown address (198.61.XX.XX:11036)
[1794:9495:0403/134116:VERBOSE1:port.cc(289)] Jingle:Port[audio:1:0::Net[en0:10.0.1.3/32]]: Received non-STUN packet from unknown address (198.61.XX.XX:11036)

Why would changing the person I was calling result in such a drastic difference with no other changes? I am using Chrome Stable (26.0.1410.43). Thanks!

Shaun

Vikas

unread,
Apr 3, 2013, 8:19:55 PM4/3/13
to discuss-webrtc
Hi,

Would definitely need more details. There is an issue related to one
way audio in M26. You can refer to here :-
https://code.google.com/p/webrtc/issues/detail?id=1525.
When you say one-way audio which side gets no audio? What OS are you
testing on? Feel free to add all information to issue 1525 if the
problem symptoms are similar, or file a new one with the details.

/Vikas

On Apr 3, 1:50 pm, Shaun <shaun.cl...@a-cti.com> wrote:
> So when I call person A, it works great and I see in the Chrome debug logs
> something like this:
>
> [1794:9495:0403/134418:VERBOSE4:port.cc(1091)]
> Jingle:Conn[audio:EIgstJEu:1:0:local:udp:10.0.1.3:65002->:1:0:local:udp:198 .61.XX.XX:13798|CRWS|1305]:
> Sending STUN ping AkPJcNIzcHme at 9652099
> [1794:9495:0403/134418:VERBOSE4:port.cc(1021)]
> Jingle:Conn[audio:EIgstJEu:1:0:local:udp:10.0.1.3:65002->:2:0:local:udp:198 .61.XX.XX:13799|CRWS|1305]:
> UpdateState(): pings_since_last_response_=, rtt=2610, now=9652099
> [1794:9495:0403/134418:VERBOSE4:port.cc(1091)]
> Jingle:Conn[audio:EIgstJEu:1:0:local:udp:10.0.1.3:65002->:2:0:local:udp:198 .61.XX.XX:13799|CRWS|1305]:
> Sending STUN ping clrH3WZximtY at 9652099
> [1794:9495:0403/134419:VERBOSE4:port.cc(868)]
> Jingle:Conn[audio:EIgstJEu:1:0:local:udp:10.0.1.3:65002->:1:0:local:udp:198 .61.XX.XX:13798|CRWS|1305]:
> set_state
> [1794:9495:0403/134419:VERBOSE4:port.cc(1172)]
> Jingle:Conn[audio:EIgstJEu:1:0:local:udp:10.0.1.3:65002->:1:0:local:udp:198 .61.XX.XX:13798|CRWS|1305]:
> Received STUN ping response AkPJcNIzcHme,
> pings_since_last_response_=9652099 , rtt=61
> [1794:9495:0403/134419:VERBOSE4:port.cc(868)]
> Jingle:Conn[audio:EIgstJEu:1:0:local:udp:10.0.1.3:65002->:2:0:local:udp:198 .61.XX.XX:13799|CRWS|1305]:
> set_state
> [1794:9495:0403/134419:VERBOSE4:port.cc(1172)]
> Jingle:Conn[audio:EIgstJEu:1:0:local:udp:10.0.1.3:65002->:2:0:local:udp:198 .61.XX.XX:13799|CRWS|1305]:
> Received STUN ping response clrH3WZximtY,
> pings_since_last_response_=9652099 , rtt=61
> [1883:1799:0403/134419:VERBOSE1:chrome_v8_context.cc(126)] Could not
> execute chrome hidden method: dispatchOnUnload
> [1883:1799:0403/134419:VERBOSE1:dispatcher.cc(873)] Num tracked contexts: 0
> [1883:18951:0403/134419:VERBOSE1:ipc_sync_channel.cc(385)] Canceling
> pending sends
> [1794:9495:0403/134419:VERBOSE4:port.cc(1021)]
> Jingle:Conn[audio:EIgstJEu:1:0:local:udp:10.0.1.3:65002->:1:0:local:udp:198 .61.XX.XX:13798|CRWS|994]:
> UpdateState(): pings_since_last_response_=, rtt=1988, now=9652580
> [1794:9495:0403/134419:VERBOSE4:port.cc(1091)]
> Jingle:Conn[audio:EIgstJEu:1:0:local:udp:10.0.1.3:65002->:1:0:local:udp:198 .61.XX.XX:13798|CRWS|994]:
> Sending STUN ping XxjRNCl6UQ2x at 9652580
> [1794:9495:0403/134419:VERBOSE4:port.cc(1021)]
> Jingle:Conn[audio:EIgstJEu:1:0:local:udp:10.0.1.3:65002->:2:0:local:udp:198 .61.XX.XX:13799|CRWS|994]:

Brave Yao

unread,
Apr 3, 2013, 10:50:46 PM4/3/13
to discuss...@googlegroups.com
Hi Shaun,

Please provide more info per Vikas' request. Can't tell anything with such limited info.
Also please try to reproduce with Apprtc demo and collect chrome log. It's better to create another issue with the test result with Apprtc demo. We can follow it there.

/Brave

James Mortensen

unread,
Apr 4, 2013, 12:02:13 PM4/4/13
to discuss...@googlegroups.com
Hi Vikas,

These calls are from Chrome Stable to Asterisk 11.4-rc1 to the PSTN.  The person on the PSTN receives the audio, but the person in Chrome does not.  We see RTP packets on the Asterisk instance going both ways, and we've done tcpdumps on our computers to verify that we're receiving the RTP stream.

We're testing with Mac OS, but we just tried with a Windows 7 OS on Chrome Stable and see the same behavior; hence, it's not a Mac-only bug.

Please let me know if you have any other questions.  As an aside, I'm not a thread hijacker. ;)  Shaun and I are working on this together.

James

James Mortensen

unread,
Apr 4, 2013, 2:51:41 PM4/4/13
to discuss...@googlegroups.com
Hi Vikas,

We dug into the libjingle code a little trying to find out why we're getting these errors.  We're not seeing any of the errors from in the https://code.google.com/p/libjingle/source/browse/trunk/talk/p2p/base/port.cc#315 GetStunMessage method of port.cc in libjingle

When we see the following in our logs:

[6282:6151:0404/114254:VERBOSE2:port.cc(913)] Jingle:Conn[audio:e3nQtDzG:1:0:local:udp:10.0.1.6:57608->:1:0:local:udp:198.61.170.55:15390|C-WS|68]: Received non-STUN packet from an unreadable connection.
[6282:6151:0404/114254:VERBOSE2:port.cc(913)] Jingle:Conn[audio:e3nQtDzG:1:0:local:udp:10.0.1.6:57608->:1:0:local:udp:198.61.170.55:15390|C-WS|68]: Received non-STUN packet from an unreadable connection.
[6282:6151:0404/114254:VERBOSE2:port.cc(913)] Jingle:Conn[audio:e3nQtDzG:1:0:local:udp:10.0.1.6:57608->:1:0:local:udp:198.61.170.55:15390|C-WS|68]: Received non-STUN packet from an unreadable connection.
[6282:6151:0404/114254:VERBOSE2:port.cc(913)] Jingle:Conn[audio:e3nQtDzG:1:0:local:udp:10.0.1.6:57608->:1:0:local:udp:198.61.170.55:15390|C-WS|68]: Received non-STUN packet from an unreadable connection.
[6282:6151:0404/114254:VERBOSE2:port.cc(913)] Jingle:Conn[audio:e3nQtDzG:1:0:local:udp:10.0.1.6:57608->:1:0:local:udp:198.61.170.55:15390|C-WS|68]: Received non-STUN packet from an unreadable connection.
[6282:6151:0404/114254:VERBOSE2:port.cc(913)] Jingle:Conn[audio:e3nQtDzG:1:0:local:udp:10.0.1.6:57608->:1:0:local:udp:198.61.170.55:15390|C-WS|68]: Received non-STUN packet from an unreadable connection.
[6282:6151:0404/114254:VERBOSE2:port.cc(913)] Jingle:Conn[audio:e3nQtDzG:1:0:local:udp:10.0.1.6:57608->:1:0:local:udp:198.61.170.55:15390|C-WS|68]: Received non-STUN packet from an unreadable connection.
[6282:6151:0404/114254:VERBOSE2:port.cc(913)] Jingle:Conn[audio:e3nQtDzG:1:0:local:udp:10.0.1.6:57608->:1:0:local:udp:198.61.170.55:15390|C-WS|68]: Received non-STUN packet from an unreadable connection.

we notice that we don't see any of the other error messages from the GetStunMessage method. This makes us think that the logic is not heading into any of the if/else branches and is instead hitting the very last default case in that method:

  // Return the STUN message found.
  *out_msg = stun_msg.release();
  return true; We noticed in the code that this is the only area where there is no logs. Any ideas? Should we file this as an issue? Thanks! James

On Wednesday, April 3, 2013 5:19:55 PM UTC-7, Vikas wrote:

James Mortensen

unread,
Apr 4, 2013, 3:42:29 PM4/4/13
to discuss...@googlegroups.com
Correction!  We were looking at the code wrong.  It's actually FALSE that's being returned from GetStunMessage; otherwise, we'd never see the unreadable connection warnings...

Thus, we've narrowed it down to one of these two conditions in port.cc.  

  // Don't bother parsing the packet if we can tell it's not STUN.
  // In ICE mode, all STUN packets will have a valid fingerprint.
  if (ice_protocol_ == ICEPROTO_RFC5245 &&
    !StunMessage::ValidateFingerprint(data, size)) {
    return false;
  }

  // Parse the request message.  If the packet is not a complete and correct
  // STUN message, then ignore it.
  talk_base::scoped_ptr<IceMessage> stun_msg(new IceMessage());
  talk_base::ByteBuffer buf(data, size);
  if (!stun_msg->Read(&buf) || (buf.Length() > 0)) {
    return false;
  } We believe this is a bug in Chrome. I tried using different STUN servers with the same result. We used: - stun.l.google.com:19302 - stunserver.org Hope this helps! James

James Mortensen

unread,
Apr 4, 2013, 3:48:55 PM4/4/13
to discuss...@googlegroups.com
One more update.  To see these logs, you must start Chrome from the command line with verbose logging enabled as follows:

    /Applications/Google\ Chrome.app/Contents/MacOS/Google\ Chrome --enable-logging --v=11

Then go to ~/Library/Application Support/Google/Chrome and then tail chrome_debug.log to see the log messages

We use v=11 because lower verbosity values weren't giving the full picture.

James


On Wednesday, April 3, 2013 1:50:12 PM UTC-7, Shaun wrote:

Mallinath Bareddy

unread,
Apr 4, 2013, 4:57:05 PM4/4/13
to discuss...@googlegroups.com
If you think the problem is in one of the conditions you mentioned, either first packet received by the chrome is not a STUN packet or not encoded as per RFC 5389.

It may be worth attaching wireshark traces to this thread.


--
 
---
You received this message because you are subscribed to the Google Groups "discuss-webrtc" group.
To unsubscribe from this group and stop receiving emails from it, send an email to discuss-webrt...@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.
 
 

James Mortensen

unread,
Apr 4, 2013, 5:39:03 PM4/4/13
to discuss...@googlegroups.com
That's what we're thinking. We're thinking these are audio packets, but Chrome is trying to process them as STUN packets.  Attached is a pcap.

James
onewaycapture.pcap

Mallinath Bareddy

unread,
Apr 4, 2013, 5:48:23 PM4/4/13
to discuss...@googlegroups.com
For ICE to work (irrespective of Chrome), first packet sent from the Candidate Pair ( aka Connection) should be a STUN binding request(Connectivity Check). If this  Connection is not established, media should not be sent. 

In this scenario, Chrome doesn't have a Connection with the remote address where "this" packet came, and Chrome expects first packet to be a STUN packet. Chrome is working as expected, unless a STUN packet already sent but still chrome complains about not receiving it and throwing this error.

/Mallinath

James Mortensen

unread,
Apr 4, 2013, 6:25:30 PM4/4/13
to discuss...@googlegroups.com
The STUN server appears to be sending back a successful response:

    Binding Success Response MAPPED-ADDRESS: 50.43.x.x:45681 

This is coming from the stun server to my local IP.  So does this mean that Chrome is still just complaining it didn't receive it even though the trace shows it did?

Thanks,
James

Justin Uberti

unread,
Apr 4, 2013, 6:46:41 PM4/4/13
to discuss-webrtc
I believe the problem is that B isn't sending a binding request to Chrome. This is different than the request sent to the STUN server.

James Mortensen

unread,
Apr 4, 2013, 6:59:15 PM4/4/13
to discuss...@googlegroups.com
Hi Justin, thanks for your reply.  

What is B?  

Attached are screenshots from wireshark that show Binding success sent back to the destination 10.0.1.3, which is the Chrome client.  

Also, anything in these SDP's that could factor in?  

INVITE sip:+13077...@107.22.YY.YY SIP/2.0
Via: SIP/2.0/WS itnbgvqn7m64.invalid;branch=z9hG4bK4600684
Max-Forwards: 69
To: <sip:+13077...@107.22.YY.YY>
From: <sip:99...@107.22.YY.YY>;tag=dg7rvkkkj2
Call-ID: t4s0h2ct0327am8aanhr
CSeq: 9310 INVITE
Proxy-Authorization: Digest algorithm=MD5, username="99235", realm="107.22.YY.YY", nonce="515dfb4b000040c78ad049084935b30159abb6ec35c5eba2", uri="sip:+13077...@107.22.YY.YY", response="cea5f199f7851bb9a5e4b76da79e801f"
X-Foo: foo
X-Bar: bar
Contact: <sip:99...@107.22.YY.YY;gr=urn:uuid:319ce3ba-fd6f-416c-b18e-38fa2777cca3;ob>
Allow: ACK,CANCEL,BYE,OPTIONS,INVITE
Content-Type: application/sdp
Supported: path, outbound, gruu
User-Agent: JsSIP 0.3.0-devel
Content-Length: 1630

v=0
o=- 1175073233 2 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE audio
a=msid-semantic: WMS H6tuO9HZOwLZ61cx2oBejoDeHSkeekVAR0yG
m=audio 45835 RTP/SAVPF 103 104 111 0 8 107 106 105 13 126
c=IN IP4 50.43.XX.XX
a=rtcp:45835 IN IP4 50.43.XX.XX
a=candidate:3703427737 1 udp 2113937151 10.0.1.6 64605 typ host generation 0
a=candidate:3703427737 2 udp 2113937151 10.0.1.6 64605 typ host generation 0
a=candidate:3822794416 1 udp 1845501695 50.43.XX.XX 45835 typ srflx raddr 10.0.1.6 rport 64605 generation 0
a=candidate:3822794416 2 udp 1845501695 50.43.XX.XX 45835 typ srflx raddr 10.0.1.6 rport 64605 generation 0
a=candidate:2453548649 1 tcp 1509957375 10.0.1.6 63406 typ host generation 0
a=candidate:2453548649 2 tcp 1509957375 10.0.1.6 63406 typ host generation 0
a=ice-ufrag:vpJjHZNbrLBfJf04
a=ice-pwd:fum4GBZH3aTFtnDDL9kjaiGq
a=ice-options:google-ice
a=sendrecv
a=mid:audio
a=rtcp-mux
a=crypto:0 AES_CM_128_HMAC_SHA1_32 inline:bJ/AAZo+owvIw2fNpdAxNg9dXC28bfXaBZyYopno
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:CeEMC8Kn0enEGJ8qBQaT8MlTFkpPMNPW/uwd0ho4
a=rtpmap:103 ISAC/16000
a=rtpmap:104 ISAC/32000
a=rtpmap:111 opus/48000/2
a=fmtp:111 minptime=10
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:107 CN/48000
a=rtpmap:106 CN/32000
a=rtpmap:105 CN/16000
a=rtpmap:13 CN/8000
a=rtpmap:126 telephone-event/8000
a=maxptime:60
a=ssrc:813833755 cname:+ftGrNqlu8P0tQ0H
a=ssrc:813833755 msid:H6tuO9HZOwLZ61cx2oBejoDeHSkeekVAR0yG H6tuO9HZOwLZ61cx2oBejoDeHSkeekVAR0yGa0
a=ssrc:813833755 mslabel:H6tuO9HZOwLZ61cx2oBejoDeHSkeekVAR0yG
a=ssrc:813833755 label:H6tuO9HZOwLZ61cx2oBejoDeHSkeekVAR0yGa0




Via: SIP/2.0/UDP 198.61.XX.XX:5060;branch=z9hG4bK771f4743;rport
Max-Forwards: 70
From: <sip:99...@198.61.XX.XX>;tag=as016358d4
Contact: <sip:99...@198.61.XX.XX:5060>
Call-ID: 3a58feb43689194c...@198.61.XX.XX:5060
CSeq: 102 INVITE
User-Agent: Asterisk PBX 11.4.0-rc1
Date: Thu, 04 Apr 2013 22:59:24 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 683

v=0
o=root 1544519591 1544519591 IN IP4 198.61.XX.XX
s=Asterisk PBX 11.4.0-rc1
c=IN IP4 198.61.XX.XX
t=0 0
m=audio 16256 RTP/AVP 0 18 101
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=ice-ufrag:13b84bd47652b67f0c8206324bdeb4f4
a=ice-pwd:25de0dbe194836906ec2ea3d63d3da36
a=candidate:Hc63daa37 1 UDP 2130706431 198.61.XX.XX 16256 typ host
a=candidate:Sc63daa37 1 UDP 1694498815 198.61.XX.XX 16256 typ srflx
a=candidate:Hc63daa37 2 UDP 2130706430 198.61.XX.XX 16257 typ host
a=candidate:Sc63daa37 2 UDP 1694498814 198.61.XX.XX 16256 typ srflx
a=sendrecv


Thanks,
James
Screen Shot 2013-04-04 at 3.51.35 PM.png
Screen Shot 2013-04-04 at 3.51.47 PM.png

Justin Uberti

unread,
Apr 4, 2013, 7:45:35 PM4/4/13
to discuss-webrtc
"person B" is the name given to the remote client by the OP, which I presume is the SIP GW (or maybe I am confused).
I don't see a binding request from the SIP GW @ 198.61.x.x. to Chrome.

James Mortensen

unread,
Apr 4, 2013, 8:23:03 PM4/4/13
to discuss...@googlegroups.com
The 198.61 is an Asterisk server.  Can you please explain why we'd need a STUN binding request from Asterisk to Chrome?  Also, if a STUN binding request not received, why does the media appear to flow both ways?   

Also, what is this binding success message I see from the gateway to Chrome?  Can you clarify?  Maybe we're misunderstanding what this log says.

If this call is not being established correctly, when why is Chrome allowing audio to flow to the gateway?  The person on the cell phone can hear the Chrome user, but the Chrome user doesn't hear the PSTN user.  We clearly see Chrome receiving something, it just isn't getting processed as audio.

Assuming this is our fault, can you please explain how the binding process works?  What components are responsible for the binding? The JavaScript layer?  The Libjingle Layer?  The gateway?  And does this have anything to do with STUN?  It seems that if UDP packets are making it back and forth to both parties, that stunning worked.

Hope this helps clarify, thanks again for your help! :)

James

Via: SIP/2.0/UDP 198.61.XX.XX:5060;branch=z9hG4bK771f4743;rport
Max-Forwards: 70
From: <sip:99...@198.61.XX.XX>;tag=as016358d4
Contact: <sip:99...@198.61.XX.XX:5060>
Call-ID: 3a58feb43689194c385069ce3391519...@198.61.XX.XX:5060

Justin Uberti

unread,
Apr 4, 2013, 10:03:01 PM4/4/13
to discuss-webrtc
Please have a look at RFC 5245, which explains the ICE process and should answer your questions. It is clear from your description that Asterisk is not doing its part of the ICE process.

Justin Uberti

unread,
Apr 4, 2013, 10:06:34 PM4/4/13
to discuss-webrtc
To be specific, you are missing the step #14 in the example in section 17.

James Mortensen

unread,
Apr 5, 2013, 11:33:19 AM4/5/13
to discuss...@googlegroups.com
Hi Justin,

Thanks for the referral to the spec.  This example just happens to be our exact network topology with a NATed client and a non-NATed client.  

Assuming Asterisk isn't sending the binding request, why is Chrome sending audio?   Shouldn't Chrome tell the signaling server that the call has failed to setup correctly and send some sort of error response to the other endpoint?  Regardless of what entity is at fault, it seems like Chrome should throw some sort of error here and not send audio.  For instance, I would think it would signal some sort of failed state through the peerConnection and then tell the JavaScript layer to send a BYE.

Thanks again,
James

Shaun

unread,
Apr 5, 2013, 11:59:14 AM4/5/13
to discuss...@googlegroups.com
I ran a trace on the server, aka B, and can see STUN packets being sent both ways, hopefully someone much smarter than me can tell me what's missing. Thanks!
capture.pcap

Justin Uberti

unread,
Apr 5, 2013, 12:44:55 PM4/5/13
to discuss-webrtc

I looked at the trace and a binding request is sent from B to Chrome, but not until 7 seconds into the call

1949 6.971568 198.61.170.55 50.43.101.90 STUN 186 Binding Request user: KHi2c1n7iBcTukWC:7cafd4523fc0f40912fdb7196e39c60a


Regarding why Chrome sends audio, if you look at the example I sent previously, the offering endpoint starts sending audio once its checks complete, this is shown in step 13. The remote side should not start sending audio until its check completes, in step 17, so Chrome discards it silently.

Shaun

unread,
Apr 5, 2013, 12:47:11 PM4/5/13
to discuss...@googlegroups.com
So does that mean if it were faster on the draw to send the reply everything would be good to go? What kind of time would Chrome expect for this to work perfectly? Is there a spec on this somewhere? Thanks!

Justin Uberti

unread,
Apr 5, 2013, 1:23:06 PM4/5/13
to discuss-webrtc
It's not a reply, it's the initiation of the binding request. Do you hear media eventually (after 7 seconds)? If not, there is some other problem.

The capture was missing the call setup so it's hard to tell exactly.

Shaun

unread,
Apr 5, 2013, 1:25:43 PM4/5/13
to discuss...@googlegroups.com
Attached are two additional pcap files where it looks like they both send binding requests almost instantly both ways, but the sipml5 call worked and the jssip call did not, am I missing something? Thanks! 

And to your last post, no I never hear media from the PSTN, only from Chrome to the PSTN. Also these pcaps have the full SIP trace as well. 
jssip.pcap
sipml5.pcap

Shaun

unread,
Apr 5, 2013, 6:08:50 PM4/5/13
to discuss...@googlegroups.com
I also posted a bug on the issues list for this: https://code.google.com/p/webrtc/issues/detail?id=1593

James Mortensen

unread,
Apr 12, 2013, 10:54:31 AM4/12/13
to discuss...@googlegroups.com
Hey Joel,

I've verified that with webrtc2sip I can get consistent 2 way audio with Asterisk, even to cell phones.  When you get 1 way audio, is it with calls to all phones or just cell phones?

Also, have you tried calling out from different networks on the client side?   Is your Asterisk server behind NAT or bound to a public IP?

James 

On Thursday, April 11, 2013 4:05:02 PM UTC-7, Joel Rosenfield wrote:
I believe I am seeing a similar issue that is 100% repeatable.  The symptom is that, after what appear to be successful SIP/SDP and STUN transactions, Chrome 26 doesn't send audio packets.  However, when connecting to a different type of application hosted on the same server, I get 2-way audio as expected.  The timing in the Chrome logs make me wonder if there may be a race condition, but that is speculation.

I am using Chrome 26 -> Asterisk 11.2.1 with the sipML5 patch which results in 1-way audio.  I also have webrtc2sip loaded on the same server as Asterisk, and I get two-way audio using the same Chrome 26 client.  Both the Asterisk failure and the webrtc2sip success scenarios are 100% repeatable.

In both cases, SIP/SDP seem correct, and packet traces shows that both scenarios have STUN request/success in both directions.  The only difference is that, in the webrtc2sip (success) case, the packet trace shows audio packets in both directions while in the Asterisk (failure) case, voice packets only flow from server to client (called to caller).

I am more than happy to help debug this or comment on Issue 1525 (which also seems similar) if someone on the webRTC project thinks it would help.  I have the same results when using Canary.

Here are some snippets from the Chrome 26 logs (v=9):
Chrome 26 -> Asterisk (fail):
[6188:7016:0411/103611:VERBOSE3:p2ptransportchannel.cc(825)] Jingle:Channel[audio|1|__]: Previous best connection: Conn[audio:UVO8cTOy:1:0:local:udp:192.168.56.1:55175->:1:0:local:udp:10.159.25.56:15798|C--I|-]
[6188:7016:0411/103611:VERBOSE3:p2ptransportchannel.cc(828)] Jingle:Channel[audio|1|__]: New best connection: Conn[audio:xxMWKq7b:1:0:local:udp:192.168.1.109:55174->:1:0:stun:udp:107.YY.YY.YY:15798|CRWS|2268]
[6188:7016:0411/103611:VERBOSE4:dtlstransportchannel.cc(349)] Jingle:Channel[audio|1|__]: DTLSTransportChannelWrapper: channel writable state changed
[6188:7016:0411/103611:VERBOSE4:dtlstransportchannel.cc(337)] Jingle:Channel[audio|1|_W]: DTLSTransportChannelWrapper: channel readable state changed
{no log of "Channel socket writable (audio, 1) for the first time", "Changing voice state, recv=1 send=1", etc.}

Chrome 26 -> webrtc2sip (success):
[6800:4828:0411/083246:VERBOSE4:dtlstransportchannel.cc(337)] Jingle:Channel[audio|1|__]: 
DTLSTransportChannelWrapper: channel readable state changed
. . . 
[6800:4828:0411/083246:VERBOSE3:p2ptransportchannel.cc(825)] Jingle:Channel[audio|1|R_]: Previous best connection: Conn[audio:2taC+vDP:1:0:local:udp:192.168.56.1:59923->:1:0:local:udp:10.159.25.56:39388|C--I|-]
[6800:4828:0411/083246:VERBOSE3:p2ptransportchannel.cc(828)] Jingle:Channel[audio|1|R_]: New best connection: Conn[audio:eFnx85Ys:1:0:local:udp:192.168.1.109:59922->:1:0:stun:udp:107.YY.YY.YY:39388|CRWS|2283]
[6800:4828:0411/083246:VERBOSE4:dtlstransportchannel.cc(349)] Jingle:Channel[audio|1|R_]: DTLSTransportChannelWrapper: channel writable state changed
[6800:4828:0411/083246:VERBOSE3:channel.cc(910)] Channel socket writable (audio, 1) for the first time
[6800:4828:0411/083246:VERBOSE3:channel.cc(920)] Using Cand[eFnx85Ys:1:local:udp:{1819BAC1-9E5C-44BA-BF00-87359EDB7A89}:192.168.1.109:59922:k46yDErFo0BSshws:KadBz/lqJcTVFiEl2138IBMm]->Cand[:1:stun:udp::107.YY.YY.YY:39388:vLfVJM87RtPvhDX:dEYCJSUH8nVwDPMjbihZ3]
[6800:4828:0411/083246:VERBOSE3:webrtcvoiceengine.cc(570)] Setting option overrides: AudioOptions {}
[6800:4828:0411/083246:VERBOSE3:webrtcvoiceengine.cc(618)] Applying audio options: AudioOptions {}
[6800:4828:0411/083246:VERBOSE3:channel.cc(1607)] Changing voice state, recv=1 send=1
[4000:3468:0411/083246:VERBOSE1:audio_input_renderer_host.cc(200)] AudioInputRendererHost::OnStartDevice(stream_id=1, session_id = 2)
[4000:3468:0411/083246:VERBOSE1:audio_input_renderer_host.cc(214)] AudioInputRendererHost::OnCreateStream(stream_id=1)

Here are the offers/answers:
Asterisk (failure):
Offer SDP:
v=0
o=- 3355069378 2 IN IP4 127.0.0.1
s=Doubango Telecom - chrome
t=0 0
a=group:BUNDLE audio
a=msid-semantic: WMS x5JGa7ahN17045xZ3wLtZfelxoqTPIYraphP
m=audio 55174 RTP/SAVPF 103 104 111 0 8 107 106 105 13 126
c=IN IP4 23.XX.XX.XX
a=rtcp:55174 IN IP4 23.XX.XX.XX
a=candidate:3467446226 1 udp 2113937151 192.168.1.109 55174 typ host generation 0
a=candidate:3467446226 2 udp 2113937151 192.168.1.109 55174 typ host generation 0
a=candidate:2999745851 1 udp 2113937151 192.168.56.1 55175 typ host generation 0
a=candidate:2999745851 2 udp 2113937151 192.168.56.1 55175 typ host generation 0
a=candidate:1340408166 1 udp 1845501695 23.XX.XX.XX 55174 typ srflx raddr 192.168.1.109 rport 55174 generation 0
a=candidate:1340408166 2 udp 1845501695 23.XX.XX.XX 55174 typ srflx raddr 192.168.1.109 rport 55174 generation 0
a=candidate:2150562594 1 tcp 1509957375 192.168.1.109 49587 typ host generation 0
a=candidate:2150562594 2 tcp 1509957375 192.168.1.109 49587 typ host generation 0
a=candidate:4233069003 1 tcp 1509957375 192.168.56.1 49588 typ host generation 0
a=candidate:4233069003 2 tcp 1509957375 192.168.56.1 49588 typ host generation 0
a=ice-ufrag:nMJqIvCZkxxjanvM
a=ice-pwd:rd+pTHRvBwPN3l2kpnSnzTgN
a=ice-options:google-ice
a=sendrecv
a=mid:audio
a=rtcp-mux
a=crypto:0 AES_CM_128_HMAC_SHA1_32 inline:yZgpDGPCt7d7uN6ruugbJ1s7qogSDXkNE8GwghGq
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:1vcNH38Xq9j+pGL85f2O4Jo5iLsevgW9U9BbYFjO
a=rtpmap:103 ISAC/16000
a=rtpmap:104 ISAC/32000
a=rtpmap:111 opus/48000/2
a=fmtp:111 minptime=10
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:107 CN/48000
a=rtpmap:106 CN/32000
a=rtpmap:105 CN/16000
a=rtpmap:13 CN/8000
a=rtpmap:126 telephone-event/8000
a=maxptime:60
a=ssrc:1167001888 cname:uyihe4P/auBCsB3W
a=ssrc:1167001888 msid:x5JGa7ahN17045xZ3wLtZfelxoqTPIYraphP x5JGa7ahN17045xZ3wLtZfelxoqTPIYraphPa0
a=ssrc:1167001888 mslabel:x5JGa7ahN17045xZ3wLtZfelxoqTPIYraphP
a=ssrc:1167001888 label:x5JGa7ahN17045xZ3wLtZfelxoqTPIYraphPa0

Answer SDP:
v=0
o=root 725358089 725358089 IN IP4 107.YY.YY.YY
s=Asterisk PBX SVN-trunk-r379070M
c=IN IP4 107.YY.YY.YY
t=0 0
m=audio 15798 RTP/SAVPF 0 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ssrc:984573663 cname:ldjWoB60jbyQlR6e
a=ssrc:984573663 mslabel:6994f7d1-6ce9-4fbd-acfd-84e5131ca2e2
a=ssrc:984573663 label:Doubango
a=silenceSupp:off - - - -
a=ptime:20
a=ice-ufrag:2ee074ce5c17851f4818d7db14cb38da
a=ice-pwd:1df3f9607a6096836787cf823c1711c1
a=candidate:Ha9f1938 1 udp 2130706431 10.159.25.56 15798 typ host generation 0 svn 165
a=candidate:S6b15c590 1 udp 1694498815 107.YY.YY.YY 15798 typ srflx generation 0 svn 165
a=sendrecv
a=crypto:0 AES_CM_128_HMAC_SHA1_32 inline:TAQxMfw6OpaVVkhm1Q90JfKg8f7x+vKt+qi34sGu

webrtc2sip (success):
Offer SDP:
v=0
o=- 3861354938 2 IN IP4 127.0.0.1
s=Doubango Telecom - chrome
t=0 0
a=group:BUNDLE audio
a=msid-semantic: WMS 1hUAoYxSMI6iMeJHtBYKfv0ygMKz6ZuZiDHl
m=audio 59922 RTP/SAVPF 103 104 111 0 8 107 106 105 13 126
c=IN IP4 23.XX.XX.XX
a=rtcp:59922 IN IP4 23.XX.XX.XX
a=candidate:3467446226 1 udp 2113937151 192.168.1.109 59922 typ host generation 0
a=candidate:3467446226 2 udp 2113937151 192.168.1.109 59922 typ host generation 0
a=candidate:2999745851 1 udp 2113937151 192.168.56.1 59923 typ host generation 0
a=candidate:2999745851 2 udp 2113937151 192.168.56.1 59923 typ host generation 0
a=candidate:1340408166 1 udp 1845501695 23.XX.XX.XX 59922 typ srflx raddr 192.168.1.109 rport 59922 generation 0
a=candidate:1340408166 2 udp 1845501695 23.XX.XX.XX 59922 typ srflx raddr 192.168.1.109 rport 59922 generation 0
a=candidate:2150562594 1 tcp 1509957375 192.168.1.109 49290 typ host generation 0
a=candidate:2150562594 2 tcp 1509957375 192.168.1.109 49290 typ host generation 0
a=candidate:4233069003 1 tcp 1509957375 192.168.56.1 49291 typ host generation 0
a=candidate:4233069003 2 tcp 1509957375 192.168.56.1 49291 typ host generation 0
a=ice-ufrag:k46yDErFo0BSshws
a=ice-pwd:KadBz/lqJcTVFiEl2138IBMm
a=ice-options:google-ice
a=sendrecv
a=mid:audio
a=rtcp-mux
a=crypto:0 AES_CM_128_HMAC_SHA1_32 inline:vF1ocspsQ+QJZFLBiyMJmGJZlshQE0eNy7cL0tp0
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:jRysrmeuyu9wmb9nEC5hGHMZXwJEcHbl0QtFegpQ
a=rtpmap:103 ISAC/16000
a=rtpmap:104 ISAC/32000
a=rtpmap:111 opus/48000/2
a=fmtp:111 minptime=10
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:107 CN/48000
a=rtpmap:106 CN/32000
a=rtpmap:105 CN/16000
a=rtpmap:13 CN/8000
a=rtpmap:126 telephone-event/8000
a=maxptime:60
a=ssrc:1779256102 cname:Nc/UwFlqhkKO2S21
a=ssrc:1779256102 msid:1hUAoYxSMI6iMeJHtBYKfv0ygMKz6ZuZiDHl 1hUAoYxSMI6iMeJHtBYKfv0ygMKz6ZuZiDHla0
a=ssrc:1779256102 mslabel:1hUAoYxSMI6iMeJHtBYKfv0ygMKz6ZuZiDHl
a=ssrc:1779256102 label:1hUAoYxSMI6iMeJHtBYKfv0ygMKz6ZuZiDHla0

Answer SDP:
v=0
o=doubango 1983 678901 IN IP4 10.159.25.56
s=-
c=IN IP4 10.159.25.56
t=0 0
m=audio 39388 RTP/SAVPF 0 8
c=IN IP4 10.159.25.56
a=ptime:20
a=silenceSupp:off - - - -
a=rtpmap:0 PCMU/8000/1
a=rtpmap:8 PCMA/8000/1
a=crypto:0 AES_CM_128_HMAC_SHA1_32 inline:XUowHy+H46VP5sY718HpqcmRltLdIHciYNr98Kfu
a=sendrecv
a=rtcp-mux
a=ssrc:4132823663 cname:ldjWoB60jbyQlR6e
a=ssrc:4132823663 mslabel:6994f7d1-6ce9-4fbd-acfd-84e5131ca2e2
a=ssrc:4132823663 label:Doubango
a=ice-ufrag:vLfVJM87RtPvhDX
a=ice-pwd:dEYCJSUH8nVwDPMjbihZ3
a=candidate:D2rTbod39 1 udp 2130706431 10.159.25.56 39388 typ host
a=candidate:srflxD2rT 1 udp 1694498815 107.YY.YY.YY 39388 typ srflx raddr 10.159.25.56 rport 39388

Here is my complete architecture:
Success:  Chrome 26 -> webrtc2sip -> Kamailio -> FreeSWITCH, which FS configured to play an announcement and then echo delay.
Failure:  Chrome 26 -> Asterisk, dial 600 for the Echo test.  
NOTE:  I had similar 1-way audio when calling Chrome 26 -> Asterisk -> Chrome 26, whereas xLIte -> Asterisk Echo succeeds (2-way audio).
Chrome 26 is running on Windows 7 (Windows 8 had that same failure).  Both Chrome 26 and Asterisk are behind (separate) NATs.

Thanks,
- Joel

James Mortensen

unread,
Apr 12, 2013, 11:08:29 AM4/12/13
to discuss...@googlegroups.com
Also, please see Issue 1612, which has been opened by the webRTC team.  There's also an Asterisk ticket #21383

James

Joel Rosenfield

unread,
Apr 12, 2013, 11:16:20 AM4/12/13
to discuss...@googlegroups.com
Hey James,

Thanks for your response.  The tests that I have run to date are Chrome 26 to the Asterisk Echo test (x600) and Chrome 26 -> Asterisk -> Chrome 26.  In both cases, I hear audio from called to caller but not from caller to called.  Further research showed that Chrome was not sending voice packets when it was the calling party, even after an apparently successful STUN connectivity check (so far as I can tell it was successful).  

Just to be sure, I have both Asterisk and webrtc2sip installed on the same server, which is behind a NAT.  I am running two tests: one from Chrome to Asterisk and the other Chrome to webrtc2sip.  For my tests, webrtc2sip and Asterisk to not communicate with each other.  I did this since both Asterisk and webrtc2sip are B2BUAs, so the media in the remote call leg should be irrelevant in both cases.  The result is that I see audio packets in both directions in the webrtc2sip test, but only in the called to caller direction for Asterisk (no packets from Chrome).

I am new to the Chrome logs, but it appears that in both cases I see "channel writable state" and "channel readable state" logs.  However, I only see logs such as "Channel socket writable (audio, 1) for the first time" in the webrtc2sip case.

Thanks,
- Joel

James Mortensen

unread,
Apr 12, 2013, 12:04:48 PM4/12/13
to discuss...@googlegroups.com
Hi Joel,

Do you see anything like this in the Chrome logs (0 way audio call to PSTN):

[6282:6151:0404/114254:VERBOSE2:port.cc(913)] Jingle:Conn[audio:e3nQtDzG:1:0:local:udp:10.0.1.6:57608->:1:0:local:udp:198.61.X.X:15390|C-WS|68]: Received non-STUN packet from an unreadable connection.
[6282:6151:0404/114254:VERBOSE2:port.cc(913)] Jingle:Conn[audio:e3nQtDzG:1:0:local:udp:10.0.1.6:57608->:1:0:local:udp:198.61.X.X:15390|C-WS|68]: Received non-STUN packet from an unreadable connection.
[6282:6151:0404/114254:VERBOSE2:port.cc(913)] Jingle:Conn[audio:e3nQtDzG:1:0:local:udp:10.0.1.6:57608->:1:0:local:udp:198.61.X.X:15390|C-WS|68]: Received non-STUN packet from an unreadable connection.
or anything like this:

[60093:33795:0412/084543:ERROR:socket_host_udp.cc(127)] Received unexpected data packet from 108.59.X.X:16858 before STUN binding is finished.
[60093:33795:0412/084543:ERROR:socket_host_udp.cc(127)] Received unexpected data packet from 108.59.X.X:16858 before STUN binding is finished.
[60093:33795:0412/084543:ERROR:socket_host_udp.cc(127)] Received unexpected data packet from 108.59.X.X:16858 before STUN binding is finished.
WARNING: no real random source present!
[60093:33795:0412/084543:ERROR:socket_host_udp.cc(127)] Received unexpected data packet from 108.59.X.X:16858 before STUN binding is finished.
[60153:1799:0412/084543:ERROR:webrtc_audio_renderer.cc(229)] Not implemented reached in virtual void content::WebRtcAudioRenderer::Start()
[60093:33795:0412/084543:ERROR:socket_host_udp.cc(127)] Received unexpected data packet from 108.59.X.X:16858 before STUN binding is finished.
[60093:33795:0412/084543:ERROR:socket_host_udp.cc(127)] Received unexpected data packet from 108.59.X.X:16858 before STUN binding is finished.
[60093:33795:0412/084543:ERROR:socket_host_udp.cc(127)] Received unexpected data packet from 108.59.X.X:16858 before STUN binding is finished.
[60093:33795:0412/084543:ERROR:socket_host_udp.cc(127)] Received unexpected data packet from 108.59.X.X:16858 before STUN binding is finished.



James



--
 
---
You received this message because you are subscribed to a topic in the Google Groups "discuss-webrtc" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/discuss-webrtc/GKtrfMir2sE/unsubscribe?hl=en.
To unsubscribe from this group and all its topics, send an email to discuss-webrt...@googlegroups.com.

For more options, visit https://groups.google.com/groups/opt_out.
 
 



--
James Mortensen
Project Manager, VoiceCurve, Inc.
866-707-4590
james.m...@voicecurve.com

Joel Rosenfield

unread,
Apr 12, 2013, 12:43:36 PM4/12/13
to discuss...@googlegroups.com
Hey James,

The short answer is no and no.  I'll post the full logs in a moment.

Thanks,
- Joel

Joel Rosenfield

unread,
Apr 12, 2013, 1:02:09 PM4/12/13
to discuss...@googlegroups.com
Attached is the Chrome log of the Chrome -> Asterisk (failure) case.
Thanks,
- Joel
sipml5 asterisk v=9 chrome_debug.log

Joel Rosenfield

unread,
Apr 12, 2013, 1:03:23 PM4/12/13
to discuss...@googlegroups.com
Thanks James,

Yes, it appears that I am observing both of those issues.  Specifically, when I call Chrome 26 -> Asterisk 11.2.1 -> Chrome 26, I get end-to-end one-way audio for the called -> caller path, but I observe no voice packets in either call leg for the caller -> called path.  So the Chrome -> Asterisk call leg appears to exhibit webRTC Issue 1612, and the Asterisk -> Chrome call leg appears to exhibit Asterisk Ticket #21383.

My experience is that with my setup, I can repeat both issues 100% of the time and would be happy to help test any fixes.

Thanks again,
- Joel

James Mortensen

unread,
Apr 12, 2013, 2:34:02 PM4/12/13
to discuss...@googlegroups.com
Ah, we're likely not seeing the Chrome -> Asterisk 11.1.2 -> Chrome audio issues because we go directmedia and directrtpsetup=yes and directmedia=yes when calling another Chrome so that it's peer to peer. 

In other words, the RTP packets flow between clients and don't go through the server.  Hence, we only see the problem when calling the PSTN, since Asterisk must be in the middle of that transaction.

I agree there's definitely a timing issue somewhere between Chrome and Asterisk.

One thing we noticed with 1 way audio is it only happens when calling cell phones.  We can call landlines and get 2 way audio.

One thing I'm going to work on today is making some changes to our ICE candidates sent from Asterisk to Chrome, to see if maybe we can workaround the issue.  

James


--
 
---
You received this message because you are subscribed to a topic in the Google Groups "discuss-webrtc" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/discuss-webrtc/GKtrfMir2sE/unsubscribe?hl=en.
To unsubscribe from this group and all its topics, send an email to discuss-webrt...@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.
 
 

Joel Rosenfield

unread,
Apr 12, 2013, 3:18:35 PM4/12/13
to discuss...@googlegroups.com
Hey James,

Yes, my Asterisk config is basically the same as described in the sipML5 Asterisk demo instructions, which include directmedia=no.  I'm basically using Asterisk as a media gateway for webRTC clients to access our voice platform.  We're going to stand up Asterisk on a server without a NAT to see if that might solve the problem by perturbing the timing to avoid the race condition described in Issue 1612 (assuming that is indeed my problem).

Thanks,
- Joel

James Mortensen

unread,
Apr 12, 2013, 3:36:29 PM4/12/13
to discuss...@googlegroups.com
When I use an Asterisk on the public Internet (no-NAT), we see the opposite, audio does not flow from callee to caller.  What's more, when grabbing a PCAP file from the server, you hear both audio streams!  In other words, there is audio flowing from Asterisk to Chrome (the caller), but the Chrome caller can't hear.  Chrome isn't reading the audio packets.

But what I see when using an Asterisk behind NAT is that the audio does not flow from caller to callee, only callee to caller.  What's more, when grabbing a PCAP from the server on the NAT'd server, I don't hear the audio from the Chrome caller to the PSTN, just from the PSTN (callee) to Chrome (the caller).  Thus, this sort of supports what you're saying about this possibly being an Asterisk issue whereas the no-NAT use case is more of a Chrome STUN binding issue.

I've attached two PCAP's from two test calls from Chrome (caller) to the PSTN (callee).  One is on a NAT'd Asterisk and the other is no-NAT.  In both cases, I'm using JsSIP 0.3.0. 

In both calls, I said "this is from Chrome to PSTN" when speaking into my Logitech headset, and "this is from PSTN to Chrome" when speaking into my cellphone.  Note that in the 108 (NAT'd) pcap, you hear silence when I speak "this is from Chrome to the PSTN".

Also, I put this together just before your last message.  Standing up a server without NAT will give you a clearer perspective as to what is going on, and also help confirm that we're seeing the same issues.  We're actually thinking that using webrtc2sip's RTCWeb Breaker is going to be a good workaround for now, since Asterisk can treat the calls as legacy calls.
chrome2pstn108.pcap
chrome2pstn198-2.pcap

James Mortensen

unread,
Apr 12, 2013, 6:05:03 PM4/12/13
to discuss...@googlegroups.com
Hey Joel,

We have an Asterisk patch for you to try on your NAT'd server. It seems to have resolved our issues with 1 way audio, and I'm hoping it fixes your problem too.

Basically, the patch will replace your Asterisk's local IP in the answer with the public IP:

    a=candidate:Ha9f1938 1 udp 2130706431 10.159.25.56 15798 typ host generation 0 svn 165

gets changed to:

    a=candidate:Ha9f1938 1 udp 2130706431 107.X.X.X 15798 typ host generation 0 svn 165

To apply the patch:
  • Download the source for Asterisk11.4.0-rc1.  
  • Before applying the patch, you must replace the IP address on line 22 with your Asterisk public IP.
  • To apply the patch, cd into the parent of the asterisk source code, so that typing 'ls channels/chan_sip.c' would find the chan_sip.c file.
  • Then, with the patch in the same directory, run the following command:
        patch channels/chan_sip.c < chansip_nat_2013_4_12.patch
  • Then run "make" and "make install" and restart Asterisk.

There's not much to this, so if it's easier you could edit chan_sip.c manually in Asterisk 11.1.2 and recompile.  


Let me know if this works for you.

Thanks,
James


On Fri, Apr 12, 2013 at 12:18 PM, Joel Rosenfield <joelrose...@gmail.com> wrote:
chansip_nat_2013_4_12.patch

James Mortensen

unread,
Apr 12, 2013, 6:28:49 PM4/12/13
to discuss...@googlegroups.com
Correction!  Line 28 is where you modify the IP address. I'm working on replacing that dynamically.

James

Joel Rosenfield

unread,
Apr 12, 2013, 6:34:54 PM4/12/13
to discuss...@googlegroups.com
Hey James,

I'm glad that worked for you and thanks for letting me know.  Unfortunately, I've already tried hacking chan_sip.c to such that it only includes one correct candidate in the SDP, which is one with the public IP.  This failed for me in a similar fashion -- Chrome doesn't send audio packets.  From what I interpret from the Chrome logs, the ICE/STUN process seems to settle on the correct candidates in my case, but Chrome for some reason doesn't start playing audio once it confirms that the channel is both "readable" and "writeable".

That said, I haven't tried to patch with either Asterisk version 11.3.0 or 11.4.0-rc1, so perhaps I'll give that a try over the weekend.  I have tried and failed using 11.3.0 without any patch, yielding no audio.  I think I may still need to add ssrc lines to the SDP.

Thanks again,
- Joel

James Mortensen

unread,
Apr 12, 2013, 6:40:36 PM4/12/13
to discuss...@googlegroups.com
Hey Joel,

We tried that too.  You need both a host candidate and a srflx candidate, like so:

a=ice-ufrag:205168a9152cd52c2a1d25cf2a784b9c a=ice-pwd:2037f62971c0589064f3c1602254f2e2 a=candidate:Haf0e6c8 1 UDP 2130706431 108.XX.XX.XX 12084 typ host a=candidate:S6c3b569f 1 UDP 1694498815 108.XX.XX.XX 12084 typ srflx a=candidate:Haf0e6c8 2 UDP 2130706430 108.XX.XX.XX 12085 typ host a=candidate:S6c3b569f 2 UDP 1694498814 108.XX.XX.XX 12084 typ srflx a=sendrecv a=crypto:0 AES_CM_128_HMAC_SHA1_32 inline:iTsncnpHirWWucWWfKLFjwj5k9PRCblHiQWr5pL1
The bold candidates are host candidates. Unpatched, they contain your local IP.  We put the public IP there and it worked.  If it helps, we first tried what you did, removing the host candidates completely, and as you say, Chrome didn't like that.

James

James Mortensen

unread,
Apr 12, 2013, 10:35:42 PM4/12/13
to discuss...@googlegroups.com
Hello,

In case the WebRTC team is interested, Shaun and I submitted a patch to Asterisk, which appears to resolve the one-way audio issues when calling from Chrome to Asterisk to the PSTN when all three components are behind NAT.

The issue also includes my chrome_debug log from one of the calls, so the team here can see what the binding requests/responses look like.  At this point, it would be great if someone with more knowledge of the RFC-5245 spec could take a look at this and let us know if this is doing what it's supposed to do.  


Thank you,
James

Justin Uberti

unread,
Apr 13, 2013, 12:05:02 AM4/13/13
to discuss-webrtc
Thanks for the logs, makes it easy to see what is going on.

However, the patch doesn't solve the core problem. The core problem is that the ports from Asterisk in the srflx candidates are identical (and therefore wrong) - this is the same issue I mentioned before. Because of this, Chrome can't demux by 5-tuple, since the 5-tuples are the same for RTP and RTCP. This also explains why "fixing" the host candidates seems to make things work, since the host candidates seem OK.


--
 
---
You received this message because you are subscribed to the Google Groups "discuss-webrtc" group.
To unsubscribe from this group and stop receiving emails from it, send an email to discuss-webrt...@googlegroups.com.

James Mortensen

unread,
Apr 13, 2013, 8:28:48 PM4/13/13
to discuss...@googlegroups.com
Hi Justin,

I ran another experiment in the Asterisk source code. I removed my hack so the local IP's returned to the normal host candidates, but I instead increment the port on the second srflx candidate by 1, so we get:

a=ice-ufrag:3f5707dc69a55c454f221d105d15c5ba a=ice-pwd:77899ab321787fdb7549f0a1643aa3b8 a=candidate:Haf0e6c8 1 UDP 2130706431 10.240.230.200 13320 typ host a=candidate:S6c3b569f 1 UDP 1694498815 108.XX.XX.XX 13320 typ srflx a=candidate:Haf0e6c8 2 UDP 2130706430 10.240.230.200 13321 typ host
a=candidate:S6c3b569f 2 UDP 1694498814 108.XX.XX.XX 13321 typ srflx a=sendrecv

I ran the following stun test client from the linux command line:

    # stun -v stun.l.google.com:19302

We consistently see sequential ports. Thus, for this test, we can safely assume that the port should be 1 higher on the second srflx candidate.  Like my other hack, this too results in successful two way audio to both the movie phone number and my Verizon cell phone.  

I've attached another chrome debug log in case you want to check things out.  We'll also do more testing on our end to try different scenarios to see if we can replicate any issues.  If everything checks out, we can then think about finding out why Asterisk isn't putting the right port in the candidates.  Clearly, the STUN servers return two ports. So either Asterisk isn't reading them correctly from the STUN server response, or it's getting replaced with the first port somewhere before the candidates are added to the 183/200 SDP sent to Chrome.

Thanks again for all your help!

James

chrome_debug_hacked_ports.log

Joel Rosenfield

unread,
Apr 13, 2013, 9:20:12 PM4/13/13
to discuss...@googlegroups.com
Hey James, this appears to have worked!  More testing is necessary, but the Asterisk Echo test now works for me.

Thanks,
- Joel

Justin Uberti

unread,
Apr 13, 2013, 10:31:24 PM4/13/13
to discuss-webrtc
Glad you guys got it working. Looking at your log, the SDP matches my expectations:

a=candidate:Haf0e6c8 1 UDP 2130706431 10.240.230.200 13320 typ host
a=candidate:S6c3b569f 1 UDP 1694498815 108.XX.XX.XX 13320 typ srflx
a=candidate:Haf0e6c8 2 UDP 2130706430 10.240.230.200 13321 typ host
a=candidate:S6c3b569f 2 UDP 1694498814 108.XX.XX.XX 13321 typ srflx

I think your assessment is correct, Asterisk is somehow getting confused when getting STUN ports for both RTP and RTCP. Hope you can get this fixed, this will surely help many future WebRTC-Asterisk applications...


--
 
---
You received this message because you are subscribed to the Google Groups "discuss-webrtc" group.
To unsubscribe from this group and stop receiving emails from it, send an email to discuss-webrt...@googlegroups.com.

James Mortensen

unread,
Apr 14, 2013, 1:56:38 AM4/14/13
to discuss...@googlegroups.com
Hi Joel,

That's great! Thanks for letting us know.  However, based on what Justin says about the candidates, you should try this new patch instead, which forces the 2nd srflx candidate to use a port one value higher than the port used for the first candidate.

Thanks again for helping us test this out.

James

chansip_11-4-rc1_21383_2013_4_13.patch

James Mortensen

unread,
Apr 14, 2013, 4:10:10 PM4/14/13
to discuss...@googlegroups.com
Hi Joel,

Please disregard my previous message.  I cleaned up the code and submitted the patch to ASTERISK-21383:  https://issues.asterisk.org/jira/browse/ASTERISK-21383

The latest patch is found here:
https://issues.asterisk.org/jira/secure/attachment/46983/chansip_11-4-rc1_21383_2013_4_14.patch

Thank you,
James

Joel Rosenfield

unread,
Apr 14, 2013, 8:11:05 PM4/14/13
to discuss...@googlegroups.com
Hi James,

Yes, the revised patch works fine for me, and of course it's much better not having to provision the IP address manually.  Thanks for submitting it.

- Joel

Justin Uberti

unread,
Apr 15, 2013, 1:42:19 AM4/15/13
to discuss-webrtc
Note that the patch won't work when running behind a NAT that doesn't increment the external port by 1 for each binding (of which there are many).


You received this message because you are subscribed to the Google Groups "discuss-webrtc" group.
To unsubscribe from this group and stop receiving emails from it, send an email to discuss-webrt...@googlegroups.com.

James Mortensen

unread,
Apr 15, 2013, 1:54:27 AM4/15/13
to discuss...@googlegroups.com
Is that why the SDP on the Chrome side seems to work okay even with matching ports? I noticed that the SDP sent from Chrome doesn't increment the port like I needed to do on the Asterisk sideL 

m=audio 52743 RTP/SAVPF 103 104 111 0 8 107 106 105 13 126 c=IN IP4 97.XX.XX.XX a=rtcp:52743 IN IP4 97.XX.XX.XX a=candidate:3573973069 1 udp 2113937151 192.168.0.102 52743 typ host generation 0 a=candidate:3573973069 2 udp 2113937151 192.168.0.102 52743 typ host generation 0 a=candidate:1414432505 1 udp 1845501695 97.XX.XX.XX 52743 typ srflx raddr 192.168.0.102 rport 52743 generation 0 a=candidate:1414432505 2 udp 1845501695 97.XX.XX.XX 52743 typ srflx raddr 192.168.0.102 rport 52743 generation 0 a=candidate:2609216701 1 tcp 1509957375 192.168.0.102 59680 typ host generation 0 a=candidate:2609216701 2 tcp 1509957375 192.168.0.102 59680 typ host generation 0 a=ice-ufrag:d2wQ+WfOjPFzkIGZ a=ice-pwd:zNLwaGxi6s0kjxX3UNuizdXv a=ice-options:google-ice

I was thinking that the patch might need to check the SDP for the rtcp attribute, and if it's found, don't increment the port. I noticed the spec said something about not incrementing the port in that scenario. Is this what you were thinking?

Thanks again for all your help!

James

Justin Uberti

unread,
Apr 16, 2013, 12:25:20 AM4/16/13
to discuss-webrtc
Chrome is actually multiplexing the data over the same port, which improves call reliability. In your case, Asterisk creates two different ports, but the candidates get mixed up so RTP and RTCP traffic will get sent to the same port (i.e. multiplexing in a case where Asterisk is not expecting to multiplex).

I think your patch really needs to just fix the underlying problem with STUN binding, anything else is making assumptions on NAT behavior that won't always work (unless you're not NATed on the Asterisk side, in which case you can just throw away the STUN candidates).

Nilson Freitas

unread,
Jun 10, 2013, 4:32:44 PM6/10/13
to discuss...@googlegroups.com
Hello James,

How did you solved this problem???

I am facing the same issue as you...

Thanks

James Mortensen

unread,
Jun 10, 2013, 6:22:31 PM6/10/13
to discuss...@googlegroups.com
Hi Nilson,

Please see the patch we created here:  https://issues.asterisk.org/jira/browse/ASTERISK-21383  Since applying that patch, the number of one way audio incidents has decreased dramatically, although it still happens every so often.

James


--
 
---
You received this message because you are subscribed to a topic in the Google Groups "discuss-webrtc" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/discuss-webrtc/GKtrfMir2sE/unsubscribe?hl=en.
To unsubscribe from this group and all its topics, send an email to discuss-webrt...@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.
 
 

Victor de Torres

unread,
May 8, 2014, 12:12:07 PM5/8/14
to discuss...@googlegroups.com
Still with the same problem on Asterisk ver. 11.9. This patch is released on this ver. isn't it?

Adnan A M

unread,
May 26, 2014, 11:31:28 PM5/26/14
to discuss...@googlegroups.com
So I have been having a similar problem with Android. I keep getting the following errors which I believe is similar to what James here has been getting :

Received non-STUN packet from an unreadable connection.

Interestingly , I sometimes also see the following error :

Unable to write to channel( audio, 1)

The audio flows one way for me, from the Called to the Callee. Interestingly enough I am able to get it working on iOS with the requests going through the same STUN server. We even tried using the Google STUN server but still the same response.

Any ideas ?

Vinay Nair

unread,
May 29, 2014, 2:04:16 AM5/29/14
to discuss...@googlegroups.com
I have also been facing the same issue. Any solution for this?
Reply all
Reply to author
Forward
0 new messages