janus stuck in bad state???

1,409 views
Skip to first unread message

brian....@bdkconsulting.com

unread,
Sep 22, 2018, 2:45:19 PM9/22/18
to meetecho-janus
i am using the streaming plugin with an rtsp stream with janus running on an AWS server.

My problem is that not infrequently (but in no repeatable way I have yet found) I can load my web page with starts a janus session and I get through the preparing, starting, started messages and I only get 0kb/s and no stream data.  As far as I can tell this will continue indefinitely.  If I reload the page, I get back to this stuck state.

Without changing anything else, if I kill janus and restart it, and reload my page, I can typically see the stream.

I have a log where I am in the 0kb/s state (debug-level=5) and also one that works.
The log of what I think this captures the relevant section where things should be streaming data, but are not is at the end.

So I have a couple of questions:
1) Has anyone seen something like this before
2) Any suggestions for additional information to collect to try to figure out why this is happening
3) Is there anything that I can observe in the janus api that may identify this situation on the server so that I can restart janus?  (I know, ugly workaround)

-brian


[Sat Sep 22 10:57:55 2018] [6653378477235409] Created inbound SRTP session for component 1 in stream 1
[Sat Sep 22 10:57:55 2018] [6653378477235409] Created outbound SRTP session for component 1 in stream 1
[Sat Sep 22 10:57:55 2018] [6653378477235409] The DTLS handshake for the component 1 in stream 1 has been completed
[Sat Sep 22 10:57:55 2018] [6653378477235409] The DTLS handshake has been completed
[Sat Sep 22 10:57:55 2018] [6653378477235409] Telling the plugin about it (JANUS Streaming plugin)
[Sat Sep 22 10:57:55 2018] [janus.plugin.streaming-0x7f4b00002fb0] WebRTC media is now available
[Sat Sep 22 10:57:55 2018] [6653378477235409] Sending event to transport...
[Sat Sep 22 10:57:55 2018]   >> Pushing event: 0 (Success)
[Sat Sep 22 10:57:55 2018] [6653378477235409] Sending event to transport...; 0x7f4b14004e70
[Sat Sep 22 10:57:55 2018] [6653378477235409] DTLS already set up, disabling retransmission timer!
[Sat Sep 22 10:57:55 2018] Got a Janus API request from janus.transport.http (0x7f4afc001a90)
[Sat Sep 22 10:57:55 2018] Got a keep-alive on session 8067749530815251
[Sat Sep 22 10:57:55 2018] Session 8067749530815251 found... returning up to 1 messages
[Sat Sep 22 10:57:56 2018] Got a Janus API request from janus.transport.http (0x7f4b04000e20)
[Sat Sep 22 10:57:56 2018] Got a keep-alive on session 8067749530815251
[Sat Sep 22 10:57:56 2018] Session 8067749530815251 found... returning up to 1 messages
[Sat Sep 22 10:58:04 2018] [2955476031314509] 32s passed, sending GET_PARAMETER
[Sat Sep 22 10:58:07 2018] [6653378477235409] Component state changed for component 1 in stream 1: 4 (ready)
[Sat Sep 22 10:58:14 2018] ^[[33m[WARN]^[[0m [6653378477235409] Not video and not audio? dropping (SSRC 466121096)...
[Sat Sep 22 10:58:19 2018] ^[[33m[WARN]^[[0m [6653378477235409] Not video and not audio? dropping (SSRC 3663009146)...
[Sat Sep 22 10:58:22 2018] ^[[33m[WARN]^[[0m [6653378477235409] Not video and not audio? dropping (SSRC 3655004683)...
[Sat Sep 22 10:58:22 2018] ^[[33m[WARN]^[[0m [6653378477235409] Not video and not audio? dropping (SSRC 3655004683)...
[Sat Sep 22 10:58:26 2018] Long poll time out for session 8067749530815251...

Lorenzo Miniero

unread,
Sep 24, 2018, 8:49:10 AM9/24/18
to meetecho-janus
"Long poll time out" suggests that either you stopped sending data to Janus, or there's a problem with transports in Janus. Possibly related to one of these:

You may want to check what has been discussed there. They refer to WebSockets, but it may be a generic transport issue in the core since you're using HTTP. When you see it stuck, try a different transport to see if it works instead.
Lorenzo

Brian Koblenz

unread,
Sep 24, 2018, 3:09:25 PM9/24/18
to Lorenzo Miniero, meetecho-janus
Thanks for the pointer.  I enabled --debug-locks and modified the script referenced in  https://github.com/meetecho/janus-gateway/issues/1263
and ran into the problem of waiting with 0kb/s.  I had lots of lock references in the log and once I got the script correctly adapted there were no locks held.

I rebooted the camera while janus was waiting and that had no effect.  I restarted janus and immediately got streaming again.  So I am pretty convinced janus is in a bad state.  Other ideas?

-brian


fwiw, here is the adapted script I used in case anyone else needs it:

if(process.argv.length <= 2) {
        console.log("Missing filename...");
        console.log("Usage: " + process.argv[0] + " " + process.argv[1] + " logfile");
        process.exit(1);
}
var filename = process.argv[2];
console.log("Parsing log file " + filename + " for LOCK/UNLOCK evaluation...");

var locks = {};
var lineReader = require('readline').createInterface({
        input: require('fs').createReadStream(filename)
});
lineReader.on('line', function(line) {
        if(line.indexOf("lock]") < 0)
                return;
        // Found a line: is it a lock or an unlock? what for?
        var unlock = line.indexOf(":unlock") > -1;
        //var mutex = line.split(":lock ")[1];
        var mutex = line.split("lock] ")[1];
        if(unlock) {
                delete locks[mutex];
        } else {
                var count = locks[mutex] ? locks[mutex].locks : 0;
                locks[mutex] = {
                        locks: count+1,
                        line: line
                }
        }
});
lineReader.on('close', function() {
        console.log("Locks still taken:");
        console.log(locks);
});


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

Lorenzo Miniero

unread,
Sep 25, 2018, 5:16:23 AM9/25/18
to meetecho-janus
Are you sure it's not an issue on the RTSP side? When you restart Janus, you do a new RTSP setup as well, so that's what may not be happening in your case (Janus<->Camera channel lost and not restored).

Lorenzo
To unsubscribe from this group and stop receiving emails from it, send an email to meetecho-janus+unsubscribe@googlegroups.com.

Brian Koblenz

unread,
Sep 25, 2018, 10:30:26 AM9/25/18
to Lorenzo Miniero, meetecho-janus
I am not too sure of anything, but I think in the bad case, janus continues to try to re-initiate the rtsp sequence when it cant get video.

Here is a full (debug-level=5) log in failed scenario up until janus is killed:



To unsubscribe from this group and stop receiving emails from it, send an email to meetecho-janu...@googlegroups.com.

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

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

Lorenzo Miniero

unread,
Sep 25, 2018, 1:09:56 PM9/25/18
to meetecho-janus
Then it means it's not Janus that is stuck, it's the RTSP connectivity that is, maybe stuck in a loop. I see many "5s passed with no media, trying to reconnect the RTSP stream" lines, which trigger a reconnection to the RTSP server. This explains why your users don't get any media: Janus isn't getting any from the RTSP server to relay, and after 5 seconds tries to reconnect and it's the same all over, as for some reason those attempts fail as well. You should check what's happening on the traffic there, maybe capturing with tcpdump/wireshark to check what's happening for the RTSP signalling, ensure media is still flowing, and if it isn't, why (maybe some NAT terminates the mappings after a while?).

Lorenzo
To unsubscribe from this group and stop receiving emails from it, send an email to meetecho-janus+unsubscribe@googlegroups.com.

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

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

Brian Koblenz

unread,
Oct 2, 2018, 10:39:12 PM10/2/18
to Lorenzo Miniero, meetecho-janus
Still trying to figure out why I am getting such long delays (sometimes) when rtsp streaming.

In one case, I observed, I get a lots of delay (and during that delay I validated that another program could stream the rtsp data from the camera to the same server where janus is running), I finally start seeing data after getting a message that video SSRC changed 0->902713241:

Can someone explain what it means for SSRC to change and is there any reason why that might then allow streaming to occur?

-brian


[Tue Oct  2 19:27:43 2018] [461303801436609] 32s passed, sending GET_PARAMETER
[Tue Oct  2 19:27:49 2018] Long poll time out for session 1058526832911635...
[Tue Oct  2 19:27:49 2018] Got a Janus API request from janus.transport.http (0x7f1f54008170)
[Tue Oct  2 19:27:49 2018] Got a keep-alive on session 1058526832911635
[Tue Oct  2 19:27:49 2018] Session 1058526832911635 found... returning up to 1 messages
[Tue Oct  2 19:28:15 2018] [461303801436609] 32s passed, sending GET_PARAMETER
[Tue Oct  2 19:28:19 2018] Long poll time out for session 1058526832911635...
[Tue Oct  2 19:28:19 2018] Got a Janus API request from janus.transport.http (0x7f1f540089f0)
[Tue Oct  2 19:28:19 2018] Got a keep-alive on session 1058526832911635
[Tue Oct  2 19:28:19 2018] Session 1058526832911635 found... returning up to 1 messages
[Tue Oct  2 19:28:48 2018] [461303801436609] 32s passed, sending GET_PARAMETER
[Tue Oct  2 19:28:50 2018] Long poll time out for session 1058526832911635...
[Tue Oct  2 19:28:50 2018] Got a Janus API request from janus.transport.http (0x7f1f540053f0)
[Tue Oct  2 19:28:50 2018] Got a keep-alive on session 1058526832911635
[Tue Oct  2 19:28:50 2018] Session 1058526832911635 found... returning up to 1 messages
[Tue Oct  2 19:29:20 2018] Long poll time out for session 1058526832911635...
[Tue Oct  2 19:29:20 2018] Got a Janus API request from janus.transport.http (0x7f1f54006fa0)
[Tue Oct  2 19:29:20 2018] Got a keep-alive on session 1058526832911635
[Tue Oct  2 19:29:20 2018] Session 1058526832911635 found... returning up to 1 messages
[Tue Oct  2 19:29:21 2018] [461303801436609] 32s passed, sending GET_PARAMETER
[Tue Oct  2 19:29:35 2018] Video SSRC changed, 0 --> 902713241


To unsubscribe from this group and stop receiving emails from it, send an email to meetecho-janu...@googlegroups.com.

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

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

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

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

Lorenzo Miniero

unread,
Oct 3, 2018, 4:49:00 AM10/3/18
to meetecho-janus
Brian, your reports are starting to get a bit confusing, and don't help us help you. First you said it wasn't working at all, or would just stop working until you restarted: now that there are delays, but you don't explain what kind of delays or where. What's the exact issue? Are we still talking about the same issue you introduced in the first place? If not, please use different posts for different problems, as otherwise we get just as lost.

SSRC changed means there was a change in source. Since the previous one was zero, either the previous RTSP server didn't send any data at all and the new one now does, or you just established a session.

Lorenzo
To unsubscribe from this group and stop receiving emails from it, send an email to meetecho-janus+unsubscribe@googlegroups.com.

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

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

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

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

Brian Koblenz

unread,
Oct 3, 2018, 11:06:27 AM10/3/18
to Lorenzo Miniero, meetecho-janus
Let me retry to set context.

I have janus running on an AWS server S.  I have my device (D) (which has a tunnel to S) on the same subnet as a camera C.  And there is a browser (B) on some other subnet,  I have live555ProxyServer running on D referencing the rtsp stream from C, so now that rtsp stream can reached from S through the tunnel to D.  There is another program (openRTSP also from live555.com) that I have installed on S which gives me manual way to access the proxied live rtsp stream on D.

My (current) observation is that I load a streaming webpage, and get the Starting, Preparing, Started messages but generally see 0Kb/s and no live streaming data is visible.  This can go on for minutes.  (I earlier thought that I needed to restart Janus and/or the camera and/or live555ProxyServer in order to get data, but I now believe that most of the time I just need to keep waiting and data will eventually appear.)

While Janus is showing me 0kb/s, I can start openRTSP on S observe that it can receive data from live555ProxyServer on D (which is running through the same tunnel with basically 0 packet loss).  So I am pretty convinced that the data paths are fine and the network performance is fine.

fwiw, C is an S1 camera from Dericam.

My understanding is that cameras play a little fast and loose with the RTSP standard and we have each of Janus, live555ProxyServer, and C on our rtsp path.
I am not even sure of the right question to ask.  Is there a way to know if Janus is receiving packets and tossing them vs not receiving anything?  Should I use a different debugging level than 5 to collect the next relevant piece of information?  Is there any insight gained from knowing that janus successfully talked (indirectly) to C and then went a couple of minutes and then changed SSRC from 0 to something.

Does that help clarify?
-brian


To unsubscribe from this group and stop receiving emails from it, send an email to meetecho-janu...@googlegroups.com.

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

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

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

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

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

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

Brian Koblenz

unread,
Oct 3, 2018, 12:06:24 PM10/3/18
to Lorenzo Miniero, meetecho-janus
I now even need to be careful that while I believe I saw that packets were received when I manually ran openRTSP, I have also seen an instance where packets were not received by openRTSP either (even though it too could communicate with the camera).

I only have 500 ports open on my AWS for UDP access.  I pass the available ports to Janus, but there is no way I have yet found to control the ports for openRTSP.  Might some retries end up going through enough ports until it happens to find one in my range?

I am going to open up ports 12000-60000 for UDP traffic and see if that helps things.

-brian

Brian Koblenz

unread,
Oct 4, 2018, 12:38:11 PM10/4/18
to Lorenzo Miniero, meetecho-janus
Lorenzo,

I think I have a full debug-level=7 trace that captures the situation (I am sure self-inflicted) where I am struggling.  The four log files represent the entire contiguous log.

The first part (https://pastebin.com/j7RDmKL7) of the log captures the startup.  I dont think there is much interesting here but it does log parameters.

The second part (https://pastebin.com/RguQb4E6) of the log captures when I load the webpage.  A Janus.init() and janus.attach.success is performed and a keepalive timer is established.   I am not really looking to have rtsp traffic at this point (which keeps timing out in the log), so maybe I should be issuing a "stop" request??  This is informational, but I dont think directly related to my core issue.

The third part (https://pastebin.com/a4RJwLAF)  of the log is when I try to watch the live stream.  I start around 08:22:00 and I get the preparing, starting, started messages and for about 6.5 minutes I see constantly 0kb/s and no image.  The log shows some video traffic, but also shows that janus does not think there is any traffic for 5s intervals.  This part of the log is where I am really trying to understand what I have done wrong or what else might be happening.

For the final part (https://pastebin.com/hZjfjxWc) of the log (at about 08:28:32) I start seeing (no new actions taken) non-zero Kb/s and a few seconds later I get an image.  (There is some time (between 08:29:02 and 08:29:15) where the image did not appear to update but then it got going again until stopped at 08:20:20.  (I am not that worried about the stall since that could certainly be network based.)

I am hoping you can look in some detail at the third log and identify what may be the culprit.  I sure hope we can zero in on this.

-brian

Lorenzo Miniero

unread,
Oct 5, 2018, 4:53:42 AM10/5/18
to meetecho-janus
Debug level 7 is way too verbose: for your issue, 5 is typically more than enough.

The "5s passed with no media, trying to reconnect the RTSP stream" thing we found out from previous posts already. It means Janus didn't receive any media for more than 5s from the RTSP server, and so assumes the RTSP session was lost and tries to re-establish it by doing a new RTSP setup. As such, you should investigate why media stops flowing between the two, and whether or not this is true for RTSP signalling traffic as well. Janus will most definitely forward media if it receives it, so the RTSP server (or the network between them) is to blame here.

The RTP range in janus.cfg only applies to the WebRTC side. It does NOT apply to the ports that are chosen for the RTSP communication and media. As such, you should ensure that the two servers (RTSP and Janus) are free to communicate with no obstacle between them.

Lorenzo


Il giorno giovedì 4 ottobre 2018 18:38:11 UTC+2, Brian Koblenz ha scritto:
Lorenzo,

I think I have a full debug-level=7 trace that captures the situation (I am sure self-inflicted) where I am struggling.  The four log files represent the entire contiguous log.

The first part (https://pastebin.com/j7RDmKL7) of the log captures the startup.  I dont think there is much interesting here but it does log parameters.

The second part (https://pastebin.com/RguQb4E6) of the log captures when I load the webpage.  A Janus.init() and janus.attach.success is performed and a keepalive timer is established.   I am not really looking to have rtsp traffic at this point (which keeps timing out in the log), so maybe I should be issuing a "stop" request??  This is informational, but I dont think directly related to my core issue.

The third part (https://pastebin.com/a4RJwLAF)  of the log is when I try to watch the live stream.  I start around 08:22:00 and I get the preparing, starting, started messages and for about 6.5 minutes I see constantly 0kb/s and no image.  The log shows some video traffic, but also shows that janus does not think there is any traffic for 5s intervals.  This part of the log is where I am really trying to understand what I have done wrong or what else might be happening.

For the final part (https://pastebin.com/hZjfjxWc) of the log (at about 08:28:32) I start seeing (no new actions taken) non-zero Kb/s and a few seconds later I get an image.  (There is some time (between 08:29:02 and 08:29:15) where the image did not appear to update but then it got going again until stopped at 08:20:20.  (I am not that worried about the stall since that could certainly be network based.)

I am hoping you can look in some detail at the third log and identify what may be the culprit.  I sure hope we can zero in on this.

-brian


To unsubscribe from this group and stop receiving emails from it, send an email to meetecho-janus+unsubscribe@googlegroups.com.

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

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

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

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

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

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

Brian Koblenz

unread,
Oct 7, 2018, 9:56:01 PM10/7/18
to Lorenzo Miniero, meetecho-janus
Thanks for the RTP range explanation.  I think I am good in that respect.

I used debug level 7, because it showed what I think is video data as shown in the following snippet:
[Thu Oct  4 08:22:03 2018] [3927625017756940] Got video RTCP (22 bytes)
[Thu Oct  4 08:22:04 2018] [3927625017756940]  Got an RTCP packet
[Thu Oct  4 08:22:04 2018] [3927625017756940] Incoming RTCP, bundling: this is video (no audio has been negotiated)
[Thu Oct  4 08:22:04 2018]    Parsing compound packet (total of 8 bytes)
[Thu Oct  4 08:22:04 2018]      #1 RR (201)
[Thu Oct  4 08:22:04 2018]        RTCP PT 201, length: 8 bytes
[Thu Oct  4 08:22:04 2018]   End of compound packet
[Thu Oct  4 08:22:04 2018] [3927625017756940] Got video RTCP (22 bytes)
[Thu Oct  4 08:22:05 2018] ^[[33m[WARN]^[[0m [3852303497046843] 5s passed with no media, trying to reconnect the RTSP stream

I can be in the state where I am getting these RTCP packets in the log for minutes, and eventually I get something like the following:
[Thu Oct  4 08:28:32 2018] Video SSRC changed, 0 --> 3447177376
[Thu Oct  4 08:28:32 2018] [3927625017756940]  Got an RTCP packet
[Thu Oct  4 08:28:32 2018] [3927625017756940] Incoming RTCP, bundling: this is video (no audio has been negotiated)
[Thu Oct  4 08:28:32 2018]    Parsing compound packet (total of 44 bytes)
[Thu Oct  4 08:28:32 2018]      #1 RR (201)
[Thu Oct  4 08:28:32 2018] jitter=0.000000, fraction=0, loss=0
[Thu Oct  4 08:28:32 2018]        RTCP PT 201, length: 32 bytes
[Thu Oct  4 08:28:32 2018]      #2 PLI -- PSFB (206)
[Thu Oct  4 08:28:32 2018]        RTCP PT 206, length: 12 bytes
[Thu Oct  4 08:28:32 2018]   End of compound packet

So I think my conclusion is that the network pathways are fine and are fine even when I am not seeing a streamed image.  Right?

This makes me think either I am misusing the api (but since I eventually get streaming data I think that is unlikely) or the RTSP server isn't playing well with the streaming plugin.  Are those reasonable conclusions?  Is something else plausible?

From a streaming perspective my intent is to only have a single live stream (and session/handle to support it) that can be started and stopped.  When I load the webpage, I do a janus.init() and with the attach, I do a streaming.hangup() since it seems streaming starts by default (I have issued no explicit streaming (watch, start or stop).  Then, when I want to stream, I send a streaming.watch and when I want to stop I do a streaming.stop and streaming.hangup since I really dont want that data stream flowing until the next watch.  Is that an appropriate usage?

-brian


To unsubscribe from this group and stop receiving emails from it, send an email to meetecho-janu...@googlegroups.com.

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

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

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

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

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

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

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

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

Lorenzo Miniero

unread,
Oct 8, 2018, 3:00:37 AM10/8/18
to meetecho-janus
The RTCP you see there comes from browsers. It only reinforces the concept that everything's fine on the WebRTC side, and that the issue is on the RTSP side.

Lorenzo
To unsubscribe from this group and stop receiving emails from it, send an email to meetecho-janus+unsubscribe@googlegroups.com.

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

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

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

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

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

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

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

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

Brian Koblenz

unread,
Oct 10, 2018, 11:30:41 PM10/10/18
to Lorenzo Miniero, meetecho-janus
While I have not gotten to the root cause, I have realized much of my delay problem goes away when I require both audio and video from the rtsp stream rather than just video.  I will keep digging into this a bit and suspect it is some kind of incompatibility with the rtsp server.

thanks
-brian


To unsubscribe from this group and stop receiving emails from it, send an email to meetecho-janu...@googlegroups.com.

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

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

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

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

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

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

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

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

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

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

brian....@bdkconsulting.com

unread,
Oct 15, 2018, 1:54:05 PM10/15/18
to meetecho-janus
I slowly gain a little more understanding and that leads to more questions.

My observable issue is that non-infrequently, I will "watch" a stream and get through the preparing,starting,started sequence, but not get any data.  The feedback I get from L is that I am not receiving any data.  So, what I rebuilt janus_streaming.c with a little more logging to capture calls to janus_streaming_relay_rtp_packet and janus_streaming_relay_rtcp_packet, as well as logging lines that convey that audio and video packets were received.

When I first load my web page and start janus and do a streaming.hangup() I am still receiving a steady flow of video packets.  I actually have a use case where I am a little sensitive to bandwidth consumption, and only want those packets to flow from the camera between the streaming "watch" and "stop" commands.    My first question is do I have to janus-destroy the mountpoint to stop the data flow from the camera to janus or is there another recommended method through the streaming plugin?  (This is independent of the actual problem of I am debugging.)

When I "watch" my stream I see the following in my log.   You can see (***) lines where I have a steady flow of incoming video packets, but the "Incoming RTCP bundling, this is audio" keeps repeating and I get no video.  There are no "Incoming RTCP bundling, this is video" messages, but my log data in the routine janus_streaming_relay_thread is continuously indicating that I am receiving video packets.

In an instance of running the code that does behave as I expect, I do see "Incoming RTCP bundling, this is video" messages.

I have not dug into the RTP/RTCP protocol, but it seems like janus is expecting RTCP video messages and the camera doesnt think it needs to send any.

I think this (conclusively?) shows there is no data path issue and my problem is somehow related to janus_streaming/camera rtsp combination not being happy.

What inferences should I draw from this and where do I dig deeper?  Or have I already made inappropriate inferences?

-brian


[Mon Oct 15 10:06:17 2018] [6493567867251632] The DTLS handshake for the component 1 in stream 1 has been completed
[Mon Oct 15 10:06:17 2018] [6493567867251632] The DTLS handshake has been completed
[Mon Oct 15 10:06:17 2018] [6493567867251632] Telling the plugin about it (JANUS Streaming plugin)
[Mon Oct 15 10:06:17 2018] [janus.plugin.streaming-0x7f0408001b20] WebRTC media is now available
[Mon Oct 15 10:06:17 2018] [6493567867251632] Sending event to transport...
[Mon Oct 15 10:06:17 2018] Sending event to janus.transport.http (0x7f0408001820)
[Mon Oct 15 10:06:17 2018] Got a Janus API event to send (0x7f0408001820)
[Mon Oct 15 10:06:17 2018]   >> Pushing event: 0 (Success)
[Mon Oct 15 10:06:17 2018] [6493567867251632] Sending event to transport...; 0x7f0410007040
[Mon Oct 15 10:06:17 2018] Sending event to janus.transport.http (0x7f0408001820)
[Mon Oct 15 10:06:17 2018] Got a Janus API event to send (0x7f0408001820)
[Mon Oct 15 10:06:17 2018] [6493567867251632] DTLS already set up, disabling retransmission timer!
[Mon Oct 15 10:06:17 2018] New connection on REST API: ::ffff:127.0.0.1
[Mon Oct 15 10:06:17 2018] [transports/janus_http.c:janus_http_handler:1150] Got a HTTP GET request on /janus/268031666939034...
[Mon Oct 15 10:06:17 2018] [transports/janus_http.c:janus_http_handler:1151]  ... Just parsing headers for now...
[Mon Oct 15 10:06:17 2018] [transports/janus_http.c:janus_http_headers:1739] Accept-Encoding: identity
[Mon Oct 15 10:06:17 2018] [transports/janus_http.c:janus_http_headers:1739] Host: 127.0.0.1:8088
[Mon Oct 15 10:06:17 2018] [transports/janus_http.c:janus_http_headers:1739] Connection: close
[Mon Oct 15 10:06:17 2018] [transports/janus_http.c:janus_http_headers:1739] User-Agent: Python-urllib/2.7
[Mon Oct 15 10:06:17 2018] [transports/janus_http.c:janus_http_handler:1183] Processing HTTP GET request on /janus/268031666939034...
[Mon Oct 15 10:06:17 2018] [transports/janus_http.c:janus_http_handler:1236]  ... parsing request...
[Mon Oct 15 10:06:17 2018] Session: 268031666939034
[Mon Oct 15 10:06:17 2018] Got a Janus API request from janus.transport.http (0x7f0404000e20)
[Mon Oct 15 10:06:17 2018] Got a keep-alive on session 268031666939034
[Mon Oct 15 10:06:17 2018] Sending Janus API response to janus.transport.http (0x7f0404000e20)
[Mon Oct 15 10:06:17 2018] Got a Janus API response to send (0x7f0404000e20)
[Mon Oct 15 10:06:17 2018] Session 268031666939034 found... returning up to 1 messages
***[Mon Oct 15 10:06:17 2018] Got 1083 bytes on the video channel...
***[Mon Oct 15 10:06:17 2018] Got 1091 bytes on the video channel...
[Mon Oct 15 10:06:17 2018] New connection on REST API: ::ffff:127.0.0.1
[Mon Oct 15 10:06:17 2018] [transports/janus_http.c:janus_http_handler:1150] Got a HTTP GET request on /janus/268031666939034...
[Mon Oct 15 10:06:17 2018] [transports/janus_http.c:janus_http_handler:1151]  ... Just parsing headers for now...
[Mon Oct 15 10:06:17 2018] [transports/janus_http.c:janus_http_headers:1739] Accept-Encoding: identity
[Mon Oct 15 10:06:17 2018] [transports/janus_http.c:janus_http_headers:1739] Host: 127.0.0.1:8088
[Mon Oct 15 10:06:17 2018] [transports/janus_http.c:janus_http_headers:1739] Connection: close
[Mon Oct 15 10:06:17 2018] [transports/janus_http.c:janus_http_headers:1739] User-Agent: Python-urllib/2.7
[Mon Oct 15 10:06:17 2018] [transports/janus_http.c:janus_http_handler:1183] Processing HTTP GET request on /janus/268031666939034...
[Mon Oct 15 10:06:17 2018] [transports/janus_http.c:janus_http_handler:1236]  ... parsing request...
[Mon Oct 15 10:06:17 2018] Session: 268031666939034
[Mon Oct 15 10:06:17 2018] Got a Janus API request from janus.transport.http (0x7f0410008690)
[Mon Oct 15 10:06:17 2018] Got a keep-alive on session 268031666939034
[Mon Oct 15 10:06:17 2018] Sending Janus API response to janus.transport.http (0x7f0410008690)
[Mon Oct 15 10:06:17 2018] Got a Janus API response to send (0x7f0410008690)
[Mon Oct 15 10:06:17 2018] Session 268031666939034 found... returning up to 1 messages
***[Mon Oct 15 10:06:17 2018] Got 1005 bytes on the video channel...
[Mon Oct 15 10:06:17 2018] [6493567867251632]  Got an RTCP packet
[Mon Oct 15 10:06:17 2018] [6493567867251632] Incoming RTCP, bundling: this is audio (local SSRC: video=558475374, audio=3287382980, got$
[Mon Oct 15 10:06:17 2018]    Parsing compound packet (total of 8 bytes)
[Mon Oct 15 10:06:17 2018]      #1 RR (201)
[Mon Oct 15 10:06:17 2018]        RTCP PT 201, length: 8 bytes
[Mon Oct 15 10:06:17 2018]   End of compound packet
[Mon Oct 15 10:06:17 2018] [6493567867251632] Got audio RTCP (22 bytes)
***[Mon Oct 15 10:06:17 2018] Got 873 bytes on the video channel...

brian....@bdkconsulting.com

unread,
Oct 15, 2018, 9:02:01 PM10/15/18
to meetecho-janus
Just as I thought I was really narrowing things down, I also have seen a case where, when I have a delay, the RTP packets are streaming but there are not RTCP packets.

I also added code to dump the RTCP packets.  I got an rtcp packet with an unknown type that seemed to have a valid ssrc, but it was ignored.  (In this case, I pull bytes 8-12 of the packet as ssrc and display as hex and decimal.  I also dump the first 8 bytes of the rtcp packet in hex.)  Any thoughts?

from ice.c:janus_ice_cb_nice_recv
[Mon Oct 15 17:41:32 2018] [6087445640823823]  Got an RTCP packet

from rtsp.c:janus_rtcp_get_receiver_ssrc where I dump out rx rtcp for the bundled set of packets

[Mon Oct 15 17:41:32 2018] rx rtcp: 80C9000100000001 ssrc: 81CE0002 (ssrcd: 2177761282)
[Mon Oct 15 17:41:32 2018] ssrc RTCP_RR: 0000 (0)
[Mon Oct 15 17:41:32 2018] rx rtcp: 81CE000200000001 ssrc: 3816C5A5 (ssrcd: 941016485)
[Mon Oct 15 17:41:32 2018] rx rtcp unknown type CE (206)
[Mon Oct 15 17:41:32 2018] rx rtcp: 80000001EA6FF230 ssrc: CC013909 (ssrcd: 3422632201)
[Mon Oct 15 17:41:32 2018] rx rtcp unknown type 00 (0)
[Mon Oct 15 17:41:32 2018] rx rtcp: CC013909FDAD1730 ssrc: 81BDA003 (ssrcd: 2176688131)
[Mon Oct 15 17:41:32 2018] rx rtcp unknown type 01 (1)
[Mon Oct 15 17:41:32 2018] rx ssrc Returning 0

The return 0 above means there was no recognition of the rtcp packet as having a valid ssrc, but 941016485 looks valid to me.  That packet type was 206 which matches RTCP_PSFB as a defined type, but not in the case statement in janus_rtcp_get_receiver_ssrc.  From a quick read, this looks like some kind of FeedBack message that I need to dig more deeply into.  Might this be the getting to the root of my problem?

[Mon Oct 15 17:41:32 2018] [6087445640823823] Incoming RTCP-A, bundling: this is video (local SSRC: video=941016485, audio=275199893, got 0)
[Mon Oct 15 17:41:32 2018]    Parsing compound packet (total of 20 bytes)
[Mon Oct 15 17:41:32 2018]      #1 RR (201)
[Mon Oct 15 17:41:32 2018]        RTCP PT 201, length: 8 bytes
[Mon Oct 15 17:41:32 2018]      #2 PLI -- PSFB (206)
[Mon Oct 15 17:41:32 2018]        RTCP PT 206, length: 12 bytes
[Mon Oct 15 17:41:32 2018]   End of compound packet
[Mon Oct 15 17:41:32 2018] [6087445640823823] Got video RTCP (34 bytes)
[Mon Oct 15 17:41:32 2018] Got 1132 bytes on the audio channel...
[Mon Oct 15 17:41:32 2018] ^[[31m[ERR]^[[0m [plugins/janus_streaming.c:janus_streaming_relay_rtp_packet:6436] Enter relay_rtp_packet
[Mon Oct 15 17:41:32 2018] Got 1132 bytes on the audio channel...
[Mon Oct 15 17:41:32 2018] [6087445640823823]  Got an RTCP packet
[Mon Oct 15 17:41:32 2018] rx rtcp: 81C9000700000001 ssrc: 3816C5A5 (ssrcd: 941016485)
[Mon Oct 15 17:41:32 2018] ssrc RTCP_RR: 3816C5A5 (941016485)
[Mon Oct 15 17:41:32 2018] [6087445640823823] Incoming RTCP-A, bundling: this is video (local SSRC: video=941016485, audio=275199893, got 941016485)


On Saturday, September 22, 2018 at 11:45:19 AM UTC-7, brian....@bdkconsulting.com wrote:

Lorenzo Miniero

unread,
Oct 16, 2018, 4:39:38 AM10/16/18
to meetecho-janus
Not all RTCP packets will be relayed to the WebRTC user: actually, most of them will be dropped, as packets like RR/SR/SDES are terminated by the core and originated there, which means anything the plugin tries to push that falls into that category is ignored. Other packets (e.g., PLI, REMB) are relayed instead.

Lorenzo
Reply all
Reply to author
Forward
0 new messages