WebRTC signaling - Google App Engine - 500 internal server error on POST - how to troubleshoot?

525 views
Skip to first unread message

Kenneth Thorman

unread,
Feb 26, 2014, 2:40:52 AM2/26/14
to discuss...@googlegroups.com
This is related to a problem that I have encountered while working on Mono (C#) port of the Java Appspotdemo (and the WebRTCDemo) on GitHub.


I have been able to make some progress and feel that I am pretty close to getting this working but I am currently facing a blocking issue.

I am experiencing a signaling issue with the Google App Engine backend that is throwing a 500 internal server error when I run the mono version but this works in the Java version.

Now I was going to replace the Google App Engine backend with a node.js driven one anyhow, but I wanted to offer a plugable backend so you could switch between what signaling implementation you wanted to use.
So before I completely discard the Google App Engine backend I wanted to ask if anyone here had a clue what is going wrong.


I have attached the adb logcat output files that have been filtered to only show relevant entries.

if you load the files side by side in WinMerge you will get something like the attached screenshot "logcat_compare.png"

Basically the 2 different POSTs to the Google App Engine backend is

Java:
?: D/console(): {"type":"offer","sdp":"v=0\r\no=- 865 2 IN IP4 127.0.0.1\r\ns=-\r\nt=0 0\r\na=group:BUNDLE audio video\r\na=msid-semantic: WMS ARDAMS\r\nm=audio 1 RTP\/SAVPF 103 111 9 102 0 8 106 105 13 127 126\r \nc=IN IP4 0.0.0.0\r\na=rtcp:1 IN IP4 0.0.0.0\r\na=ice-ufrag:qHuoCF4XUbCqb8Zo\r\na=ice-pwd:hqT1TD08Wa79JT6gJrIOa0nl\r\na=ice-options:google-ice\r\na=mid:audio\r\na=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level\r\na=sendrecv\r\na=rtcp-mux\r\na=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:iXFhO+vsWM0LUDG8osWjiGrC5rebrED7FjJK\/pcG\r\na=rtpmap:111 opus\/\/2\r\na=fmtp:111 minptime=10\r\na=rtpmap:103 ISAC\/\r\na=rtpmap:9 G722\/\r\na=rtpmap:102 ILBC\/\r\na=rtpmap:0 PCMU\/\r\na=rtpmap:8 PCMA\/\r\na=rtpmap:106 CN\/\r\na=rtpmap:105 CN\/\r\na=rtpmap:13 CN\/\r\na=rtpmap:127 red\/\r\na=rtpmap:126 telephone-event\/\r\na=maxptime:60\r\na=ssrc: cname:hXANRinEVEPPMc9m\r\na=ssrc: msid:ARDAMS ARDAMSa0\r\na=ssrc: mslabel:ARDAMS\r\na=ssrc: label:ARDAMSa0\r\nm=video 1 RTP\/SAVPF 100 116 117\r\nc=IN IP4 0.0.0.0\r\na=rtcp:1 IN IP4 0.0.0.0\r\na=ice-ufrag:qHuoCF4XUbCqb8Zo\r\na=ice-pwd:hqT1TD08Wa79JT6gJrIOa0nl\r\na=ice-options:google-ice\r\na=mid:video\r\na=extmap:2 urn:ietf:params:rtp-hdrext:toffset\r\na=extmap:3 http:\/\/www.webrtc.org\/experiments\/rtp-hdrext\/abs-send-time\r\na=sendrecv\r\na=rtcp-mux\r\na=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:iXFhO+vsWM0LUDG8osWjiGrC5rebrED7FjJK\/pcG\r\na=rtpmap:100 VP8\/\r\na=rtcp-fb:100 ccm fir\r\na=rtcp-fb:100 nack\r\na=rtcp-fb:100 goog-remb\r\na=rtpmap:116 red\/\r\na=rtpmap:117 ulpfec\/\r\na=ssrc: cname:hXANRinEVEPPMc9m\r\na=ssrc: msid:ARDAMS ARDAMSv0\r\na=ssrc: mslabel:ARDAMS\r\na=ssrc: label:ARDAMSv0\r\n"}

Mono:
?: D/console(): {"type":"offer","sdp":"v=0\r\no=-  2 IN IP4 127.0.0.1\r\ns=-\r\nt=0 0\r\na=group:BUNDLE audio video\r\na=msid-semantic: WMS ARDAMS\r\nm=audio 1 RTP\/SAVPF 103 111 9 102 0 8 106 105 13 127 126\r \nc=IN IP4 0.0.0.0\r\na=rtcp:1 IN IP4 0.0.0.0\r\na=ice-ufrag:PQDfbt7jFAxaEzS\/\r\na=ice-pwd:ypEZE0Mae2DiO1+nkBpBgo8i\r\na=ice-options:google-ice\r\na=mid:audio\r\na=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level\r\na=sendrecv\r\na=rtcp-mux\r\na=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:hWIRXLRWTS5+gVysSEguxNf9c3LTEOpfEoiwZD8W\r\na=rtpmap:111 opus\/\/2\r\na=fmtp:111 minptime=10\r\na=rtpmap:103 ISAC\/\r\na=rtpmap:9 G722\/\r\na=rtpmap:102 ILBC\/\r\na=rtpmap:0 PCMU\/\r\na=rtpmap:8 PCMA\/\r\na=rtpmap:106 CN\/\r\na=rtpmap:105 CN\/\r\na=rtpmap:13 CN\/\r\na=rtpmap:127 red\/\r\na=rtpmap:126 telephone-event\/\r\na=maxptime:60\r\na=ssrc: cname:JRRgYWnxI9eCvZY1\r\na=ssrc: msid:ARDAMS ARDAMSa0\r\na=ssrc: mslabel:ARDAMS\r\na=ssrc: label:ARDAMSa0\r\nm=video 1 RTP\/SAVPF 100 116 117\r\nc=IN IP4 0.0.0.0\r\na=rtcp:1 IN IP4 0.0.0.0\r\na=ice-ufrag:PQDfbt7jFAxaEzS\/\r\na=ice-pwd:ypEZE0Mae2DiO1+nkBpBgo8i\r\na=ice-options:google-ice\r\na=mid:video\r\na=extmap:2 urn:ietf:params:rtp-hdrext:toffset\r\na=extmap:3 http:\/\/www.webrtc.org\/experiments\/rtp-hdrext\/abs-send-time\r\na=sendrecv\r\na=rtcp-mux\r\na=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:hWIRXLRWTS5+gVysSEguxNf9c3LTEOpfEoiwZD8W\r\na=rtpmap:100 VP8\/\r\na=rtcp-fb:100 ccm fir\r\na=rtcp-fb:100 nack\r\na=rtcp-fb:100 goog-remb\r\na=rtpmap:116 red\/\r\na=rtpmap:117 ulpfec\/\r\na=ssrc: cname:JRRgYWnxI9eCvZY1\r\na=ssrc: msid:ARDAMS ARDAMSv0\r\na=ssrc: mslabel:ARDAMS\r\na=ssrc: label:ARDAMSv0\r\n"}

If you compare these 2 lines char by char they are almost identical and I have not been able to identify what might be the culprit or why this is different.
The Java POST to the backend works, the Mono POST does not and results in 

?: I/MonoDroid(): UNHANDLED EXCEPTION: System.Exception: Error ---> Java.IO.IOException: Exception of type 'Java.IO.IOException' was thrown.
?: I/MonoDroid(): at Appspotdemo.Mono.Droid.AppRTCClient.maybeDrainQueue () [0x] in <filename unknown>:0
?: I/MonoDroid(): --- End of managed exception stack trace ---
?: I/MonoDroid(): java.io.IOException: Non-200 response to POST: HTTP/1.1 500 Internal Server Error for msg: {"type":"offer","sdp":"v=0\r\no=-  2 IN IP4 127.0.0.1\r\ns=-\r\nt=0 0\r\na=group:BUNDLE audio video\r\na=msid-semantic: WMS ARDAMS\r\nm=audio 1 RTP\/SAVPF 103 111 9 102 0 8 106 105 13 127 126\r \nc=IN IP4 0.0.0.0\r\na=rtcp:1 IN IP4 0.0.0.0\r\na=ice-ufrag:PQDfbt7jFAxaEzS\/\r\na=ice-pwd:ypEZE0Mae2DiO1+nkBpBgo8i\r\na=ice-options:google-ice\r\na=mid:audio\r\na=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level\r\na=sendrecv\r\na=rtcp-mux\r\na=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:hWIRXLRWTS5+gVysSEguxNf9c3LTEOpfEoiwZD8W\r\na=rtpmap:111 opus\/\/2\r\na=fmtp:111 minptime=10\r\na=rtpmap:103 ISAC\/\r\na=rtpmap:9 G722\/\r\na=rtpmap:102 ILBC\/\r\na=rtpmap:0 PCMU\/\r\na=rtpmap:8 PCMA\/\r\na=rtpmap:106 CN\/\r\na=rtpmap:105 CN\/\r\na=rtpmap:13 CN\/\r\na=rtpmap:127 red\/\r\na=rtpmap:126 telephone-event\/\r\na=maxptime:60\r\na=ssrc: cname:JRRgYWnxI9eCvZY1\r\na=ssrc: msid:ARDAMS ARDAMSa0\r\na=ssrc: mslabel:ARDAMS\r\na=ssrc: label:ARDAMSa0\r\nm=video 1 RTP\/SAVPF 100 116 117\r\nc=IN IP4 0.0.0.0\r\na=rtcp:1 IN IP4 0.0.0.0\r\na=ice-ufrag:PQDfbt7jFAxaEzS\/\r\na=ice-pwd:ypEZE0Mae2DiO1+nkBpBgo8i\r\na=ice-options:google-ice\r\na=mid:video\r\na=extmap:2 urn:ietf:params:rtp-hdrext:toffset\r\na=extmap:3 http:\/\/www.webrtc.org\/experiments\/rtp-hdrext\/abs-send-time\r\na=sendrecv\r\na=rtcp-mux\r\na=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:hWIRXLRWTS5+gVysSEguxNf9c3LTEOpfEoiwZD8W\r\na=rtpmap:100 VP8\/\r\na=rtcp-fb:100 ccm fir\r\na=rtcp-fb:100 nack\r\na=rtcp-fb:100 goog-remb\r\na=rtpmap:116 red\/\r\na=rtpmap:117 ulpfec\/\r\na=ssrc: cname:JRRgYWnxI9eCvZY1\r\na=ssrc: msid:ARDAMS ARDAMSv0\r\na=ssrc: mslabel:ARDAMS\r\na=ssrc: label:ARDAMSv0\r\n"}
?: I/MonoDroid(): at appspotdemo.mono.droid.AppRTCClient_AsyncTaskAnonymousInnerClassHelper.n_doInBackground(Native Method)
?: I/MonoDroid(): at appspotdemo.mono.droid.AppRTCClient_AsyncTaskAnonymousInnerClassHelper.doInBackground(AppRTCClient_AsyncTaskAnonymousInnerClassHelper.java:28)
?: I/MonoDroid(): at android.os.AsyncTask$2.call(AsyncTask.java:264)
?: I/MonoDroid(): at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:305)
?: I/MonoDroid(): at java.util.concurrent.FutureTask.run(FutureTask.java:137)
?: I/MonoDroid(): at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:208)
?: I/MonoDroid(): at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:)
?: I/MonoDroid(): at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:569)
?: I/MonoDroid(): at java.lang.Thread.run(Thread.java:856)
: W/UNKNOWN_FORMAT(): I/MonoDroid():
?: I/MonoDroid(): --- End of inner exception stack trace ---
?: I/MonoDroid(): at Appspotdemo.Mono.Droid.AppRTCClient.maybeDrainQueue () <0x002b4>
?: I/MonoDroid(): at Appspotdemo.Mono.Droid.AppRTCClient/AsyncTaskAnonymousInnerClassHelper.RunInBackground (string[]) <0x>
?: I/MonoDroid(): at Android.OS.AsyncTask`3<string, int, string>.DoInBackground (Java.Lang.Object[]) <0x>
?: I/MonoDroid(): at Android.OS.AsyncTask.n_DoInBackground_arrayLjava_lang_Object_ (intptr,intptr,intptr) <0x000a3>
?: I/MonoDroid(): at (wrapper dynamic-method) object.986ae4d8-afd7-46ac-a5b0-b7fc82e (intptr,intptr,intptr) <0x>
?: W/libjingle(): Warning(webrtcvideoengine.cc:): webrtc: Too long processing time of Incoming frame: 20ms
: W/UNKNOWN_FORMAT(): E/mono    ():
?: E/mono(): Unhandled Exception:
?: E/mono(): System.Exception: Error ---> Java.IO.IOException: Exception of type 'Java.IO.IOException' was thrown.
?: E/mono(): at Appspotdemo.Mono.Droid.AppRTCClient.maybeDrainQueue () [0x] in <filename unknown>:0
?: E/mono(): --- End of managed exception stack trace ---
?: E/mono(): java.io.IOException: Non-200 response to POST: HTTP/1.1 500 Internal Server Error for msg: {"type":"offer","sdp":"v=0\r\no=-  2 IN IP4 127.0.0.1\r\ns=-\r\nt=0 0\r\na=group:BUNDLE audio video\r\na=msid-semantic: WMS ARDAMS\r\nm=audio 1 RTP\/SAVPF 103 111 9 102 0 8 106 105 13 127 126\r \nc=IN IP4 0.0.0.0\r\na=rtcp:1 IN IP4 0.0.0.0\r\na=ice-ufrag:PQDfbt7jFAxaEzS\/\r\na=ice-pwd:ypEZE0Mae2DiO1+nkBpBgo8i\r\na=ice-options:google-ice\r\na=mid:audio\r\na=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level\r\na=sendrecv\r\na=rtcp-mux\r\na=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:hWIRXLRWTS5+gVysSEguxNf9c3LTEOpfEoiwZD8W\r\na=rtpmap:111 opus\/\/2\r\na=fmtp:111 minptime=10\r\na=rtpmap:103 ISAC\/\r\na=rtpmap:9 G722\/\r\na=rtpma
?: E/mono-rt(): [ERROR] FATAL UNHANDLED EXCEPTION: System.Exception: Error ---> Java.IO.IOException: Exception of type 'Java.IO.IOException' was thrown.
?: E/mono-rt(): at Appspotdemo.Mono.Droid.AppRTCClient.maybeDrainQueue () [0x] in <filename unknown>:0
?: E/mono-rt(): --- End of managed exception stack trace ---
?: E/mono-rt(): java.io.IOException: Non-200 response to POST: HTTP/1.1 500 Internal Server Error for msg: {"type":"offer","sdp":"v=0\r\no=-  2 IN IP4 127.0.0.1\r\ns=-\r\nt=0 0\r\na=group:BUNDLE audio video\r\na=msid-semantic: WMS ARDAMS\r\nm=audio 1 RTP\/SAVPF 103 111 9 102 0 8 106 105 13 127 126\r \nc=IN IP4 0.0.0.0\r\na=rtcp:1 IN IP4 0.0.0.0\r\na=ice-ufrag:PQDfbt7jFAxaEzS\/\r\na=ice-pwd:ypEZE0Mae2DiO1+nkBpBgo8i\r\na=ice-options:google-ice\r\na=mid:audio\r\na=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level\r\na=sendrecv\r\na=rtcp-mux\r\na=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:hWIRXLRWTS5+gVysSEguxNf9c3LTEOpfEoiwZD8W\r\na=rtpmap:111 opus\/\/2\r\na=fmtp:111 minptime=10\r\na=rtpmap:103 ISAC\/\r\na=rtpmap:9 G722\/160
?: A/GAbi++(): Pure virtual function called!
: W/UNKNOWN_FORMAT(): E/mono-rt ():
?: E/mono-rt(): =================================================================
?: E/mono-rt(): Got a SIGSEGV while executing native code. This usually indicates
?: E/mono-rt(): a fatal error in the mono runtime or one of the native libraries
?: E/mono-rt(): used by your application.
?: E/mono-rt(): =================================================================
: W/UNKNOWN_FORMAT(): E/mono-rt ():
: W/UNKNOWN_FORMAT(): E/mono    ():
?: E/mono(): Unhandled Exception:
?: E/mono(): System.NullReferenceException: Object reference not set to an instance of an object
?: E/mono-rt(): [ERROR] FATAL UNHANDLED EXCEPTION: System.NullReferenceException: Object reference not set to an instance of an object


Any help on why the Google App Engine backend is throwing this 500 internal server error would be greatly appreciated.

Thank you in advance.

Regards
Kenneth Thorman

logcat_compare.png
mono_logcat_filtered2.zip
java_logcat_filtered2.zip

Kenneth Thorman

unread,
Feb 26, 2014, 6:27:00 AM2/26/14
to discuss...@googlegroups.com
I just found this https://groups.google.com/d/msg/discuss-webrtc/7ZjqemtH9xE/mQiV1KlzYlcJ

It seems like an extra space can cause this 500 internal server error, and if we do look closely at the mono vs java sdp message it seems like there is missing a parameter in the beginning

Java:
?: D/console(): {"type":"offer","sdp":"v=0\r\no=- 865 2 IN ...

Mono:
?: D/console(): {"type":"offer","sdp":"v=0\r\no=-  2 IN ...

865 is missing - maybe this can be the cause of the error?

Regards
Kenneth

Kenneth Thorman

unread,
Mar 7, 2014, 10:34:49 AM3/7/14
to discuss...@googlegroups.com
Small update on lack of progress.

I have been struggling with this for some time now, and not been able to make much headway, I did find that it seems like signaling parameters is supposed to be "urls" instead of "url".
But this still did not solve the problem, so now I am considering replacing the signaling backend with a node.js based one which we already have working for web.  

Regards
Kenneth

Alexandre GOUAILLARD

unread,
Mar 7, 2014, 11:39:37 AM3/7/14
to discuss...@googlegroups.com
hi kenneth,

They recently changed the iceservers string (for the peer connection constructor) formatting, you might be hitting that. It broke android and iOS appRTC client recently.

On a side note: from our experience, moving away from GAE has solved many of our problems (that we listed here: https://groups.google.com/forum/#!topic/discuss-webrtc/dP7tcAnM-ZM )

It seems that google is aware of this:
brave yao:  ""I really don't think GAE is good enough for RTC production purpose(You already saw how many patches are needed).""

The channel API not being available for java, C++ or obj-c, the way the appRTCDemo works is also ….. interesting:
There is a simple html page (channel.html) that is open in a web view and used as a proxy, as the javascript callbacks are binded to native code (ouch!).

In our move back in 2013 to web socket and node.js back end, the connectivity improved by 20+%, and the handshake+connection went from easily 10s (sometimes up to 15s as we had to re-send the lost messages), to below 1s.

HTH,

alex.



--

---
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/d/optout.



--
Alex. Gouaillard, PhD, PhD, MBA
------------------------------------------------------------------------------------
CTO - Temasys Communications, S'pore / Mountain View
President - CoSMo Software, Cambridge, MA
------------------------------------------------------------------------------------

Kenneth Thorman

unread,
Mar 7, 2014, 12:01:05 PM3/7/14
to discuss...@googlegroups.com
Hi Alexandre

Thank you very much, what a relief. I have been running around in circles trying to figure out the GAE, and just did not have much luck at all.
Will move forward changing the signaling backend to node.js then and hopefully that is going to bring me closer to a running project on Android on top of Xamarin.

Thank you 

Regards
Kenneth

Alexandre GOUAILLARD

unread,
Mar 7, 2014, 12:19:34 PM3/7/14
to discuss...@googlegroups.com
beware of load balancing and database hosting/distribution/sharding … that was the two most difficult things we had to tackle during our migration. For all the problem GAE had (mainly related to the CHannel API), it was taking care of the two aforementioned problem very well. Also, finding node.js components to replace the GAE dashboard is not direct.

Kenneth Thorman

unread,
Mar 7, 2014, 12:39:56 PM3/7/14
to discuss...@googlegroups.com
Hi Alexandre

Due to the usage pattern that we are developing this for, I do not think this will be a big problem.
We want to use this to offer a video solution to elderly and weak people at home, so they can speak with the nurse or doctor remotely for certain things, rather than having to leave home and then physically going to the doctor.
Due to laws in the Nordic countries, and to some extent in European countries, this health related data is considered confidential and has to physically stay within the countries boundaries. This means that we need to make sure that any middle man (TURN server), or similar is located in the respective country. So our solution is not a cloudbased worldwide service with usage metering but more a regional based offering for all patient that belong to a specific medical region. They can use it as much as they want. They will get their own meeting server and turn server  ...

Databases will be clustered and passive active, we are currently using Nginx to reverse proxy node.js/web and I am currently investigating Memcached and Redis for node.js shared state and persistence. But I am not sure this is needed since the state is also kept at the node.js client which if node breaks down, it will resync when node.js is back online. This is a problem is both the client and node breaks down at the same time. Alas :) I am not that far in my clustering and HA thoughts. 

For this reason I think that we will avoid some of the problems that you are mentioning. At least we have the full web based offering running, with rooster list, call setup ... so I think I should be able to move the JS based signaling code more or less one to one to the C# equivalent code. Especially since js socket.io based code almost is identical to the equivalent C# WebSocket4Net code, this will allow me to avoid that pesky webview/native communication.

Sorry I guess I brought the tread slightly off topic


--

---
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/ul7Vn8brQSM/unsubscribe.
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/d/optout.



--
-- 
Regards / Med venlig hilsen / Med vänliga hälsningar

Kenneth Thorman
Appinux A/S
Flæsketorvet 68, 1.
1711 København V
Telefon: +45 45650594
Mobil +45 20222074
website: www.appinux.com
support: support.appinux.com

Alexandre GOUAILLARD

unread,
Mar 7, 2014, 1:01:30 PM3/7/14
to discuss...@googlegroups.com
Na,

it's interesting to see real world use case, in the making.

We have a similar solution, taking advantage to the fact that in Singapore, only the first appointment with a Dr needs to be face to face (for diagnostic) but any follow up can be remote. Not that they are very far away given the size of the island, but it's still more comfortable form home.

Your solution makes a lot of sense in your case.

Redis make sense for very structured data (like the login and session info). For the rest, not so much.

Well, looks you're all sorted up. Good luck.

When you're done, if you had a little bit of time to give feedback on the list about your experience, I think that would due appreciated by all. Also, bistri's webrtcstats.com is in need of love :D That would be great to have more sources for webrtc usage stats. We can only achieve this if we all share.

cheers.

alex.

Kenneth Thorman

unread,
Mar 7, 2014, 1:19:13 PM3/7/14
to discuss...@googlegroups.com
Hi Alex

All the code and the postings with the information to go with the code is available online. I will keep posting on the blog and update the code on github to share it with others.

(with references to other postings)



Githubs

(it is not much but if someone else find it interesting then who knows where we might take this)

I am unsure of how to use http://webrtcstats.com/?

Regards
Kenneth

Kenneth Thorman

unread,
Mar 7, 2014, 1:30:00 PM3/7/14
to discuss...@googlegroups.com
I have posted some information about the projects that we are doing on http://webrtcstats.com/. Hopefully someone will find it useful.

Regards
Kenneth
Reply all
Reply to author
Forward
0 new messages