Xournal++ crashes when audio finishes playing

[nicolae-stroncea]

Affects versions :

• OS: Fedora 30 Gnome Wayland And X11(occurs on both), Built and compiled
• Version of Xournal++ : Most recent one, seems to be master on commi 6260dba

Describe the bug
After recording, when I click Play object, once the audio ends, it crashes horribly, in one case froze on the GUI and needed to restart PC.

To Reproduce
Steps to reproduce the behavior:

1. Step 1: Build and Compile xournalpp on Fedora 30, package as a .tar.gz
2. Step 2: Set audio input and output to pulse, Record, and then play audio.
3. Step 3: Once audio finishes playing, it will crash

Expected behavior
Not to crash
errorlog.20190906-231602.log

EDIT: To clarify about what I meant when I said: once the audio ends: It seems to occur both when general audio finishes playing, as well as when audio finishes playing for a particular object

[LittleHuba]

If you run Xournal++ from a console do you get some additional output when it crashes?
(It is normal that there are some lines written when you start Xournal++ - so these do not count)

[nicolae-stroncea]

I tried multiple output types: pulse, sysdefault, System Default, I think it crashed for all of them. My default input device is sysdefault.

I attached a couple of logs that are all around the same error.

errorlog.20190918-164810.log

With Terminal Output:

ALSA lib pcm.c:2564:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.rear
ALSA lib pcm.c:2564:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.center_lfe
ALSA lib pcm.c:2564:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.side
ALSA lib pcm_route.c:869:(find_matching_chmap) Found no matching channel map
ALSA lib pcm_route.c:869:(find_matching_chmap) Found no matching channel map
ALSA lib pcm_route.c:869:(find_matching_chmap) Found no matching channel map
ALSA lib pcm_route.c:869:(find_matching_chmap) Found no matching channel map
Cannot connect to server socket err = No such file or directory
Cannot connect to server request channel
jack server is not running or cannot be started
JackShmReadWritePtr::~JackShmReadWritePtr - Init not done for -1, skipping unlock
JackShmReadWritePtr::~JackShmReadWritePtr - Init not done for -1, skipping unlock

(xournalpp:28087): Gtk-CRITICAL **: 16:47:43.627: gtk_widget_queue_resize: assertion 'GTK_IS_WIDGET (widget)' failed
double free or corruption (out)

** (xournalpp:28087): WARNING **: 16:48:10.697: [Crash Handler] Crashed with signal 6

** (xournalpp:28087): WARNING **: 16:48:10.697: [Crash Handler] Wrote crash log to: /home/nicolae/.xournalpp/errorlogs/errorlog.20190918-164810.log

** (xournalpp:28087): WARNING **: 16:48:11.336: Trying to emergency save the current open document…

** (xournalpp:28087): WARNING **: 16:48:11.353: Successfully saved document to "/home/nicolae/.xournalpp//emergencysave.xopp"
Killed

Additional documents:
errorlog.20190918-163912.log
errorlog.20190918-163258.log
errorlog.20190912-172821.log
errorlog.20190912-172516.log
errorlog.20190909-193738.log
errorlog.20190918-151931.log

Running other isntances from the terminal I got:
double free or corruption (out)
Killed(I force quit it since it completely froze)

Hee's another one:
ALSA lib pcm.c:2564:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.rear
ALSA lib pcm.c:2564:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.center_lfe
ALSA lib pcm.c:2564:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.side
ALSA lib pcm_route.c:869:(find_matching_chmap) Found no matching channel map
ALSA lib pcm_route.c:869:(find_matching_chmap) Found no matching channel map
ALSA lib pcm_route.c:869:(find_matching_chmap) Found no matching channel map
ALSA lib pcm_route.c:869:(find_matching_chmap) Found no matching channel map
Cannot connect to server socket err = No such file or directory
Cannot connect to server request channel
jack server is not running or cannot be started
JackShmReadWritePtr::~JackShmReadWritePtr - Init not done for -1, skipping unlock
JackShmReadWritePtr::~JackShmReadWritePtr - Init not done for -1, skipping unlock

(xournalpp:27886): Gtk-CRITICAL **: 16:43:36.454: gtk_widget_queue_resize: assertion 'GTK_IS_WIDGET (widget)' failed

(xournalpp:27886): Gtk-WARNING **: 16:43:39.051: Could not load image 'pixmaps/xournalpp.svg': Failed to open file “/home/nicolae/Software/xournalpp/build/packages/xournalpp-1.0.13-Fedora-Thirty-x86_64/bin/../share/xournalpp//ui/pixmaps/xournalpp.svg”: No such file or directory

(xournalpp:27886): Gtk-WARNING **: 16:43:53.612: Could not load image 'pixmaps/xournalpp.svg': Failed to open file “/home/nicolae/Software/xournalpp/build/packages/xournalpp-1.0.13-Fedora-Thirty-x86_64/bin/../share/xournalpp//ui/pixmaps/xournalpp.svg”: No such file or directory
double free or corruption (out)

** (xournalpp:27886): WARNING **: 16:44:14.349: [Crash Handler] Crashed with signal 6
Killed

[LittleHuba]

Okay the errorlogs don't really make sense. They lead to a method that does already check it's bounds and should never fail.
Do you know your way around a debugger? You would need to check the variables of the method pop in AudioQueue for sanity. Otherwise I can provide you with a modified version that outputs these values at runtime.

[nicolae-stroncea]

I haven't used any C++ coding tools and don't think I have the environment set up for it, closest I've come to it is C. If you can generate a modified version, I will be happy to use it to debug. If you think debugging it directly would be better, let me know what tools I need to install.

[LittleHuba]

Hmm both have their advantages and disadvantages. The modified version will definitely take longer to fix the issue. But if you don't think you are up to speed and debug on your own then it is most likely the only way to go.
But I can also give you the steps to set up the environment. We actually have a Wiki entry for this already: https://github.com/xournalpp/xournalpp/blob/master/readme/WindowsBuild.md

[morrolinux]

Also crashes when you hit "stop" button, click on another segment during playback (~25% of the times) or even randomly during playback from time to time.
I've run it under vscode debugger and I can see the call stack.
When AudioPlayer::stop() gets called, it calls this->audioQueue->reset() which crashes at library level at this->clear()
I also always get the error double free or corruption (!prev).
or
double free or corruption (out).

I think it might be some unhandled behaviour in the AudioQueue management, but I found the logic behind the whole thing of "connecting an audio producer and an audio consumer" a bit complex to read and understand given my very little free time, so I wouldn't know where to start looking.

[morrolinux]

To me it looks like a race condition between the player stop() method and the queue reset invoked upon audio termination. I still can't say it for sure though.

[LittleHuba]

That would seem legit with the error that is generated.
Making the pop method atomic should fix the problem.

[nicolae-stroncea]

@LittleHuba could that be the cause for the crashes I'm experiencing?

[LittleHuba]

Unlikely as your crashes occur as soon as the pen touches the screen which is not related to the sound system at all.

[nicolae-stroncea]

I'm in midterm right now, so don't think I'll be able to manually debug it, at least for the next month. @LittleHuba, do you think you could create a version which outputs desired values to a log file/terminal?

[LittleHuba]

Will fix the race condition as soon as PR-freeze is over and then we check if your problem persists.

[morrolinux]

Cool! in the meantime I needed something working so I simply reimplemented AudioQueue as a circular baffer rather than a dequeue type of structure (was it really necessary after all?). It seem to work fine, so I can somewhat confirm it was a race condition although I didn't really manage to debug it properly :)

I'll also have to find out why sndfile's seek() is so painfully slow on long tracks past a few minutes. Maybe we can get around this with a byte tipe of seeking/trimming rather than the library one, because up to 10 seconds to seek the track is simply unacceptable for one who actually study with it.
I'll keep you updated on that whenever I found something useful.
Cheers 👋

[LittleHuba]

Cool! in the meantime I needed something working so I simply reimplemented AudioQueue as a circular baffer rather than a dequeue type of structure (was it really necessary after all?). It seem to work fine, so I can somewhat confirm it was a race condition although I didn't really manage to debug it properly :)

Provide us with a PR if it works nicely. Deque is not really necessary. I just did not know if a ring buffer could handle different hardware speed good enough.

Update your sndfile library as they should have fixed that problem exactly the way you proposed 😉

[morrolinux]

Provide us with a PR if it works nicely. Deque is not really necessary. I just did not know if a ring buffer could handle different hardware speed good enough.

Right. I guess we might make the producer wait for the consumer to free the buffer (and the opposite) if that becomes a thing.

Update your sndfile library as they should have fixed that problem exactly the way you proposed

Thanks for the hint! I'm really happy to hear that.
I'm currently on libsndfile 1.0.28-2 on ArchLinux which appears to be the latest version... how do you know they solved it? I was looking for it and even opened a new issue on the github repo because I couldn't find any related issue or bug tracker

[LittleHuba]

Right. I guess we might make the producer wait for the consumer to free the buffer (and the opposite) if that becomes a thing.

Yeah we will see if it is a problem.

Thanks for the hint! I'm really happy to hear that.
I'm currently on libsndfile 1.0.28-2 on ArchLinux which appears to be the latest version... how do you know they solved it? I was looking for it and even opened a new issue on the github repo because I couldn't find any related issue or bug tracker

#996
It was this ticket we discussed this. But if you are on Arch try out sndfile-git.

[morrolinux]

It was this ticket we discussed this. But if you are on Arch try out sndfile-git.

Oh I forgot!
BTW installing sndfile-git indeed solves it... I guess the official repo isn't that frequently updated after all :)

[LittleHuba]

Maybe we should ask for a new release. The last one is from 2017...
Already done even if not in a very nice way (libsndfile/libsndfile#470)
Have just asked again in a hopefully nice way. Let's cross the fingers that this will be released soon and we don't need to fix this on our own.

[LittleHuba]

Okay seems like the release will take some time. We should add a section to the FAQ to make people aware of this issue and present them with the solution to switch to a manually installed version.

Version 1.0.29pre2 should have the fix included.
http://www.mega-nerd.com/libsndfile/files/1.0.29pre2/

[LittleHuba]

@nicolae-stroncea could you try #1512 if it fixes your issue? You can follow the normal build instructions but use the git repository of the PR and make sure you are on the right branch.

If you need help I can provide you with the instructions.

[LittleHuba]

@nicolae-stroncea please test #1529

[nicolae-stroncea]

Sorry for the delay, am currently in my midterm period. This fixed it! Feature works perfectly now. Thanks a lot for the fix by the way, I'm already using the feature to review my notes