ICE candidates don't get added to SDP answer

RESOLVED FIXED in Firefox 34

Status

()

Core
WebRTC: Signaling
RESOLVED FIXED
3 years ago
3 years ago

People

(Reporter: marko.seidenglanz, Assigned: bwc)

Tracking

34 Branch
mozilla35
Points:
---

Firefox Tracking Flags

(firefox32 unaffected, firefox33 unaffected, firefox34 fixed, firefox35 fixed)

Details

Attachments

(12 attachments, 1 obsolete attachment)

(Reporter)

Description

3 years ago
Created attachment 8496415 [details]
webrtc_trace.txt

User Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.66 Safari/537.36

Steps to reproduce:

- Create peer connection

- Request local media access (audio)

- Set remote SDP:
v=0
o=- 1299471806 1299471806 IN IP4 asterisk
s=Asterisk
c=IN IP4 10.240.143.142
t=0 0
m=audio 15166 RTP/SAVPF 8 101
c=IN IP4 10.240.143.142
a=connection:new
a=setup:actpass
a=fingerprint:SHA-256 51:27:7B:3C:8F:4C:01:A1:5E:B4:1B:8D:58:39:53:A6:92:BE:7F:EF:DC:51:17:20:C7:C0:9A:E6:57:8B:AC:A1
a=ice-ufrag:3e129b3c1ee92e5a75fb4ee92d28c4e1
a=ice-pwd:27067e3b36472bab4a0805686bfb2098
a=candidate:Haf08f8e 1 UDP 2130706431 10.240.143.142 15166 typ host
a=candidate:H92947a05 1 UDP 2130706431 146.148.122.5 15166 typ host
a=candidate:Haf08f8e 2 UDP 2130706430 10.240.143.142 15167 typ host
a=candidate:H92947a05 2 UDP 2130706430 146.148.122.5 15167 typ host
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:150
a=sendrecv
a=rtcp-mux


Actual results:

peerConnection.onaddstream() event handler is not called anymore.


Expected results:

Remote stream should be received, like it was the case in every release before.

Are there any API changes in FF 34?
(Reporter)

Updated

3 years ago
Component: Untriaged → WebRTC: Signaling
Product: Firefox → Core
(Reporter)

Comment 1

3 years ago
peerConnection.remoteDescription is NULL after setting it, but no error is thrown.
(Reporter)

Comment 2

3 years ago
Neither the success CB is called nor the error CB of peerConnection.setRemoteDescription(). It just happens nothing.
Sorry but I'm unable to reproduce the problem with the description you gave so far. Callbacks work and remoteDescription is filled appropriately.

In the list of steps to reproduce the problem you did not mention that your are adding the gUM stream to your PC. I assume you just forgot to mention that.

The only bigger change we did recently is that FF34 by default now does full trickle ICE. But I don't see how that should affect the problem here.

Would it be possible for you to share the HTML/JS code you are using on the answerer side?
One more question: from your description I assumed, that in your description FF in on the answer side, correct?
(Reporter)

Comment 5

3 years ago
Yes. FF is on the answer side.

This is the core code responsible for session handling (see bottom of this comment).

On initialization, there is a new peer connection created. Everytime a new session is initiated, I create a new peer connection (function createPeerConnection()). I've tried to reuse an existing PC, which works, but I cannot hear any audio. Is it possible to reuse a PC for another session? What has to be done to do so? At least I have to destroy the local stream or can I reuse it as well?


User media is requested as soon, as a SIP/INVITE is received (function handleSIPRequest()). After user media has been granted (cbOnUserMediaGranted) the remote offer is set (function setRemoteOffer()). Unfortunately neither of the callbacks (onSetRemoteSDPSuccess, onSetRemoteSDPError) get's called. It just happens nothing.

The code worked in all FF releases before 34.

So the chronology I use is.
1) Create PC
2) Request UM
3) Set remote SDP
4) Create answer SDP
5) Set answer SDP locally
6) Send answer SDP after all ICE candidates have been gathered

The rest of call establishment is arranged directly between Asterisk and FF.

Could you please tell me, whether these steps are in correct order? What is the correct point in this procedure to request access to UM?


/********************************************************************
 *********************** CROSS-BROWSER WEBRTC SHIM ******************
 ********************************************************************/
window.RTCPeerConnection = window.mozRTCPeerConnection || window.webkitRTCPeerConnection;
window.RTCSessionDescription = window.mozRTCSessionDescription || window.RTCSessionDescription;
window.RTCIceCandidate = window.mozRTCIceCandidate || window.RTCIceCandidate;
navigator.getUserMedia = navigator.getUserMedia || navigator.mozGetUserMedia || navigator.webkitGetUserMedia;


/********************************************************************
 ************************** CONSTRUCTOR *****************************
 ********************************************************************/
module.WebRTCClient = function(config) {

	var self = this;

	if (!config.endpoint) throw "Endpoint required";
	if (!config.onError || typeof config.onError != "function") throw "Handler onError missing or not a function";
	if (!config.onReady || typeof config.onReady != "function") throw "Handler onReady missing or not a function";

	/************************** UA DETECTION ************************/
	this.userAgent = navigator.mozGetUserMedia ? "firefox" : navigator.webkitGetUserMedia ? "chrome" : "unknown";

	/***** REGISTER CLIENT AS MESSAGE HANDLER FOR SIP MESSAGES ******/
	this.endpoint = config.endpoint;
	this.endpoint.registerMessageHandler("sip", this);

	this.onReady = config.onReady;

	/************************** ERROR LOGGING ***********************/
	this.onError = function(err) {

		var errStr = "";
		if (typeof err === "string") {
			errStr = err;
		} else if ((err instanceof Error)) {
			errStr += err.msg ? err.msg + " --- " : "";
			errStr += err.stack ? err.stack : "";
		}

		self.webrtcFeedback("WebRTC Client Error: " + errStr);
		config.onError(errStr);
		de.modima.communication.logger.log("WebRTC Error: ", errStr);
		self.initialize();

	};
	window.onerror = this.onError;

	/********************* MEDIA ACCESS EVENT HANDLER ******************/
	this.onMediaDenied = config.onMediaDenied && typeof config.onMediaDenied == "function" ? config.onMediaDenied : function() {
		this.onError("User has denied media access.");
	};
	this.onMediaGranted = config.onMediaGranted && typeof config.onMediaGranted == "function" ? config.onMediaGranted : function() {};
	this.onMediaRequested = config.onMediaRequested && typeof config.onMediaRequested == "function" ? config.onMediaRequested : function() {};

	/************** CREATE AUDIO ELEMENT FOR INBOUND STREAM *************/
	this.remoteAudio = document.getElementById('audio_rtp_stream_inbound');
	if (!this.remoteAudio) {
		this.remoteAudio = document.createElement('audio');
		this.remoteAudio.setAttribute("id", "audio_rtp_stream_inbound");
		this.remoteAudio.setAttribute("autoplay", true);
	}

	/************************ PEER CONNECTION CONFIG ********************/
	this.connectionConfig = {
		"iceServers": [{
			"url": "stun:stun.l.google.com:19302"
		}, {
			"url": "stun:23.21.150.121"
		}]
	};

	this.connectionConstraints = {
		"optional": [{
			"DtlsSrtpKeyAgreement": true
		}]
	};


	/******************************* MEDIA CONFIG ************************/
	this.mediaConstraints = {
		"audio": true,
	};

	/*
	if (this.userAgent == "chrome") {
		this.mediaConstraints.googEchoCancellation = true;
		this.mediaConstraints.googEchoCancellation2 = true;
		this.mediaConstraints.googAutoGainControl = true;
		this.mediaConstraints.googAutoGainControl2 = true;
		this.mediaConstraints.googNoiseSuppression = true;
		this.mediaConstraints.googNoiseSuppression2 = true;
		this.mediaConstraints.googHighpassFilter = true;
		this.mediaConstraints.googTypingNoiseDetection = true;
		this.mediaConstraints.googAudioMirroring = true;
	}
	*/

	/******************************* SDP CONFIG **************************/
	this.sdpConstraints = {};

	/************************ SIP MESSAGE HISTORY ************************/
	// SIP requests sent by this client;
	this.sipRequests = {};

	// SIP responses sent by this client;
	this.sipResponses = {};
};

/********************************************************************
 ************************ FEEDBACK HANDLING *************************
 ********************************************************************/
module.last_feedback;
module.WebRTCClient.prototype.webrtcFeedback = function(msg) {
	de.modima.communication.logger.warn(msg);
	if (module.last_feedback && (module.last_feedback - new Date().getTime() > 1000)) {
		module.last_feedback = new Date().getTime();
		de.modima.communication.webrtcFeedback("SSIP/" + this.getURI(), msg);
	}
};


/********************************************************************
 ******************************** INIT ******************************
 ********************************************************************/
module.WebRTCClient.prototype.initialize = function(cntRetry) {

	de.modima.communication.logger.log("INIT WEBRTC CLIENT");

	var self = this;

	if (!navigator.mozGetUserMedia && !navigator.webkitGetUserMedia) {
		cntRetry = cntRetry || 0;
		if (cntRetry < 30) {
			de.modima.communication.logger.log("Checking webrtc capabilities... Next attempt (" + cntRetry + ") in 100 millis: ");
			setTimeout(function() {
				self.initialize(cntRetry + 1);
			}, 100);
			return;
		}
		this.onError("User Agent does not support WebRTC. Please use an up to date Chrome or Firefox browser.");
		return;
	}

	this.userMediaRequestPending = false;

	/************************ RESET WEBRTC SESSION ************************/
	this.session = null;

	// Destroy local audio stream
	this.destroyLocalAudio();

	// Destroy remote audio stream
	this.destroyRemoteAudio();

	// Reset peer connection
	this.resetPeerConnection();
};

module.WebRTCClient.prototype.isReady = function() {
	return this.peerConnection && this.peerConnection !== null;
};


/********************************************************************
 ********************** PEER CONNECTION HANDLING ********************
 ********************************************************************/
module.WebRTCClient.prototype.createPeerConnection = function() {
	de.modima.communication.logger.log("CREATE PC");

	var self = this;

	/********************************************************************************************************************************************************************
	 * SIGNALLING STATES:
	 * stable...................there is no SDP offer/answer exchange in progress. This is also the initial state of the connection.
	 * have-local-offer.........the local end of the connection has locally applied a SDP offer.
	 * have-remote-offer........the remote end of the connection has locally applied a SDP offer.
	 * have-local-pranswer......a remote SDP offer has been applied, and a SDP pranswer applied locally.
	 * have-remote-pranswer.....a local SDP offer has been applied, and a SDP pranswer applied remotely.
	 * closed...................the connection is closed.
	 ********************************************************************************************************************************************************************/
	function onSignalingStateChanged(event) {
		//de.modima.communication.logger.log("Signaling state changed:", event.currentTarget.signalingState);
		if (event.currentTarget && event.currentTarget.signalingState) {
			de.modima.communication.logger.log("Signaling state changed:", event.currentTarget.signalingState);
		} else {
			de.modima.communication.logger.log("Signaling state changed:", event);
		}
	}

	/********************************************************************************************************************************************************************
	 * ICE CONNECTION STATES:
	 * new..............the ICE agent is gathering addresses or waiting for remote candidates (or both)
	 * checking.........the ICE agent has remote candidates, on at least one component, and is check them, though it has not found a connection yet. At the same time, it may still be gathering candidates.
	 * connected........the ICE agent has found a usable connection for each component, but is still testing more remote candidates for a better connection. At the same time, it may still be gathering candidates.
	 * completed........the ICE agent has found a usable connection for each component, and is no more testing remote candidates.
	 * failed...........the ICE agent has checked all the remote candidates and didn't find a match for at least one component. Connections may have been found for some components.
	 * disconnected.....liveness check has failed for at least one component. This may be a transient state, e. g. on a flaky network, that can recover by itself.
	 * closed...........the ICE agent has shutdown and is not answering to requests.
	 ********************************************************************************************************************************************************************/
	function onIceConnectionStateChanged(event) {

		if (self.onICEStateChange && typeof self.onICEStateChange == "function") {
			self.onICEStateChange(self.peerConnection.iceConnectionState);
		}

		//de.modima.communication.logger.log("ICE connection state changed: ", event.currentTarget.iceConnectionState);
		if (event.currentTarget && event.currentTarget.iceConnectionState) {
			de.modima.communication.logger.log("ICE connection state changed:", event.currentTarget.iceConnectionState);
		} else {
			de.modima.communication.logger.log("ICE connection state changed:", event);
		}
	}

	function onIceCandidate(event) {
		de.modima.communication.logger.log("Ice candidate: ", event);

		if (!event || !event.candidate && self.peerConnection.remoteDescription) {
			de.modima.communication.logger.log("All ICE candidates gathered. --> Send local SDP");
			self.sendAnswer();
		}
	}

	function onRemoteStreamAdded(event) {
		de.modima.communication.logger.log("Remote stream added.", event);
		self.remoteAudio.src = URL.createObjectURL(event.stream);
	}

	function onRemoteStreamRemoved(event) {
		de.modima.communication.logger.log("Remote stream removed.", event);
	}

	function onNegotiationNeeded(event) {
		de.modima.communication.logger.log("Negotiation needed", event);
	}

	function onStreamRemoved(event) {
		de.modima.communication.logger.log("Stream removed", event);
	}

	/******************************************************
	 ********************** CREATE PC *********************
	 ******************************************************/
	try {
		this.peerConnection = new RTCPeerConnection(this.connectionConfig, this.connectionConstraints);
		this.signalReady();
	} catch (e) {
		this.self(e);
		return;
	}

	/*******************  EVENT HANDLERS *******************/
	this.peerConnection.onaddstream = onRemoteStreamAdded;
	this.peerConnection.onicecandidate = onIceCandidate;
	this.peerConnection.oniceconnectionstatechange = onIceConnectionStateChanged;
	this.peerConnection.onsignalingstatechange = onSignalingStateChanged;
	this.peerConnection.onremovestream = onRemoteStreamRemoved;
	this.peerConnection.onnegotiationneeded = onNegotiationNeeded;
	this.peerConnection.onremovestream = onStreamRemoved;
};

module.WebRTCClient.prototype.resetPeerConnection = function(message) {
	if (this.peerConnection) {
		de.modima.communication.logger.log("CLOSE PEER CONNECTION");
		this.peerConnection.close();
	}
	this.peerConnection = null;
	this.createPeerConnection();
};

/****************************************************
 ************** PROXY MESSAGE HANDLER ***************
 ****************************************************/
module.WebRTCClient.prototype.handleMessage = function(message) {

	message.content = parseSIP(message.content);

	if (message.content.method) {

		/*** SIP REQUEST HANDLING ***/
		this.handleSIPRequest(message);

	} else if (message.content.status) {

		/*** SIP RESPONSE HANDLING ***/
		this.handleSIPResponse(message);

	} else {
		this.webrtcFeedback("Unexpected SIP message: " + JSON.stringify(message));
	}
};


/****************************************************
 *************** SIP REQUEST HANDLING ***************
 ****************************************************/
module.WebRTCClient.prototype.handleSIPRequest = function(message) {

	var self = this;

	/** UPDATE SIP SESSION **/
	if (!this.session) {
		this.session = new module.protocols.sip.SIPSession(message);
	} else {
		this.session.update(message);
	}

	var sip = message.content;

	/** HANDLE MESSAGE **/
	switch (sip.method) {

		case "INVITE":

			/** 100 TRYING **/
			this.createSIPResponse(100);

			var cbOnUserMediaGranted = function() {

				self.onMediaGranted();

				de.modima.communication.logger.log("User media granted --> Set remote offer");
				self.setRemoteOffer({
					"type": "offer",
					"sdp": self.session.server.sdp
				});
			};

			var cbOnUserMediaDenied = function() {

				self.onMediaDenied();

				/** 603 DECLINED **/
				self.createSIPResponse(603, true);
				self.onError("Media access denied by user.");
			};

			self.doGetUserMedia(cbOnUserMediaGranted, cbOnUserMediaDenied, self.onUserMediaRequested);
			break;



		case "BYE":

			this.createSIPResponse(200, true);
			this.onRemoteHangup();
			break;


		case "CANCEL":

			this.createSIPResponse(200, true);
			this.onRemoteHangup();
			break;


		case "ACK":

			this.stopResponseRetry(message);
			break;


		default:

			this.webrtcFeedback("Received unexpected SIP request: ", JSON.stringify(message));
	}
};

/****************************************************
 *************** SIP RESPONSE HANDLING **************
 ****************************************************/
module.WebRTCClient.prototype.handleSIPResponse = function(message) {

	var sip = message.content;

	switch (sip.status) {

		case "200":

			this.stopRequestRetry(message);
			break;


		case "481":

			this.stopRequestRetry(message);
			break;


		default:

			this.webrtcFeedback("Received unexpected SIP response: ", JSON.stringify(message));
	}
};


/********************************************************************
 ************************** MEDIA HANDLING **************************
 ********************************************************************/
module.WebRTCClient.prototype.doGetUserMedia = function(cbOnUserMediaGranted, cbOnUserMediaDenied, cbOnUserMediaRequested) {

	var self = this;

	cbOnUserMediaGranted = cbOnUserMediaGranted || this.onMediaGranted;
	cbOnUserMediaDenied = cbOnUserMediaDenied || this.onMediaDenied;
	cbOnUserMediaRequested = cbOnUserMediaRequested || this.onMediaRequested;

	function onUserMediaSuccess(stream) {
		de.modima.communication.logger.log("MEDIA ACCESS GRANTED", stream);
		self.userMediaRequestPending = false;

		de.modima.communication.logger.log("ADD OUTBOUND STREAM TO PC");
		self.peerConnection.addStream(stream);

		cbOnUserMediaGranted();
	}

	function onUserMediaError() {
		de.modima.communication.logger.log("MEDIA ACCESS DENIED");
		self.userMediaRequestPending = false;
		cbOnUserMediaDenied();
	}

	/*********************************************************
	 ***************** ACQUIRE MEDIA ACCESS ******************
	 ********************************************************/
	if (self.peerConnection && self.peerConnection.localStream && !self.peerConnection.localStream.ended) {
		/** STREAM EXISTING **/
		de.modima.communication.logger.log("MEDIA STREAM EXISTING", self.peerConnection.localStream);
		cbOnUserMediaGranted();
	} else if (this.userMediaRequestPending) {
		/** USER REQUEST PENDING **/
		de.modima.communication.logger.log("Media request pending. Wait for user action!");
		cbOnUserMediaRequested();
	} else {
		/** REQUEST ACCESS TO USER MEDIA **/
		try {
			navigator.getUserMedia(this.mediaConstraints, onUserMediaSuccess, onUserMediaError);
			this.userMediaRequestPending = true;
			cbOnUserMediaRequested();
		} catch (e) {
			this.onError(e);
		}
	}
};

module.WebRTCClient.prototype.destroyLocalAudio = function(value) {
	de.modima.communication.logger.log("DESTROY LOCAL AUDIO");
	if (this.peerConnection && this.peerConnection.localStream) {
		de.modima.communication.logger.log("STOP LOCAL STREAM");
		this.peerConnection.localStream.stop();
		this.peerConnection.removeStream(this.peerConnection.localStream);
	}
};

module.WebRTCClient.prototype.destroyRemoteAudio = function(value) {
	de.modima.communication.logger.log("DESTROY REMOTE AUDIO");
	if (this.peerConnection && this.peerConnection.remoteStream) {
		de.modima.communication.logger.log("STOP REMOTE STREAM");
		this.peerConnection.remoteStream.stop();
		this.peerConnection.removeStream(this.peerConnection.remoteStream);
	}

	if (this.remoteAudio) {
		de.modima.communication.logger.log("STOP REMOTE AUDIO");
	}
};

/********************************************************************
 ***************************** SDP HANDLING *************************
 ********************************************************************/
module.WebRTCClient.prototype.createLocalDescription = function() {

	var self = this;

	function onCreateSDPError(error) {
		self.onError("Failed to create local SDP. Cause: " + error.toString());
	}

	function onSetSDPSuccess() {
		de.modima.communication.logger.log("Set local SDP success.");
	}

	function onSetSDPError(error) {
		self.onError("Failed to set local SDP. Cause: " + error.toString());
	}

	function setLocalSDP(sessionDescription) {

		if (!self.session) {
			self.onError("Failed to set local SDP. Cause: No session");
			return;
		}

		de.modima.communication.logger.log("Set local session description. UA: " + self.userAgent + " | Signaling: " + self.peerConnection.signalingState + " | ICE Gathering: " + self.peerConnection.iceGatheringState);

		self.session.client.sdp = sessionDescription.sdp;

		self.peerConnection.setLocalDescription(sessionDescription, onSetSDPSuccess, onSetSDPError);
	}

	this.peerConnection.createAnswer(setLocalSDP, onCreateSDPError, this.sdpConstraints);
};


module.WebRTCClient.prototype.setRemoteOffer = function(sessionDescription) {

	var self = this;

	function onSetRemoteSDPSuccess() {
		de.modima.communication.logger.log('Set remote session description success.');
		self.createLocalDescription();
	}

	function onSetRemoteSDPError(error) {
		self.onError('Failed to set remote session description: ' + "--> Reset WebRTC client");
	}

	de.modima.communication.logger.log("Set remote session description: ", sessionDescription);
	sessionDescription.sdp = stringifySDP(sessionDescription.sdp);
	this.peerConnection.setRemoteDescription(new RTCSessionDescription(sessionDescription), onSetRemoteSDPSuccess, onSetRemoteSDPError);
	console.log("SDP: ", this.peerConnection.remoteDescription);
};


module.WebRTCClient.prototype.sendAnswer = function() {

	if (!this.session) {
		this.onError("Failed to send answer. Cause: No session. Client state: " + this.state);
		return;
	}

	this.session.client.sdp = this.peerConnection.localDescription.sdp;
	this.createSIPResponse(200, true);
};
(Reporter)

Comment 6

3 years ago
Could you also send me your code, where this SDP is working? I've tried to set it in FF console and the effect stays the same. CB Handlers don't get called.
(In reply to marko.seidenglanz from comment #5)

> On initialization, there is a new peer connection created. Everytime a new
> session is initiated, I create a new peer connection (function
> createPeerConnection()). I've tried to reuse an existing PC, which works,
> but I cannot hear any audio. Is it possible to reuse a PC for another
> session?

No.  We don't support onnegotiationneeded yet (no renegotiation) (and closed PC's are never reusable).

> What has to be done to do so? At least I have to destroy the local
> stream or can I reuse it as well?

You can just reuse the MediaStream.

> User media is requested as soon, as a SIP/INVITE is received (function
> handleSIPRequest()). After user media has been granted
> (cbOnUserMediaGranted) the remote offer is set (function setRemoteOffer()).

I don't think there's any need to wait to set the RemoteOffer.

> Unfortunately neither of the callbacks (onSetRemoteSDPSuccess,
> onSetRemoteSDPError) get's called. It just happens nothing.

Hmmm


I'll bet this is related to moving to all-trickle-ice (per the spec).

> 
> The code worked in all FF releases before 34.
> 
> So the chronology I use is.
> 1) Create PC
> 2) Request UM
> 3) Set remote SDP

And here's where you're stalling

> 4) Create answer SDP
> 5) Set answer SDP locally
> 6) Send answer SDP after all ICE candidates have been gathered
> 
> The rest of call establishment is arranged directly between Asterisk and FF.
> 
> Could you please tell me, whether these steps are in correct order? What is
> the correct point in this procedure to request access to UM?

That depends on your UI.  Generally, though, it's best to request it after the user decides to accept.  You can request it anytime, but if you do it before they say "yes" we'll put a very obvious "mic active" indicator up (assuming they have allowed persistent permissions to your app).  If they haven't allowed it, it could be confusing/annoying, and if they click on your page the 'doorhanger' request will roll up until manually reopened.  You do want ICE gathering to start as soon as possible, of course.
(Reporter)

Comment 8

3 years ago
This is the URL where you can try the application: http://test.webrtc.24dial.com/web/index.html

Just click on 'DIAL' in the "PREVIEW" section. You can do a hangup by clicking on 'CLIENT HANGUP' Button.

In FF < 34 the connection get's established correctly (Check FF Console and about:webrtc)
In FF > 34 the last log message is: "Set remote session description" and pc.remoteDescription is NULL

Please have a try and tell me whether you can reproduce the same behaviour or not.
Created attachment 8497925 [details]
answer.html

This is a stripped down example which shows that the callback for setRemoteDescription still get called and the remoteDescription is not empty.
With attachment 8497925 [details] you can see in the console log that setRemoteDescription success callback still gets called, even with the SDP from your original report.

For the onaddstream verification I used my own little manual calling pages. You can find them here: https://github.com/nils-ohlmeier/mozwebrtctools/tree/master/manual_call

During my manual testing I encountered a situation where onaddstream did not get called, but that was because I did not have a stream attached to the peer connection and therefore the SDP answer indicated correctly 'recvonly'. So the offerer realy had nothing to add.
I did not have the time yet to try your links or study your code.
So I tried the link now with FF 33 an 34.
The SDP was null for me on 33, but actually showed content on 34. Not sure what is going on there. In both cases the success callback for setRemoteDescription got invoked.

Now with 33 the call connected and I heard a voice prompt. With 34 I did not hear the voice prompt.

The problem is a know bug in our current implementation: pc.localDescription on the answerer side does not get updated with the ICE candidates. This is apparently a side effect of the new trickle ICE code which landed in 34.
I'm about to write test cases for that in bug 1060102 to increase the pressure on fixing this.

Now the interesting question is: why does your Asterisk need the ICE candidates from the remote side at all to establish the connection?
If you do the same things with two FF instances, the answerer will start sending ICE check request to the ports from the offer. The offerer answers these ICE requests on its media ports. And therefore the connection gets established even though the offerer never gets an SDP with candidates in it or ICE candidates from the answerer separately.

So basically both sides have bugs:
- Asterisk is suppose to listen on the media ports when it creates the offer (or creates the ICE candidates) and it needs to be ready to answer ICE requests and establish the transport and media layer without knowing the remote addresses.
- FF fails to add the ICE candidates to the SDP answer since version 34.
Status: UNCONFIRMED → NEW
status-firefox32: --- → unaffected
status-firefox33: --- → unaffected
status-firefox34: --- → affected
status-firefox35: --- → affected
Ever confirmed: true
OS: Linux → All
Hardware: x86_64 → All
Summary: WebRTC: Remote stream is not received anymore after setting remote session description → ICE candidates don't get added to SDP answer
(Reporter)

Comment 12

3 years ago
I've tried your example and observed the same problem as with my code. The callback doesn't get called anymore, but it does in earlier versions and in Chrome too.

I tested it with FF build 34.0a2 (2014-09-30).
I don't have any idea, why it is working in your case.

I also tried your suggestion to disable ICE trickling by not providing any ICE Servers to the PC. It worked as you said (except in FF 34).
(In reply to marko.seidenglanz from comment #12)
> I've tried your example and observed the same problem as with my code. The
> callback doesn't get called anymore, but it does in earlier versions and in
> Chrome too.
> 
> I tested it with FF build 34.0a2 (2014-09-30).
> I don't have any idea, why it is working in your case.

My only idea at this point would be if you could try it again with a fresh user profile.
 
> I also tried your suggestion to disable ICE trickling by not providing any
> ICE Servers to the PC. It worked as you said (except in FF 34).

You don't disable trickiling by not providing ICE servers. You would have to not wait for the end trickeling.

From your earlier reply:

> 5) Set answer SDP locally
> 6) Send answer SDP after all ICE candidates have been gathered

Basically send the SDP right after you set it locally. Once Asterisk receives the SDP it knows at least about the amount of streams, which codec to use etc. If it will make it start answering ICE checks is another question.
Obviously if you send the initial SDP without the ICE candidates in it you would want/should send the ICE candidates to Asterisk once they come in. I'm guessing Asterisk doesn't support that.

I'm not saying that changing your code this way will fix things. I'm just saying this is how it is suppose to work according to the standards.
Unfortunately it appears to me that you are stuck for now with these two bugs, one on the Asterisk side one on the FF side.
Regarding your own code:

    this.peerConnection.setRemoteDescription(new RTCSessionDescription(sessionDescription), onSetRemoteSDPSuccess, onSetRemoteSDPError);
    console.log("SDP: ", this.peerConnection.remoteDescription);

This is actually a race condition. You can not expect remoteDescription to be set before either the success or the failure callback got called. (Sure this makes not much sense if the callbacks don't work.) Just saying this explains why I say it empty on 33, but have content on 34, as this logging will depend on how quickly the C++ code in the background processed the setRemoteDescription() call.
(Assignee)

Comment 15

3 years ago
It may be that bug 1060625 will help with this some; I appear to have inadvertently fixed bug 1055787 in that patch, which is why you aren't seeing any candidates in your local SDP. Try out Nightly and see if that works better for you.
(Assignee)

Comment 16

3 years ago
Ok, I've tried Nightly, and we get further, but DTLS never establishes. I never see a response to our Client Hello. Is there anything in your logs that hint why this might be?
(Assignee)

Comment 17

3 years ago
CCing mt since we've made some changes to DTLS version and cipher suite stuff recently, maybe this is the problem.
What DTLS cipher suites are enabled on your server?
Flags: needinfo?(marko.seidenglanz)
(Assignee)

Comment 19

3 years ago
So bug 1060625 is probably going to be too large to uplift to aurora, meaning we'll need a stopgap to fix the incorporation of candidates into local SDP. I don't think this will be too hard.
(Assignee)

Comment 20

3 years ago
Created attachment 8498456 [details] [diff] [review]
Part 1: (aurora only) Stopgap patch that fixes bug 1055787 in Aurora.

Stopgap patch for local candidate incorporation. Applies to Aurora (34), but no later.
(Assignee)

Updated

3 years ago
Assignee: nobody → docfaraday
Status: NEW → ASSIGNED
(Assignee)

Comment 21

3 years ago
https://tbpl.mozilla.org/?tree=Try&rev=5c6305527770
We should consider uplifting bug 1060102 together with attachment 8498456 [details] [diff] [review] to prove that it works.
(Reporter)

Comment 23

3 years ago
(In reply to Martin Thomson [:mt] from comment #18)
> What DTLS cipher suites are enabled on your server?

I've enabled all suites. Apparently wireshark tells me, that "TLS_RSA_WITH_AES_128_CBC_SHA" seems to be used.
Flags: needinfo?(marko.seidenglanz)
(Reporter)

Comment 24

3 years ago
(In reply to Martin Thomson [:mt] from comment #18)
> What DTLS cipher suites are enabled on your server?

(In reply to Byron Campen [:bwc] from comment #15)
> It may be that bug 1060625 will help with this some; I appear to have
> inadvertently fixed bug 1055787 in that patch, which is why you aren't
> seeing any candidates in your local SDP. Try out Nightly and see if that
> works better for you.

I've tried 35.0a1 (2014-10-01) without success. CB doesn't get called. I've tried with your code and also with my implementation.
(Reporter)

Comment 25

3 years ago
I also cannot see any ClientHello beeing sent from FF.
(Reporter)

Comment 26

3 years ago
On PC Init FF debug log says:

2014-10-02 08:13:50.966898 UTC - 1156273984[7f1143967380]: [main|PeerConnectionImpl] PeerConnectionImpl.cpp:279: PeerConnectionImpl: PeerConnectionImpl constructor for 
2014-10-02 08:13:50.966959 UTC - 1156273984[7f1143967380]: [main|PeerConnectionMedia] PeerConnectionMedia.cpp:181: Created PeerConnection: 0x7f10f23ee3d0
2014-10-02 08:13:50.967454 UTC - 1156273984[7f1143967380]: [main|ccapp] cc_call_feature.c:120: SIPCC-SIP_CC_PROV: 18/1, CC_CreateCall: 
2014-10-02 08:13:50.967496 UTC - 1156273984[7f1143967380]: [main|CC_SIPCCCall] CC_SIPCCCall.cpp:46: Creating  CC_SIPCCCall 65554
2014-10-02 08:13:50.967685 UTC - 1156273984[7f1143967380]: [main|CC_SIPCCCall] CC_SIPCCCall.cpp:739: setPeerConnection
2014-10-02 08:13:50.967752 UTC - 1156273984[7f1143967380]: [main|fim] fim.c:159: SIPCC-GSM_DBG_PTR: FIM 18  : fim_get_call_chn_by_call_id        : chn= (nil)
2014-10-02 08:13:50.967795 UTC - 1156273984[7f1143967380]: [main|fim] fim.c:159: SIPCC-GSM_DBG_PTR: FIM 0   : fim_get_call_chn_by_call_id        : chn= 0x7f1124ef2190
2014-10-02 08:13:50.967829 UTC - 1156273984[7f1143967380]: [main|fim] fim.c:204: SIPCC-GSM: FIM 18  : fim_get_new_call_chn               : HEAD
2014-10-02 08:13:50.967862 UTC - 1156273984[7f1143967380]: [main|fim] fim.c:204: SIPCC-GSM: FIM 18  : fim_get_new_call_chn               : CNF
2014-10-02 08:13:50.967896 UTC - 1156273984[7f1143967380]: [main|fsm_sm] fsm.c:232: SIPCC-GSM_DBG_PTR: FSM 0   : fsm_get_fcb_by_call_id             : fcb= 0x7f111fd55180
2014-10-02 08:13:50.967929 UTC - 1156273984[7f1143967380]: [main|fsm_sm] fsm.c:266: SIPCC-GSM_DBG_PTR: FSM 18  : fsm_get_new_fcb                    : fcb= 0x7f111fd55180
2014-10-02 08:13:50.967961 UTC - 1156273984[7f1143967380]: [main|fim] fim.c:204: SIPCC-GSM: FIM 18  : fim_get_new_call_chn               : B2BCNF
2014-10-02 08:13:50.968013 UTC - 1156273984[7f1143967380]: [main|fsm_sm] fsm.c:232: SIPCC-GSM_DBG_PTR: FSM 0   : fsm_get_fcb_by_call_id             : fcb= 0x7f111fd551b0
2014-10-02 08:13:50.968046 UTC - 1156273984[7f1143967380]: [main|fsm_sm] fsm.c:266: SIPCC-GSM_DBG_PTR: FSM 18  : fsm_get_new_fcb                    : fcb= 0x7f111fd551b0
2014-10-02 08:13:50.968078 UTC - 1156273984[7f1143967380]: [main|fim] fim.c:204: SIPCC-GSM: FIM 18  : fim_get_new_call_chn               : XFR
2014-10-02 08:13:50.968110 UTC - 1156273984[7f1143967380]: [main|fsm_sm] fsm.c:232: SIPCC-GSM_DBG_PTR: FSM 0   : fsm_get_fcb_by_call_id             : fcb= 0x7f111fd551e0
2014-10-02 08:13:50.968141 UTC - 1156273984[7f1143967380]: [main|fsm_sm] fsm.c:266: SIPCC-GSM_DBG_PTR: FSM 18  : fsm_get_new_fcb                    : fcb= 0x7f111fd551e0
2014-10-02 08:13:50.968173 UTC - 1156273984[7f1143967380]: [main|fim] fim.c:204: SIPCC-GSM: FIM 18  : fim_get_new_call_chn               : DEF
2014-10-02 08:13:50.968205 UTC - 1156273984[7f1143967380]: [main|fsm_sm] fsm.c:232: SIPCC-GSM_DBG_PTR: FSM 0   : fsm_get_fcb_by_call_id             : fcb= 0x7f111fd55210
2014-10-02 08:13:50.968237 UTC - 1156273984[7f1143967380]: [main|fsm_sm] fsm.c:266: SIPCC-GSM_DBG_PTR: FSM 18  : fsm_get_new_fcb                    : fcb= 0x7f111fd55210
2014-10-02 08:13:50.968268 UTC - 1156273984[7f1143967380]: [main|fim] fim.c:219: SIPCC-GSM_DBG_PTR: FIM 18  : fim_get_new_call_chn               : call_chn= 0x7f1124ef2190
2014-10-02 08:13:50.968300 UTC - 1156273984[7f1143967380]: [main|fim] fim.c:159: SIPCC-GSM_DBG_PTR: FIM 18  : fim_get_call_chn_by_call_id        : chn= 0x7f1124ef2190
2014-10-02 08:13:50.968343 UTC - 1156273984[7f1143967380]: [main|fsm_sm] fsmdef.c:3469: SIPCC-FSM: fsmdef_setpeerconnection: Entered.
2014-10-02 08:13:50.968387 UTC - 1156273984[7f1143967380]: [main|config] config_api.c:143: SIPCC-CONFIG_API: print_config_value: CFGID 113: Get Val: sdpmode = 1
2014-10-02 08:13:50.968430 UTC - 1156273984[7f1143967380]: [main|fsm_sm] fsmdef.c:704: SIPCC-FSM: DEF 0   /0: fsmdef_get_dcb_by_call_id          : dcb= 0x7f110e9d1420
2014-10-02 08:13:50.968471 UTC - 1156273984[7f1143967380]: [main|fsm_sm] fsmdef.c:1205: SIPCC-FSM: DEF 18  /0: fsmdef_get_new_dcb                 : dcb= 0x7f110e9d1420
2014-10-02 08:13:50.968524 UTC - 1156273984[7f1143967380]: [main|lsm] lsm.c:2208: SIPCC-LSM: 18  /1: lsm_get_facility_by_line           : exp= 0
2014-10-02 08:13:50.968567 UTC - 1156273984[7f1143967380]: [main|config] config_api.c:58: SIPCC-CONFIG_API: config_get_string: CFGID 227: get str: Name = JSEP
2014-10-02 08:13:50.968661 UTC - 1156273984[7f1143967380]: [main|config] config_api.c:143: SIPCC-CONFIG_API: print_config_value: CFGID 125: Get Val: Feat = 9
2014-10-02 08:13:50.968704 UTC - 1156273984[7f1143967380]: [main|config] config_api.c:58: SIPCC-CONFIG_API: config_get_string: CFGID 227: get str: Name = JSEP
2014-10-02 08:13:50.968734 UTC - 766506752[7f11439676e0]: NrIceCtx(PC:1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html)): gathering state 0->1
2014-10-02 08:13:50.968747 UTC - 1156273984[7f1143967380]: [main|config] config_api.c:143: SIPCC-CONFIG_API: print_config_value: CFGID 125: Get Val: Feat = 9
2014-10-02 08:13:50.968844 UTC - 1156273984[7f1143967380]: [main|lsm] lsm.c:1765: lsm_get_instances_available_cnt: line=1, expline=0, free=48, all_used=2, all_max=50, all_free=48
2014-10-02 08:13:50.968862 UTC - 766506752[7f11439676e0]: NrIceCtx(PC:1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html)): trickling candidate candidate:0 1 UDP 2122252543 192.168.35.78 33726 typ host
2014-10-02 08:13:50.968888 UTC - 1156273984[7f1143967380]: [main|lsm] lsm.c:1769: lsm_get_instances_available_cnt: line=1, expline=0, free_instances=48
2014-10-02 08:13:50.968946 UTC - 766506752[7f11439676e0]: [Socket Thread|PeerConnectionMedia] PeerConnectionMedia.cpp:621: OnCandidateFound: 1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html): stream1/audio
2014-10-02 08:13:50.969004 UTC - 1156273984[7f1143967380]: [main|config] config_api.c:58: SIPCC-CONFIG_API: config_get_string: CFGID 227: get str: Name = JSEP
2014-10-02 08:13:50.969093 UTC - 1156273984[7f1143967380]: [main|config] config_api.c:143: SIPCC-CONFIG_API: print_config_value: CFGID 125: Get Val: Feat = 9
2014-10-02 08:13:50.969128 UTC - 1156273984[7f1143967380]: [main|fsm_sm] fsmdef.c:1068: SIPCC-FSM: 1/18, fsmdef_init_dcb: call_not_counted_in_mnc_bt = FALSE
2014-10-02 08:13:50.969144 UTC - 766506752[7f11439676e0]: NrIceCtx(PC:1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html)): trickling candidate candidate:0 2 UDP 2122252542 192.168.35.78 39021 typ host
2014-10-02 08:13:50.969162 UTC - 1156273984[7f1143967380]: [main|gsm] gsm_sdp.c:122: SIPCC-GSM: gsmsdp_get_media_capability: dcb video pref 3
2014-10-02 08:13:50.969195 UTC - 766506752[7f11439676e0]: [Socket Thread|PeerConnectionMedia] PeerConnectionMedia.cpp:621: OnCandidateFound: 1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html): stream1/audio
2014-10-02 08:13:50.969234 UTC - 1156273984[7f1143967380]: [main|config] config_api.c:143: SIPCC-CONFIG_API: print_config_value: CFGID 113: Get Val: sdpmode = 1
2014-10-02 08:13:50.969296 UTC - 1156273984[7f1143967380]: [main|fsm_sm] fsm.c:157: SIPCC-GSM_DBG_PTR: FSM 18  : fsm_get_fcb_by_call_id_and_type    : fcb= 0x7f111fd55180
2014-10-02 08:13:50.969333 UTC - 1156273984[7f1143967380]: [main|fsm_sm] fsm.c:157: SIPCC-GSM_DBG_PTR: FSM 18  : fsm_get_fcb_by_call_id_and_type    : fcb= 0x7f111fd551b0
2014-10-02 08:13:50.969333 UTC - 766506752[7f11439676e0]: NrIceCtx(PC:1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html)): trickling candidate candidate:0 1 UDP 2122252543 192.168.35.78 42289 typ host
2014-10-02 08:13:50.969400 UTC - 766506752[7f11439676e0]: [Socket Thread|PeerConnectionMedia] PeerConnectionMedia.cpp:621: OnCandidateFound: 1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html): stream2/video
2014-10-02 08:13:50.969484 UTC - 766506752[7f11439676e0]: NrIceCtx(PC:1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html)): trickling candidate candidate:0 2 UDP 2122252542 192.168.35.78 42777 typ host
2014-10-02 08:13:50.969515 UTC - 766506752[7f11439676e0]: [Socket Thread|PeerConnectionMedia] PeerConnectionMedia.cpp:621: OnCandidateFound: 1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html): stream2/video
2014-10-02 08:13:50.969584 UTC - 766506752[7f11439676e0]: NrIceCtx(PC:1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html)): trickling candidate candidate:0 1 UDP 2122252543 192.168.35.78 42120 typ host
2014-10-02 08:13:50.969646 UTC - 766506752[7f11439676e0]: [Socket Thread|PeerConnectionMedia] PeerConnectionMedia.cpp:621: OnCandidateFound: 1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html): stream3/data
2014-10-02 08:13:50.969715 UTC - 766506752[7f11439676e0]: NrIceCtx(PC:1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html)): trickling candidate candidate:0 2 UDP 2122252542 192.168.35.78 53178 typ host
2014-10-02 08:13:50.969746 UTC - 766506752[7f11439676e0]: [Socket Thread|PeerConnectionMedia] PeerConnectionMedia.cpp:621: OnCandidateFound: 1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html): stream3/data
2014-10-02 08:13:50.969867 UTC - 1156273984[7f1143967380]: [main|fsm_sm] fsm.c:157: SIPCC-GSM_DBG_PTR: FSM 18  : fsm_get_fcb_by_call_id_and_type    : fcb= 0x7f111fd551e0
2014-10-02 08:13:50.969902 UTC - 1156273984[7f1143967380]: [main|fsm_sm] fsm.c:157: SIPCC-GSM_DBG_PTR: FSM 18  : fsm_get_fcb_by_call_id_and_type    : fcb= 0x7f111fd55210
2014-10-02 08:13:50.969934 UTC - 1156273984[7f1143967380]: [main|fsm_sm] fsmdef.c:3510: SIPCC-FSM: fsmdef_setpeerconnection: Setting peerconnection handle for (1/18) to 4a4ae40f6880b51b
2014-10-02 08:13:50.969967 UTC - 1156273984[7f1143967380]: [main|def] fsm.c:346: SIPCC-FSM: 1/18, fsm_change_state: DEF: IDLE -> STABLE
2014-10-02 08:13:50.969999 UTC - 1156273984[7f1143967380]: [main|def] dcsm.c:397: SIPCC-DCSM: dcsm_update_gsm_state: 18 : DCSM_READY --> DCSM_READY
2014-10-02 08:13:51.036510 UTC - 1156273984[7f1143967380]: [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2289: IceGatheringStateChange_m
2014-10-02 08:13:51.140203 UTC - 766506752[7f11439676e0]: NrIceCtx(PC:1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html)): trickling candidate candidate:1 1 UDP 1686110207 84.183.251.20 33726 typ srflx raddr 192.168.35.78 rport 33726
2014-10-02 08:13:51.140257 UTC - 766506752[7f11439676e0]: [Socket Thread|PeerConnectionMedia] PeerConnectionMedia.cpp:621: OnCandidateFound: 1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html): stream1/audio
2014-10-02 08:13:51.171896 UTC - 766506752[7f11439676e0]: NrIceCtx(PC:1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html)): trickling candidate candidate:1 2 UDP 1686110206 84.183.251.20 39021 typ srflx raddr 192.168.35.78 rport 39021
2014-10-02 08:13:51.172090 UTC - 766506752[7f11439676e0]: [Socket Thread|PeerConnectionMedia] PeerConnectionMedia.cpp:621: OnCandidateFound: 1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html): stream1/audio
2014-10-02 08:13:51.190385 UTC - 766506752[7f11439676e0]: NrIceCtx(PC:1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html)): trickling candidate candidate:1 1 UDP 1686110207 84.183.251.20 42289 typ srflx raddr 192.168.35.78 rport 42289
2014-10-02 08:13:51.190448 UTC - 766506752[7f11439676e0]: [Socket Thread|PeerConnectionMedia] PeerConnectionMedia.cpp:621: OnCandidateFound: 1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html): stream2/video
2014-10-02 08:13:51.209503 UTC - 766506752[7f11439676e0]: NrIceCtx(PC:1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html)): trickling candidate candidate:1 2 UDP 1686110206 84.183.251.20 42777 typ srflx raddr 192.168.35.78 rport 42777
2014-10-02 08:13:51.209565 UTC - 766506752[7f11439676e0]: [Socket Thread|PeerConnectionMedia] PeerConnectionMedia.cpp:621: OnCandidateFound: 1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html): stream2/video
2014-10-02 08:13:51.235373 UTC - 766506752[7f11439676e0]: NrIceCtx(PC:1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html)): trickling candidate candidate:1 1 UDP 1686110207 84.183.251.20 42120 typ srflx raddr 192.168.35.78 rport 42120
2014-10-02 08:13:51.235453 UTC - 766506752[7f11439676e0]: [Socket Thread|PeerConnectionMedia] PeerConnectionMedia.cpp:621: OnCandidateFound: 1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html): stream3/data
2014-10-02 08:13:51.252417 UTC - 766506752[7f11439676e0]: NrIceCtx(PC:1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html)): trickling candidate candidate:1 2 UDP 1686110206 84.183.251.20 53178 typ srflx raddr 192.168.35.78 rport 53178
2014-10-02 08:13:51.252505 UTC - 766506752[7f11439676e0]: [Socket Thread|PeerConnectionMedia] PeerConnectionMedia.cpp:621: OnCandidateFound: 1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html): stream3/data
2014-10-02 08:13:51.252571 UTC - 766506752[7f11439676e0]: NrIceCtx(PC:1412237630967432 (id=77 url=http://test.webrtc.24dial.com/web/index.html)): gathering state 1->2
2014-10-02 08:13:51.252671 UTC - 1156273984[7f1143967380]: [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2289: IceGatheringStateChange_m


On UM request it says:

2014-10-02 08:14:11.660650 UTC - 1156273984[7f1143967380]: [main|PeerConnectionMedia] PeerConnectionMedia.cpp:311: AddStream: MediaStream: 0x7f110a732d40
2014-10-02 08:14:11.660725 UTC - 1156273984[7f1143967380]: [main|fim] fim.c:159: SIPCC-GSM_DBG_PTR: FIM 18  : fim_get_call_chn_by_call_id        : chn= 0x7f1124ef2190
2014-10-02 08:14:11.660785 UTC - 1156273984[7f1143967380]: [main|fsm_sm] fsmdef.c:3525: SIPCC-FSM: fsmdef_addstream: Entered.
2014-10-02 08:14:11.660841 UTC - 1156273984[7f1143967380]: [main|config] config_api.c:143: SIPCC-CONFIG_API: print_config_value: CFGID 113: Get Val: sdpmode = 1


On pc.setRemoteDescription it just says nothing.


The same messages appear using your test code.
I think that the ClientHello thing shows where the disconnect lies.  Comment 16 claims that the ClientHello is being sent; comment 25 claims that it's not being received.  Can we look at the network for evidence that it's being dropped?
(Assignee)

Comment 28

3 years ago
Can you get the full logs from your test, especially including the logging that happens when the PeerConnectionImpl is destroyed? There might be some hints in the Timecard.
Flags: needinfo?(marko.seidenglanz)
(Assignee)

Updated

3 years ago
Attachment #8498456 - Flags: review?(drno)
(Reporter)

Comment 29

3 years ago
Created attachment 8499471 [details]
FF NC Logfile (34.0a2 (2014-10-02))

Today I tested with FF 34.0a2 (2014-10-02) and finally the SDP-CB Handler get's called.
Unfortunately I cannot hear the remote audio stream.
Flags: needinfo?(marko.seidenglanz)
Comment on attachment 8498456 [details] [diff] [review]
Part 1: (aurora only) Stopgap patch that fixes bug 1055787 in Aurora.

Review of attachment 8498456 [details] [diff] [review]:
-----------------------------------------------------------------

Tests from bug 1060102 fail, as expected, before applying this patch, and they turn green with this patch applied.

LGTM
Attachment #8498456 - Flags: review?(drno) → review+
(Assignee)

Comment 31

3 years ago
(In reply to marko.seidenglanz from comment #29)
> Created attachment 8499471 [details]
> FF NC Logfile (34.0a2 (2014-10-02))
> 
> Today I tested with FF 34.0a2 (2014-10-02) and finally the SDP-CB Handler
> get's called.
> Unfortunately I cannot hear the remote audio stream.

That is the symptom I observed on Nightly, which was caused by the failure in the DTLS handshake. Are you seeing the DTLS handshake complete on your end? Also, what did you end up doing to get the callback from setRemote? Can you get Nightly to work?
Flags: needinfo?(marko.seidenglanz)
(Reporter)

Comment 32

3 years ago
Created attachment 8500324 [details]
STUN_FF_AST

I can see a binding request from FF and a success response sent from Asterisk, but not the other way round. There is also no DTLS Handshake beeing started. Tested with FF 34.0a2 (2014-10-05).
Flags: needinfo?(marko.seidenglanz)
(Reporter)

Comment 33

3 years ago
Created attachment 8500330 [details]
FF CLIENT HELLO (35.0a1 (2014-10-05))

In Nightly, there is also a binding request beeing sent from Asterisk and the according success response from FF. After that FF sends a CLIENT_HELLO, which is never beeing answered from Asterisk.
(Reporter)

Comment 34

3 years ago
Created attachment 8500337 [details]
FF CLIENT HELLO (35.0a1 (2014-10-05))

In Nightly, there is also a binding request beeing sent from Asterisk and the according success response from FF. After that FF sends a CLIENT_HELLO, which is never beeing answered from Asterisk.
Attachment #8500330 - Attachment is obsolete: true
(Reporter)

Comment 35

3 years ago
Created attachment 8500342 [details]
CHROME CLIENT HELLO

I inspected the CLIENT_HELLO sent by chrome and it looks almost the same as the CLIENT_HELLO sent from FF. The difference is, that by using Chrome Browser Asterisk sends an SERVER_HELLO back and the handshake is completed.
(Assignee)

Comment 36

3 years ago
(In reply to marko.seidenglanz from comment #32)
> Created attachment 8500324 [details]
> STUN_FF_AST
> 
> I can see a binding request from FF and a success response sent from
> Asterisk, but not the other way round. There is also no DTLS Handshake
> beeing started. Tested with FF 34.0a2 (2014-10-05).

This would be expected if no candidates were making it to asterisk, due to the bug where 34 does not incorporate candidates into the SDP.
(Assignee)

Comment 37

3 years ago
In those attachments I can see a pretty important difference between the two client hellos. We're using the DTLS Client Hello, whereas Chrome seems to be using a TLS Client Hello.
The failure with FF 34 is expected as the patch has not landed yet.

Why is that the FF Client Hello goes from a public IP to a private IP, but the Google Chrome Client Hello goes from a private IP to a public IP? Are you sure that the Client Hello in both cases is send by the browser, and not by Asterisk?
See Also: → bug 948683
(In reply to Byron Campen [:bwc] from comment #37)
> In those attachments I can see a pretty important difference between the two
> client hellos. We're using the DTLS Client Hello, whereas Chrome seems to be
> using a TLS Client Hello.

According to Marko's log files it is actually the other way round: FF sends TLS and Chrome sends DTLS.
(Assignee)

Comment 40

3 years ago
Can we verify that the behavior with Chrome is the same from the same machine that you're running Firefox on? It seems that you're running different versions of Wireshark, hence the DTLS/TLS Client Hello confusion, and the IP address differences.
So in summary: we don't see any relevant differences in the DTLS/SSL Client Hello's. I think at this point only a log file from Asterisk telling us what it does not like about our Hello can shed light here. Marko can you please try to get that?

BTW the test page you provided in comment #8 is not working any more for me in any version of FF. If I click "Dial" I see some dialing message on the browser console, but nothing after that any more (no ICE connection, no audio,...). Did you changed anything on your end which would explains this?

Another alternative besides getting Asterisk log file might be to look a working DTLS Client Hello from Beta or Release (but because the page is not working any more I could not get that myself).
Flags: needinfo?(marko.seidenglanz)
(Reporter)

Comment 42

3 years ago
Created attachment 8500935 [details]
FF 33.0b8 DTLS CLIENT HELLO

You are right Byron. FF 33 uses the same DTLS CLIENT HELLO as Chrome, while FF 34 uses TLS CLIENT HELLO.
(Reporter)

Comment 43

3 years ago
Created attachment 8500939 [details]
ast 12.5 DTLS SERVER HELLO

Here is the SERVER HELLO send back from Asterisk after receiving the CLIENT HELLO from FF 33.
(Reporter)

Comment 44

3 years ago
I think that the problem may be related to this issue https://bugzilla.mozilla.org/show_bug.cgi?id=1052610

The test application is now working again. I had to move the Asterisk instance to another server. You saw differing IPs, because one capture was taken locally and the other capture was on the remote (Asterisk) side, but it doesn't matter, because the packets stay the same.
Flags: needinfo?(marko.seidenglanz)
(Reporter)

Comment 45

3 years ago
Created attachment 8501006 [details]
dtls handshake chrome 38

DTLS HANDSHAKE Chrome 38
(Reporter)

Comment 46

3 years ago
Created attachment 8501007 [details]
dtls handshake ff 33 beta 8

DTLS HANDSHAKE FF 33 beta 8
(Reporter)

Comment 47

3 years ago
Sorry for the ip confusion. I created two new captures using chrome 38 and ff 33, both on the client side. 

Unfortunately asterisk does not give any log entry about what he does not like in the FF 34 CLIENT HELLO message.
(Assignee)

Comment 48

3 years ago
So I took a capture of the client hello for both versions (33 and 35), and they were bitwise identical aside from the random fields.
(Reporter)

Comment 49

3 years ago
And did you get a connection in 35?
(Reporter)

Comment 50

3 years ago
I did a capture of your connection attempts with FF 35 and 33, but the file size is too big for an attachment here. I will look for another way.
(Reporter)

Comment 51

3 years ago
Ok. Here you can download the caps:
https://drive.google.com/folderview?id=0BxwAyaFvy_7fS0lJWUd3N09MVFE&usp=sharing
(Assignee)

Comment 52

3 years ago
No server hello for 35, 33 connected fine. Investigating another possibility now.
(Assignee)

Comment 53

3 years ago
In your traces I see some odd-looking RTP (lots of 5's and d's) being transmitted by asterisk before the Client Hello from 33, but not 35. This suggests something has gone wrong prior to the transmission of the Client Hello in 35. You might want to double-check your ICE logging.
(Reporter)

Comment 54

3 years ago
Thank you for the advise. I will investigate this.
(Reporter)

Comment 55

3 years ago
I had a look at the traces. But I cannot see the difference you described between 33 and 35. Both traces have RTP packets beeing sent before Client Hello arrives. What do you mean with odd-looking, especially with 5's and d's?
(Assignee)

Comment 56

3 years ago
The payload of the RTP (as hex) consists of only '5' and 'd'. It may have just been a fluke that my traces for 35 did not contain this RTP. At this point, there's not much I can do; you're going to have to debug the handshake code on your end to figure out why asterisk is sad. In the meantime, we can go ahead and get the candidate incorporation fixed on 34, since there's very little you can do to work around that (without shoehorning the candidates into the SDP in JS, which is kinda gross).
(In reply to marko.seidenglanz from comment #42)
> You are right Byron. FF 33 uses the same DTLS CLIENT HELLO as Chrome, while
> FF 34 uses TLS CLIENT HELLO.

Just to be clear: our conclusion on secondary inspection of this was that the hex values of the two HELLO's are identical. Probably you used different versions of Wireshark to capture/print the HELLO's which interpret the same value a little differently. So this is not actual a difference which could explain why Asterisk does not like the >= 34 CLIENT HELLO.
(Assignee)

Comment 58

3 years ago
(In reply to Nils Ohlmeier [:drno] from comment #57)
> (In reply to marko.seidenglanz from comment #42)
> > You are right Byron. FF 33 uses the same DTLS CLIENT HELLO as Chrome, while
> > FF 34 uses TLS CLIENT HELLO.
> 
> Just to be clear: our conclusion on secondary inspection of this was that
> the hex values of the two HELLO's are identical. Probably you used different
> versions of Wireshark to capture/print the HELLO's which interpret the same
> value a little differently. So this is not actual a difference which could
> explain why Asterisk does not like the >= 34 CLIENT HELLO.

    Actually, what's spooky about this is that the packets are bitwise identical except the random field, but the same binary of wireshark classified them differently (consistently SSL record for 35, DTLS record for 33) for me. It is a real puzzler.
(Reporter)

Comment 59

3 years ago
(In reply to Nils Ohlmeier [:drno] from comment #57)
> (In reply to marko.seidenglanz from comment #42)
> > You are right Byron. FF 33 uses the same DTLS CLIENT HELLO as Chrome, while
> > FF 34 uses TLS CLIENT HELLO.
> 
> Just to be clear: our conclusion on secondary inspection of this was that
> the hex values of the two HELLO's are identical. Probably you used different
> versions of Wireshark to capture/print the HELLO's which interpret the same
> value a little differently. So this is not actual a difference which could
> explain why Asterisk does not like the >= 34 CLIENT HELLO.

Did you have a look at the traces I made from Byron's connection attempts https://drive.google.com/folderview?id=0BxwAyaFvy_7fS0lJWUd3N09MVFE&usp=sharing

I recorded them on the same machine using the same tshark version and when I open them in the same wireshark, the headers differ, so there must be a difference between them. But of course, that may not be the cause of the problem.
(In reply to marko.seidenglanz from comment #59)
> (In reply to Nils Ohlmeier [:drno] from comment #57)
> Did you have a look at the traces I made from Byron's connection attempts
> https://drive.google.com/
> folderview?id=0BxwAyaFvy_7fS0lJWUd3N09MVFE&usp=sharing

Sorry did not have the time so far to look at them.
 
> I recorded them on the same machine using the same tshark version and when I
> open them in the same wireshark, the headers differ, so there must be a
> difference between them. But of course, that may not be the cause of the
> problem.

As I have contributed code to Wireshark, that argument is not very convincing to me. The phase of the moon or other factors can easily influence wireshark's conclusions about packets ;-)
(Reporter)

Comment 61

3 years ago
(In reply to Nils Ohlmeier [:drno] from comment #60)
> (In reply to marko.seidenglanz from comment #59)
> > (In reply to Nils Ohlmeier [:drno] from comment #57)
> > Did you have a look at the traces I made from Byron's connection attempts
> > https://drive.google.com/
> > folderview?id=0BxwAyaFvy_7fS0lJWUd3N09MVFE&usp=sharing
> 
> Sorry did not have the time so far to look at them.
>  
> > I recorded them on the same machine using the same tshark version and when I
> > open them in the same wireshark, the headers differ, so there must be a
> > difference between them. But of course, that may not be the cause of the
> > problem.
> 
> As I have contributed code to Wireshark, that argument is not very
> convincing to me. The phase of the moon or other factors can easily
> influence wireshark's conclusions about packets ;-)

Ok, I will have a look at the traces next month again. :-)
(In reply to Byron Campen [:bwc] from comment #56)
> The payload of the RTP (as hex) consists of only '5' and 'd'.

I'm not 100% sure, but consistent payloads like this in RTP usually mean that they transport silence. Which makes sense as the call is not really connected yet, or the media hasn't started to play yet.
The interesting part is that this consistent data in them means they are not encrypted/SRTP (yet). Which to some degree makes sense if the DTLS connection is not setup yet, but probably violates some spec to send non-encrypted RTP until the DTLS connection is up.
(Reporter)

Comment 63

3 years ago
Created attachment 8502536 [details]
DTLS Trace Asterisk <--> FF 35 (Client Hello, Server Hello)

Ok, I got a little bit further. Asterisk did not respond to FF's Client Hello, because the "connection" attribute of the preceding SDP, sent from FF had a connection address of 0.0.0.0. (see http://tools.ietf.org/html/rfc4566#section-5.7). I now set it manually in my client implementation.

Now Asterisk responds with Server Hello, which unfortunately FF does not respond to. Please have a look at the trace, and tell me what might be go wrong here.
(Reporter)

Comment 64

3 years ago
Also Wireshark is now surprisingly classifying the Client Hello as a DTLSv1.0 Record Layer packet. Maybe because he now sees the subsequent Server Hello.
(Reporter)

Comment 65

3 years ago
Ok I can see, that Asterisks first Server Hello Message has a sequence number of 5 and in all subsequent messages it increases by 5. This is neither the case with chrome nor with FF 33, where it sends Server Hello's starting at 0. Curious!
(Reporter)

Comment 66

3 years ago
Ahhh ok... It starts with sequence number 0, after the first CLIENT HELLO and proceeds with 5 after receiving the second CLIENT HELLO.
(Assignee)

Comment 67

3 years ago
(In reply to marko.seidenglanz from comment #63)
> Created attachment 8502536 [details]
> DTLS Trace Asterisk <--> FF 35 (Client Hello, Server Hello)
> 
> Ok, I got a little bit further. Asterisk did not respond to FF's Client
> Hello, because the "connection" attribute of the preceding SDP, sent from FF
> had a connection address of 0.0.0.0. (see
> http://tools.ietf.org/html/rfc4566#section-5.7). I now set it manually in my
> client implementation.
> 
> Now Asterisk responds with Server Hello, which unfortunately FF does not
> respond to. Please have a look at the trace, and tell me what might be go
> wrong here.

That's strange, because it is perfectly happy with Chrome doing the same thing. But, if you can work around it, that looks like a way forward. FWIW, we're going to be populating the c-line when the first candidate is incorporated once we land our rewrite of the JSEP handling code, sometime in 36.
(Assignee)

Comment 68

3 years ago
Comment on attachment 8498456 [details] [diff] [review]
Part 1: (aurora only) Stopgap patch that fixes bug 1055787 in Aurora.

Approval Request Comment
[Feature/regressing bug #]:

   Present since webrtc landing, exacerbated significantly by bug 991037.

[User impact if declined]:

   Complete inability to establish calls when interoping with something other than a browser (eg; Asterisk).

[Describe test coverage new/current, TBPL]:

   drno is working on a patch over in bug 1060102 that will add a mochitest for this.

[Risks and why]: 

   Almost none, just a simple one-liner change.

[String/UUID change made/needed]:

   None.
Attachment #8498456 - Flags: approval-mozilla-aurora?
Simple patch but can you please get this landed on m-c and verified before uplift?
Flags: needinfo?(docfaraday)
(Assignee)

Comment 70

3 years ago
This patch does not apply to m-c because the code it modifies was completely removed/rewritten.
Flags: needinfo?(docfaraday)
(Assignee)

Comment 71

3 years ago
I can do a try push if you like, I suppose.
(Assignee)

Comment 72

3 years ago
https://tbpl.mozilla.org/?tree=Try&rev=f32bcd051611
bwc told me on irc that this issue has already been fixed on m-c via another bug. 

bwc - Can you add the bug ref?
status-firefox35: affected → fixed
Comment on attachment 8498456 [details] [diff] [review]
Part 1: (aurora only) Stopgap patch that fixes bug 1055787 in Aurora.

Aurora+
Attachment #8498456 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
(Assignee)

Updated

3 years ago
See Also: → bug 1060625, bug 1055787
https://hg.mozilla.org/releases/mozilla-aurora/rev/6e9389570e3f
status-firefox34: affected → fixed
Target Milestone: --- → mozilla35
Status: ASSIGNED → RESOLVED
Last Resolved: 3 years ago
Depends on: 1060625
Resolution: --- → FIXED
(Reporter)

Comment 76

3 years ago
I can confirm that now FF 34 is working again with Asterisk, but there seems to be another problem regarding that the media stream seems not to be cleaned up correctly:

https://bugzilla.mozilla.org/show_bug.cgi?id=1081843
You need to log in before you can comment on or make changes to this bug.