How does the Activity log work(start and finish entries)?

[Chiefmas 26]

It's not uncommon for me to see multiple "finished" entries for a single user on a video, vs a single, somewhat recent start entry. Although sometimes I can't even find the start entry. I'm just curious how the determination is made. I could understand multiple finisheds, if the start isn't re-logged for a stop/start somewhat close together, but sometimes the nearest start entry I can find is many hours apart. So I'm just curious how it makes the determination. It looks odd when I can see 5 or 6 "finished playing" and there's nary a start in sight.

 

[Luke 37066]

Hi there, can we please look at an example?

Thanks !

[Chiefmas 26]

I should have mentioned originally, that it doesn't happen all the time, but it is common, and isn't tied to a specific user.

I wasn't sure if you mean server logs, but just as an example of what shows in Activity:

Quote

User1 has finished playing The Mitchells vs. The Machines on User1's FireTVStick
6/14/2022, 11:27:00 PM
 

User1 is playing The Mitchells vs. The Machines on User1's FireTVStick
6/14/2022, 10:03:56 PM
 

User2 has finished playing The Lost Boys on Google Chrome Windows
6/14/2022, 8:53:49 PM
 

User2 has finished playing The Lost Boys on Google Chrome Windows
6/14/2022, 8:52:11 PM
 

User2 has finished playing The Lost Boys on Google Chrome Windows
6/14/2022, 8:46:11 PM
 

User2 has finished playing The Lost Boys on Google Chrome Windows
6/14/2022, 8:43:11 PM
 

User3 has finished playing Star Trek: Picard - Hide and Seek on User3’s iPhone
6/14/2022, 7:35:44 PM
 

User3 is playing Star Trek: Picard - Hide and Seek on User3’s iPhone
6/14/2022, 7:35:39 PM
 

User2 has finished playing The Lost Boys on Google Chrome Windows
6/14/2022, 6:02:11 PM
 

User2 has finished playing Scooby-Doo! and Kiss: Rock and Roll Mystery on XBR-55X850D
6/14/2022, 5:37:52 PM
 

User2 is playing Scooby-Doo! and Kiss: Rock and Roll Mystery on XBR-55X850D
6/14/2022, 5:37:50 PM
 

User2 is playing Scooby-Doo! and Kiss: Rock and Roll Mystery on XBR-55X850D
6/14/2022, 5:37:45 PM
 

User2 is playing Scooby-Doo! and Kiss: Rock and Roll Mystery on XBR-55X850D
6/14/2022, 5:37:41 PM
 

User2 is playing Scooby-Doo! and Kiss: Rock and Roll Mystery on XBR-55X850D
6/14/2022, 5:37:37 PM
 

User2 has finished playing Scooby-Doo! and Kiss: Rock and Roll Mystery on XBR-55X850D
6/14/2022, 5:36:54 PM
 

User2 is playing Scooby-Doo! and Kiss: Rock and Roll Mystery on XBR-55X850D
6/14/2022, 5:36:50 PM
 

User2 is playing Scooby-Doo! and Kiss: Rock and Roll Mystery on XBR-55X850D
6/14/2022, 5:36:45 PM
 

User2 is playing Scooby-Doo! and Kiss: Rock and Roll Mystery on XBR-55X850D
6/14/2022, 5:36:40 PM
 

User2 is playing Scooby-Doo! and Kiss: Rock and Roll Mystery on XBR-55X850D
6/14/2022, 5:36:36 PM
 

User2 has finished playing Scooby-Doo! and Kiss: Rock and Roll Mystery on XBR-55X850D
6/14/2022, 5:36:00 PM
 

User2 is playing Scooby-Doo! and Kiss: Rock and Roll Mystery on XBR-55X850D
6/14/2022, 5:35:55 PM
 

 

[Luke 37066]

Hi @Chiefmas are you still running into this? Can you please attach the emby server log from when this happened? Thanks !

[Chiefmas 26]

I'm still running into...something...so here's an interesting thing that I can't figure out. I'll update a couple server logs that should cover the time period. So this is the interesting thing...no play/stop buttons...it persists through a server restart, I think maybe it's being triggered by the user? I haven't been able to catch them to see if they have a browser window sitting open or something. There appear to be a bunch of those "finished playing" messages. There might be a small gap in the logs, I restarted the server a few times, so there's a bunch of tiny logs, I tried to grab something useful.

 

embyserver-63792402826.txt embyserver.txt

Edited July 3, 2022 by Chiefmas
image fix

[Luke 37066]

OK I understand what's going on, and this is actually easy to reproduce, however I'm not really sure that there's a big problem here, and maybe the "fix" is just to either display less information in the activity log, or make sure all those finished entries are preceded by a started message.

Let me explain. The user starts playing, then pauses,, then moves the Emby app to the background. Once the Emby app is in the background, then depending on the device it can no longer communicate with Emby Server to tell it the user is actually still there. As far as the server is concerned, the user is just gone, so one minute later, it cleans everything up and acts as if the user has stopped playing.

But then at some point after that, the user comes back and continues playing just by unpausing in the video player. Then they pause again, move the app to the background again, and everything repeats itself over and over and that's why you see these "finished" messages.

Nowadays users don't really stop anymore. They just pause, do something else, and then come back later, which could be minutes later, hours, or the next day. So maybe the activity log messages just need to be updated to reflect that type of usage.

[Luke 37066]

Anyway the best way to reproduce is the web app on the smart phone. Start a video, pause, move the browser to the background. Then use another device such as the server machine to monitor the emby server dashboard.

[Chiefmas 26]

On 7/5/2022 at 1:29 AM, Luke said:

OK I understand what's going on, and this is actually easy to reproduce, however I'm not really sure that there's a big problem here, and maybe the "fix" is just to either display less information in the activity log, or make sure all those finished entries are preceded by a started message.

 

Thanks for the explanation, I'm not clamoring for a fix or anything like that. It's more a visual oddity, but it does somewhat make it look like either something is wrong, or that the logging is incomplete, and only capturing one half of an event. Really what it kind of feels like would solve is idle-ness detection/termination.

That's why I pointed out the lack of control buttons in the one screenshot. I suspected that it was something along the lines you described, and I thought if I could just tell the client to terminate the stream, it would probably stop doing that, but I didn't have a way to do so without the buttons. I'd hoped restarting the service might make the client give up, but it doesn't seem to have. But I didn't leave it down for an extended period, and I suspect it still would have just picked up again when the service came back up, even if I had waited a while.

The short term fix I landed on is I locked the user account and restarted the service, but I think that's just moved things into the server log where I probably have a bunch of login denials instead.

Regardless, thanks for the info!

 

[Luke 37066]

I think ultimately we may just get rid of all of those log messages, but obviously we should also make sure it goes aware from now playing.