896429 - createOffer randomly fails with Unable to create offer : INTERNAL_ERROR Could not create local SDP for offer; cause = ERR

Status: RESOLVED FIXED

(Core :: WebRTC: Signaling, defect)

Description

[Mark Banner (:standard8)]

Attachment: create_offer_fail.zip

We've been seeing some random errors on our Talkilla automated tests, and I've just been trying to get some more information out.

The issue we've seen that I'm filing here is during trying to create a peer connection with only a data channel. We are effectively doing:

1) Create a new peer connection
2) Create a new data channel on the pc, with id = 0, negotiated = true
3) create the offer

We occasionally get this error, instead of a success situation:

[13:31:33.868] "Unable to create offer : INTERNAL_ERROR Could not create local SDP for offer; cause = ERR"

Attached is the NSPR_LOG_MODULES=signalling:6 log for a run where this failed.

Comment 1

[Mark Banner (:standard8)]

I forgot to say we've overridden media.peerconnection.default_iceservers to be [] and media.peerconnection.use_document_iceservers to be false in preferences.

Comment 2

[Ethan Hugg [:ehugg]]

Relevant lines from the log:

486387712[1214a9e20]: [GSM Task|sdp_config] sdp_config.c:27: SDP: Invalid Config pointer: 0x0 (magic=0x0)
486387712[1214a9e20]: [GSM Task|ccsip] ccsip_sdp.c:120: SIP : sipsdp_create : SDP allocation failure
486387712[1214a9e20]: [GSM Task|fsm_sm] fsmdef.c:3229: SIPCC-FSM: Unable to build SDP. 


This implies that when sipsdp_create() is called the static ccsip_sdp_config is null.  Since there is no error message from sip_sdp_init() then either it did not get called before sipsdp_create(), or the static ccsip_sdp_config was set to NULL somewhere else.  Still investigating.

Comment 3

[Adam Roach [:abr]]

This is ringing a bell. I'm the one who added the logging message on line 27 of sdp_config, because we had this problem before. My recollection is that the last time we saw this, it was a simple thread race. Let me track this down...

Comment 4

[Adam Roach [:abr]]

Ah, no, it was Bug 872013. The telltale symptom to look for is whether the log messae "SDP: Initialized config pointer: %p (magic=0x%X)" is emitted anywhere. If it's not, then the init didn't happen in the first place (which is what I would first suspect, because I scrubbed the code to try to find anywhere it could be set to NULL).

The problem in that bug was that we were bailing out of sip_platform_task_loop, which means that the event that caused the structure to be initialized would never run.

This current situation sounds like a race between that event and the message to create the offer. Unfortunately, it sounds like we need some additional synchronization here...

Comment 5

[Ethan Hugg [:ehugg]]

That must be it because "Invalid config pointer" appears on line 4120 of this log and "Initialized config pointer" shows on line 4228.

Comment 6

[Adam Roach [:abr]]

Bingo!

Comment 7

[Ethan Hugg [:ehugg]]

Instead of looking at additional synch first, I'm going to see if I can eliminate the static ccsip_sdp_config.  Almost every static var is SIPCC either was pointless or created bugs when multiple PeerConnections were active.

Comment 8

[Ethan Hugg [:ehugg]]

Attachment: Signaling: dynamically create SDP config

Comment 9

[Ethan Hugg [:ehugg]]

Comment on attachment 779997 [details] [diff] [review]
Signaling: dynamically create SDP config


This patch shamelessly leaks a bit of memory, but if it works in your automated tests I can figure out how to free the config with the sdp_free.

Comment 10

[Mark Banner (:standard8)]

I've just been testing a build with the patch - it seems to be successful, I ran it ~65 times (runs take a while atm), and it didn't fail at all.

I swapped back to the standard nightly and it failed within about 3 runs, which is what I'd seen before.

Comment 11

[Mark Banner (:standard8)]

I also didn't see any of the error I filed in bug 896439 when the patch was applied.

Comment 12

[Ethan Hugg [:ehugg]]

Attachment: Signaling: dynamically create SDP config

Comment 13

[Ethan Hugg [:ehugg]]

Comment on attachment 780487 [details] [diff] [review]
Signaling: dynamically create SDP config


Instead of trying to sync the sdp_init call I decided to try giving each SDP structure their own copy of the config.  So we're using a tiny bit more memory with each SDP, but this allows me to remove two globals.

The usefulness of the config is in doubt, but I decided not to try that cleanup as part of this patch.

Also removed sdp_copy instead of fixing it because I found it was not used anywhere.

Comment 15

[Adam Roach [:abr]]

Comment on attachment 780487 [details] [diff] [review]
Signaling: dynamically create SDP config

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

Looks good to me. Some nits inline.

::: media/webrtc/signaling/src/sipcc/core/sdp/sdp_config.c
@@ +45,5 @@
>  {
>      int i;
>      sdp_conf_options_t *conf_p;
>  
> +    conf_p = SDP_MALLOC(sizeof(sdp_conf_options_t));

if (!conf_p) {
  CSFLogError(logTag, "SDP: could not allocate configuration object.");
  return NULL;
}

@@ +109,5 @@
> + */
> +void sdp_free_config(void *config_p)
> +{
> +    SDP_FREE(config_p);
> +}

Why the special function? Can't we just call SDP_FREE directly?

::: media/webrtc/signaling/src/sipcc/core/sipstack/ccsip_sdp.c
@@ +65,5 @@
>   * transports and codecs.
>   *
>   * The function must be called once.
>   *
> + * Returns NULL on error

"Returns a pointer to the SDP configuration profile, or NULL on failure."

Comment 16

[Ethan Hugg [:ehugg]]

>Why the special function? Can't we just call SDP_FREE directly?

I did this so that the MALLOC and FREE would show up next to each other in the same file.  I can eliminate this function and call SDP_FREE directly (also done before I realized how simple it would be).

Comment 17

[Ethan Hugg [:ehugg]]

Comment on attachment 780487 [details] [diff] [review]
Signaling: dynamically create SDP config

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

::: media/webrtc/signaling/src/sipcc/core/sdp/sdp_config.c
@@ +45,5 @@
>  {
>      int i;
>      sdp_conf_options_t *conf_p;
>  
> +    conf_p = SDP_MALLOC(sizeof(sdp_conf_options_t));

Our malloc is infallible, but I'll add this just in case that changes.

Comment 18

[Ethan Hugg [:ehugg]]

Attachment: Signaling: dynamically create SDP config

Comment 19

[Ethan Hugg [:ehugg]]

Comment on attachment 780569 [details] [diff] [review]
Signaling: dynamically create SDP config


Nits addressed.  Bringing forward r+ from abr.

Comment 20

[Ethan Hugg [:ehugg]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/38e2b972e33f

Comment 21

[Ed Morley [:emorley]]

https://hg.mozilla.org/mozilla-central/rev/38e2b972e33f