Thanks for the second log Paul.
I asked for that because I saw something I don't see in my installation, and I thought it was the problem. Every time you start playback of an Audio or Video file, four STOP commands are executed, immediately prior to the playback start. Within milliseconds. As you have said that the problem occurs when you use your keyboard to remote, I knew the remote couldn't be sending repeats. It was too fast anyway. It had to be MC, and I thought the multiple STOPs were clearing the Bookmark.
The second log showed that is not the case. What is missing in the first log is a save of the Bookmark after the movie is first played. For some reason, in your environment and setup, MC does not save the Bookmark if you play an Audio track after stopping a movie, just as you said. It just forgets to do it. It would still be interesting to see if the same thing happens with an MP4, MKV, or some format other than a full folder rip of a Blu-ray. I suspect it would happen then as well, or if it doesn't, then such a test may narrow the known conditions under which the problem happens.
I don't know enough about the internal workings of MC, or how to read all the details of the logs, to work out why. But I think you have a real, although unusual, case for JRiver to look at the problem.
It is what people call a "Corner Case" I'm sure, but I wouldn't be surprised if it happens to other people who just don't notice, or don't speak up about it. Your case may even be an indicator of a broader problem with Bookmark saving. Or just a very special case. i.e. Bookmarks aren't saved for Audio tracks, so when there is a pending Video Bookmark save, and an Audio track starts playing, MC says "Oh, I don't save Bookmarks for Audio tracks" and discards the planned save. It may even affect other tag saves in similar circumstances.
I have included a summary of your two logs below so you can see what I found. Hopefully, someone from JRiver will use your two logs to work out the cause and fix the problem. Or if I am completely wrong, tell us what is happening. I'm convinced there is enough evidence to look into it.
20170830 Log Summary.
Reset Log and started logging. Version MC23.0.41.
Navigated to the movie "Bad Santa 2".
At 18.954 seconds four STOP commands were issued and completed within 246 milliseconds.
At 19.188 seconds playback of "Bad Santa 2" is started, immediately after the fourth STOP. The Bookmark was empty, as expected.
There was some seeking around the movie, the last to about 10 minutes, then playback for about 5 seconds.
At 33.829 seconds a normal, single STOP command is issued, also including "Updating playback state" and "Applying database changes", so the movie Bookmark is set.
Then there is navigation to the Audio section and "Abbath" is selected.
At 45.969 seconds four STOP commands were issued and completed within 246 milliseconds.
At 46.188 seconds playback of "Abbath - Abbath - 01 To War!.flac" is started, immediately after the fourth STOP.
At 59.016 seconds a normal, single STOP command is issued.
Navigated to movie "Bad Santa 2" again.
At 74.329 seconds four STOP commands were issued and completed within 234 milliseconds.
At 74.563 seconds playback of "Bad Santa 2" is started, immediately after the fourth STOP. The movie Bookmark was empty, which was not expected, but perhaps explained by the four STOPs above.
At 85.625 seconds a normal, single STOP command is issued, also including "Updating playback state" and "Applying database changes", so the movie Bookmark is set.
At 107.750 seconds the updated Bookmark is saved to the library.
At 107.954 seconds logging finished.
20170902 Log Summary.
Log file starts at 9.828 seconds.
Navigate to the movie "Snatched".
At 17.031 seconds four STOP commands were issued and completed within 234 milliseconds.
At 17.265 seconds playback of "Snatched" is started, immediately after the fourth STOP. The Bookmark was empty, as expected.
There was some seeking around the movie, the last to about 10.5 minutes, then playback for about 5 seconds.
At 30.094 seconds the updated Bookmark is saved to the library.
At 30.312 seconds a normal, single STOP command is issued, also including "Updating playback state" and "Applying database changes", so the movie Bookmark is set.
At 34.031 seconds four STOP commands were issued and completed within 234 milliseconds.
At 34.265 seconds playback of "Snatched" is started, immediately after the fourth STOP. The Bookmark has a value of 646621ms, or a bit over 10.75 minutes. Which is correct.
At 44.094 seconds a normal, single STOP command is issued, also including "Updating playback state" and "Applying database changes", so the movie Bookmark is set.
At 50.969 seconds the updated Bookmark is saved to the library.
At 51.172 seconds logging finished.
Notes:
All STOP command sequences include the messages "Updating playback state" and "Applying database changes". It is not clear to me for which records updates are occuring, except when it is a single STOP which actually stops playback of a file.
Multiple STOP commands would normally clear the Bookmark, but didn't in the second log, when the second play of the movie started. It looks like because playback of the movie hadn't started yet, the multiple STOPs didn't apply to the movie.
I'm assuming now that you have four Zones set up in MC, and each Zone is receiving a STOP command before playback of a new file is started. Ah yes, the Default (Player), IPC (WDM), Audio, and ASIO In Zones.
Author
Topic: Video resumption to last played position still does not work (Read 18728 times)