You are using DCP-o-matic player for playback in front of audiences? Wow.

What display resolution are you using, and which decode resolution have you chosen?

• Carsten

You get the first annual DCP-o-matic bravery award!

The logging in the player is fairly minimal. Please could you install 2.13.120, go into prefs and set a file name for the "debug log" option. Then send me the contents of that file after a crash?

Wondering how you get decent playback performance for full screen (assuming 1920/1080) display resolutions? Brings uns back to the fact that the current frame writing seems to be pretty slow. Since you started to implement logging to the player, is there a way to e.g. separate the time needed to decompress J2K vs. the time needed to display a frame? Because, it looks as if with many/high clocked cores, the J2K is fast enough, but the display scaling/frame updating can not follow. And this may be platform dependent as well. I remember e.g. WIN has so many different APIs for video rendering.

• Carsten

I'm getting pretty good real time playback with my recent ish i7.

Better logging is necessary, you're right.

I've got an OpenGL renderer nearly ready to test, which might help. It can also do the scaling, I think.

Would be interesting to see performance when display resolution matches decode resolution (as scaling doesn't happen then).
It's difficult to set the window size exactly to the decode resolution manually. I'd love to have a setting for this. Maybe, when you set a decode resolution, set display resolution to exactly that initially. Then, if necessary, let users resize manually with window controls.

It is weird that small changes to window size have a large impact on playback performance.

Yeah, maybe that'll all be solved with a GPU assisted renderer. What do you believe, how much does the inverse x'y'z' cost you?

Hmm, is there a way to set/remember a specific display resolution in prefs? I can't see something like that in my config, but maybe it would be useful.

• Carsten

Here's the log.

Thanks. There's some more logging in 2.13.121; please could you install that and, again, upload the log?

Thanks, we'll do it tomorrow and send here the log.

Alright, looks as if player performance has increased again, in 2.13.121 it is also more solid against other parallel tasks. This is still on my 2013 i7-4coreHT notebook. It's running hot, but, it's running...

Is this already the OpenGL renderer? I get better performance also in full screen.

• Carsten

Not much has changed recently, I don't think... what are you compaing 2.13.121 to?

The OpenGL renderer is not there yet.

My last test on the Mac was 2.13.111 I think. There were some issues switching to/from full screen I think, these are gone now.

I now see two options to go full screen in player on my Mac - the F11, and the one below decoding resolution. The one below quarter-res decoding only hides the menu bar. Is that an OS X specific GUI thing?

Also, I see a thin bright horizontal line in (real) full screen mode, I think below the lower container edge (visible with e.g. letterboxed scope content). But I have seen that before, so it's not new.

btw - player crashes hard when I select a DCP/CPL from the 'recent list' when the content/directory is no longer available. Maybe give a simple 'Not available' message.

• Carsten

Bildschirmfoto 2019-02-19 um 13.29.14.png (42,709 bytes)   

Bildschirmfoto 2019-02-19 um 13.29.14.png (42,709 bytes)   

The crash on non-existent history is fixed now. I'm not adding anything below "quarter resolution" so I think that must be an OS X thing.

Hi! Since 19.02.2019 everything was ok. But today stoped. Here's the log - https://cloud.mail.ru/public/7izg/ZuTf9HfXm

Here's the system log:
Feb 22 16:27:09 localhost kwin_x11[1534]: qt.qpa.xcb: QXcbConnection: XCB error: 3 (BadWindow), sequence: 23653, resource id: 58720577, maj
or code: 15 (QueryTree), minor code: 0

The error on freeze was the same: buffer reach 480 frames. Then the player crashed, just as I described before.

A note on previous comment: it wasn't actually sent by me, so I must add that this system log line is suspected (by us) to have relation with the problem we're solving here. What's also strange is that we couldn't find anything about freeze or crash in player's log.

Hm, that BadWindow sounds like something in X11 is giving up the ghost. If that happened, the buffer error could conceivably follow.

Maybe you should be an early tester of the OpenGL view code...

We'll surely be, but then we need to set up an additional server, or a separate test environment. I don't think that it's safe for us to test that new renderer right in production.

We also bought a new CPU, now it's a Ryzen 7 2700X. We don't encounter the bug anymore, and my personal thought on it is that a frame drop itself is processed somehow “dangerously”. I may be wrong, as all my coding experience consists of shell scripts (if this can be considered coding at all), and some stuff in Pascal back in the days I was a school student.

Interesting; ok, thanks for getting back. It sounds like, as you say, underruns are being unsafely-handled. I will bump this to 2.16.0 and see if it is reproducible with some long playback runs. To my knowledge there are not many users who are running DoM player in production.

Today we caught it again, but without a crash: playback just had frozen, both video and audio. Player version was the most recent test build available in RPM package (2.3.127). I'll also send logs a little later, when I get to the PC we use for playback.

Hi, it's Alexandr, we are testing toghether with Alexey. The player is working, but suddenly in logs began write

Ср 13 мар 2019 15:40:57: 1394,208333333333 -> 1394,176479166667; delay 31,85416666656238
Ср 13 мар 2019 15:40:57: 1394,25 -> 1394,21921875; delay 30,78125000001819
Ср 13 мар 2019 15:41:00: WARNING: Butler video buffers reached 96 frames (audio is 21376)
Ср 13 мар 2019 15:41:00: WARNING: Butler video buffers reached 96 frames (audio is 21376)
Ср 13 мар 2019 15:41:00: WARNING: Butler video buffers reached 96 frames (audio is 21376)

and after
Ср 13 мар 2019 15:41:16: WARNING: Butler video buffers reached 479 frames (audio is 19376)
stopted again.

We have the projector fullHD, but show dcp in full resolution (flat or scope). Can it be the reason?

Here's the log - https://cloud.mail.ru/public/pG57/1L73qP5wL

Hi Alexandr. I am guessing that the image freezes but the sound continues just before the crash? is that right? Can you tell if the image stops (in these logs) at the 15:40:57 point or at the 15:41:16 point?

When the xxxx.xx -> xxx.xx; delay xx.xxxx messages stop it suggests that the GUI thread of the player has died, for some reason.

Yes? The image stops and sound continues. It's very difficutt to say it has stopped at 15:40:57 point or at the 15:41:16 point, because it has stopped at 24 minut. I think the problem begins at the 15:40:57 point and at the 15:41:16 point player stops. For player 480 frame is crytical.

Why it begins i don know. We show different films. It can happen in begin of film, in middle or in the end. It can happen once a day or once a week. Always in log it begins from 96 frame (WARNING: Butler video buffers reached 96 frames (audio is 19520), and ends at nearly 400 (for example one month ago it stopped at 397 frames - WARNING: Butler video buffers reached 397 frames (audio is 21872).

That the reason it could be which keels the GUI thread of the player? I see no regularity:(

2carl: yes, crash is usually preceded with a video freeze, but sometimes playback freezes for both audio and video. This way the player doesn't crash, but works again only after restart: none of the controls work. However, it seems to exit with code 0. We need to check that also, and we will as soon as we build another PC, which will be used exclusively as testing environment.

Seems that with latest test builds, the bug is “gone”. Looks like it's strongly related to frame dropping. With the latest builds, we have frame dropouts only when starting playback, and no frame drops afterwards no matter how long do we play movies for. However, we are still ready to test this on a slower machine, as soon as we build it.

OK, keep us updated!

Hi, Carl. Today used last version 2.13.141, and it freezed again. The bag the same: WARNING: Butler video buffers reached

Here's screenshot, and here's the log. The problem begins at 21:56:05

We retturned to version 2.13.137

Sorry,

screenshot - https://cloud.mail.ru/public/BaT5/fsfJEHNiv
and log - https://cloud.mail.ru/public/FhkY/qJ78B5zkb

Do you run a playlist? How long is that playlist, how many items?

I guess I could easily set up something similar on a system here and see what happens.

• Carsten

Hi, Carsten. We can't do any playlist because when we open playlist editor we cant't add any dcp in it. We are working in this mode - open player show some trailers, close program and open again and show movie. As I sad this bug happens suddenly in different times and I can't see any regularity :(

That means, it happens during a single movie showing, and you restart the player always before the next showing?

Yes.

New build (2.13.150) seems to be more hangup-prone than a previous one.

No changes regarding this bug whatsoever in any of downloadable builds. Hangups still occur, happily for both sound and video, so it's at least possible to precisely capture the glitch point and restart playback from the same frame again. However, there's still nothing interesting in logs, so I can't provide any more info. What can I do to get more data on this? We're ready to sponsor this particular bug fix since the issue first appeared.

Sorry there hasn't been much progress here. I've been getting 2.14.0 out of the door and fixing the bugs that are inevitably discovered by the early adopters :\

The OpenGL display code is more-or-less ready to roll. Would you be interested in trying that? Even if it doesn't work it would eliminate some possible causes.

The other thing I could try is to run some long-term tests on my PC (i.e. play DCPs all day). if I can reproduce there is much more chance of a fix. It would need a few hardware adjustments on my end, though (mostly more disc space).

But, it 2.13.137 safe?

• Carsten

Yes!!! We would be interested!!! We are waiting! We are ready!:)))

2carl: yes, we're eager to test this code.

2Carsten: no, crashes have occured occur on that build too. I still think it has something to do with XCB rendering, because what can be caught in system (not player) log is an XCB error.

2.15.1 is incoming to dcpomatic.com/test-download

You need to select OpenGL mode from advanced preferences. It's all very bleeding-edge but I'd be interested to hear how you get on if you try it.

Carl, hello. It's great!

But we're using linux Fedora 29, can you make rpm for us? Thank you ever so much:)

Fedora 29 RPM is up now.

Still the same on 2.15.5, still occurs randomly.

Does not occur on CentOS 7, still does on Fedora. Other distributions were not tested due to lack of time. However, on CentOS 7, there are huge frame drops in certain movies, probably related to varying decoding difficulty level. Most of movies are unaffected, and this is clearly not to be connected with image resize, as there are both Scope 2K and Full HD Flat movies affected by this.

According to my research, this problem has something to do with X11 or XCB version.

I confirm this bug on Ubuntu 18.04 (actually KDE Neon, but the base is virtually the same) and almost any version of Fedora I could get, both stable and testing branch.

Confirmed also on CentOS 7, but it was first time in several months, and occured only twice while playing movies back as usual.