Log data is missing "stopped" events

[novoid]

Hi,
I did a test-run with the current logger addon. I was looking for a movie I haven't seen so far (missing the watched/not watched information). Therefore, I started a couple of movies, stopping after a few seconds, going to the next one, starting, watching a brief period of time, stopping again until I found the last one which I watched full length.

This is what I got in the logs:

1581020386;started;0;5278;nfs://192.168.1.2/home/user/tv/2019-06-30T20.15.00 ORF - Tatort - Tatort_ Operation Hiob -- highquality.mp4;;;;-1;-1;
1581020393;resumed;22;5278;nfs://192.168.1.2/home/user/tv/2019-06-30T20.15.00 ORF - Tatort - Tatort_ Operation Hiob -- highquality.mp4;;;;-1;-1;
1581020397;resumed;30;5278;nfs://192.168.1.2/home/user/tv/2019-06-30T20.15.00 ORF - Tatort - Tatort_ Operation Hiob -- highquality.mp4;;;;-1;-1;
1581020426;started;0;5250;nfs://192.168.1.2/home/user/tv/2019-07-07T20.16.02 ORF - Tatort - Tatort_ Glaube, Liebe, Tod -- highquality.mp4;;;;-1;-1;
1581020432;resumed;20;5250;nfs://192.168.1.2/home/user/tv/2019-07-07T20.16.02 ORF - Tatort - Tatort_ Glaube, Liebe, Tod -- highquality.mp4;;;;-1;-1;
1581020435;resumed;25;5250;nfs://192.168.1.2/home/user/tv/2019-07-07T20.16.02 ORF - Tatort - Tatort_ Glaube, Liebe, Tod -- highquality.mp4;;;;-1;-1;
1581020498;started;0;5315;nfs://192.168.1.2/home/user/tv/2019-07-14T20.15.00 ORF - Tatort - Tatort_ Lohn der Arbeit -- highquality.mp4;;;;-1;-1;
1581020506;resumed;48;5315;nfs://192.168.1.2/home/user/tv/2019-07-14T20.15.00 ORF - Tatort - Tatort_ Lohn der Arbeit -- highquality.mp4;;;;-1;-1;
1581020645;started;0;5224;nfs://192.168.1.2/home/user/tv/2019-07-21T20.16.12 ORF - Tatort - Tatort_ Falsch verpackt -- highquality.mp4;;;;-1;-1;
1581020652;resumed;40;5224;nfs://192.168.1.2/home/user/tv/2019-07-21T20.16.12 ORF - Tatort - Tatort_ Falsch verpackt -- highquality.mp4;;;;-1;-1;
1581020670;started;0;5214;nfs://192.168.1.2/home/user/tv/2019-08-18T20.16.00 ORF - Tatort - Tatort  Nemesis -- highquality.mp4;;;;-1;-1;
1581020677;resumed;50;5214;nfs://192.168.1.2/home/user/tv/2019-08-18T20.16.00 ORF - Tatort - Tatort  Nemesis -- highquality.mp4;;;;-1;-1;

I'd like to understand how to interpret these lines. What I do not understand so far is the "resumed" value. I miss the "stopped" information. Can you give a brief comment or documentation on all of the columns at least for the video log?

Note: so far, I do have also issues running the corresponding Memacs module. With the column information, I do have better possibilities to debug there.

[DerBeutlin]

Hi Karl,
long time no see.
I actually don't use this myself rightnow so it's hard for me to debug.
But I mean the code for the plugin is dead simple
(https://github.com/DerBeutlin/KodiPlayEventLogger/blob/master/script.kodi_logger/addon.py#L60)
So question is, are the resumed logs legit and are only the stopped logs missing or do you expect the stopped logs instead of the resumed logs.
In the former case I would expect that this line (https://github.com/DerBeutlin/KodiPlayEventLogger/blob/master/script.kodi_logger/addon.py#L20) is preventing the stop logs but I will test it as soon as I have a Kodi running somewhere
It's working on my kodi instance perfectly, which kodi version do you have installed?

[novoid]

Hi,

Yes, even longer time, no see :-( I'm so sorry I was not scheduling GitHub time for too long. I know that this is not respectful, considering other people's time just like yours. I promise I'll try to answer much more short-term from now on.

Meanwhile, I've got LibreElec 9.2 with Kodi 18.5.

The resumed seems legit. However, I was missing the information when the playback was stopped although I've seen it in your code as well.

I did recognize that a few entries are plain wrong:

[...]
 ** <2020-04-01 Wed 20:03>--<2020-04-04 Sat 12:56> [1h episode]
 ** <2020-04-04 Sat 12:56>--<2020-04-09 Thu 21:11> [a way too long streaming URL]
 ** <2020-04-09 Thu 21:11>--<2020-04-09 Thu 21:31> [an episode that got paused]
 ** <2020-04-09 Thu 22:15>--<2020-04-14 Tue 13:18> [2nd half of the episode
 ** <2020-04-14 Tue 13:18>--<2020-04-15 Wed 21:27> [a streaming URL]
[...]

It looks to me that the stopped trigger is not making it to the log file. Therefore, your code is using the start trigger of the next event as the stop time for the previous, resulting in wrong durations and end-time-stamps.