LubosD / twinkle

Qt 5 port of Twinkle
http://twinkle.dolezel.info
GNU General Public License v2.0
170 stars 50 forks source link

Twinkle crashes with PCM error message #321

Open urbanware-org opened 1 year ago

urbanware-org commented 1 year ago

I'm using Twinkle on Fedora 37 and Twinkle 1.10.3 with PipeWire as follows:

twinkle_audio_devices

Actually this works fine, however, once in a while, Twinkle crashes "silently". The tray icon suddenly disappears without any error message. After that happened a couple of times, I ran Twinkle on a shell to see what happens when it crashes again. Every time it crashes, it does with this error message:

twinkle: pcm.c:3380: snd_pcm_areas_copy: Assertion `dst_areas' failed.

This occurs in the following two situations:

This happens at irregular intervals. Sometimes it doesn't happen at all in one day, sometimes several times. So, I'm unable to manually reproduce it in any way.

If I'm not mistaken, the error message comes from ALSA libraries. If relevant, this is the list of the installed ALSA packages:

alsa-lib-1.2.9-1.fc37.x86_64
alsa-sof-firmware-2.2.5-1.fc37.noarch
alsa-ucm-1.2.9-1.fc37.noarch
alsa-utils-1.2.9-1.fc37.x86_64

While I'm on the phone, I don't have any problems at all.

cyberbeat commented 1 year ago

I use same configuration (pipewire), and have similar "silent" crashes.

fbriere commented 1 year ago

@urbanware-org Thank you very much for taking the time to provide so many details; this was quite helpful and very much appreciated!

I think I know where the (ALSA) bug is located, but just to make sure, could you provide us with a backtrace? We have instructions on how to generate one on our Wiki; Fedora also has its own information on the subject. In addition:

Thanks in advance!

fbriere commented 1 year ago

For the record, here's where I think the bug is located (with another copy in snd_pcm_mmap_read_areas()):

https://github.com/alsa-project/alsa-lib/blob/81a7a93636d9472fcb0c2ff32d9bfdf6ed10763d/src/pcm/pcm_mmap.c#L86-L90

__snd_pcm_mmap_begin() is called to set up pcm_areas (on the stack), but no check is performed on its return value. If the call failed, pcm_areas is not set and contains garbage, and any future attempt to use it as source/destination is likely to cause an error. (Fortunately, it happened to contain 0 and is detected by an assertion, instead of any random value that would trigger a mysterious segfault later on.)

After some experimentation, it appears that the value assigned to pcm_areas remains the same from one call to the next, and also happens to survive on the stack. Basically, once the first call to __snd_pcm_mmap_begin() has been successful, any subsequent failures will not have any impact, hence why all crashes occur at the very start of any audio playback. (It's not that errors no longer occur, but rather that we're blissfully unaware of them.)

fbriere commented 1 year ago

@cyberbeat Do you get the same "failed assertion" message? If so, would you be able to generate a backtrace as I have explained in my previous comment? Thanks!

urbanware-org commented 1 year ago

Thank you very much for taking the time to provide so many details; this was quite helpful and very much appreciated!

@fbriere You're welcome, I'm always glad to help!

I think I know where the (ALSA) bug is located, but just to make sure, could you provide us with a backtrace?

I'm currently not in office having a few days off, but I will be back at work on October, 16th and can create a backtrace then.

cyberbeat commented 1 year ago

@cyberbeat Do you get the same "failed assertion" message? If so, would you be able to generate a backtrace as I have explained in my previous comment? Thanks!

Yes:

Language name: "de" warning: The VAD has been replaced by a hack pending a complete rewrite warning: The VAD has been replaced by a hack pending a complete rewrite warning: discarded first playback frame warning: The VAD has been replaced by a hack pending a complete rewrite warning: The VAD has been replaced by a hack pending a complete rewrite warning: discarded first playback frame warning: The VAD has been replaced by a hack pending a complete rewrite warning: discarded first playback frame warning: The VAD has been replaced by a hack pending a complete rewrite warning: discarded first playback frame twinkle: pcm.c:3340: snd_pcm_areas_copy: Zusicherung »dst_areas« nicht erfüllt. Abgebrochen (Speicherabzug geschrieben)

unluckily, I cannot find a core dump (although started from shell with ulimit -c unlimited, perhaps because of /proc/sys/kernel/core_pattern = |/bin/false

cyberbeat commented 1 year ago

Finally a backtrace:

Thread 1 (Thread 0x7fd3f5ffb700 (LWP 24765)):
#0  0x00007fd429f57c6b in raise () from /lib64/libc.so.6
#1  0x00007fd429f59305 in abort () from /lib64/libc.so.6
#2  0x00007fd429f4fc6a in __assert_fail_base () from /lib64/libc.so.6
#3  0x00007fd429f4fcf2 in __assert_fail () from /lib64/libc.so.6
#4  0x00007fd42cdae352 in snd_pcm_areas_copy (dst_areas=dst_areas@entry=0x7fd3f5ffa8e0, dst_offset=dst_offset@entry=0, src_areas=src_areas@entry=0x0, src_offset=src_offset@entry=2048, channels=channels@entry=1, frames=frames@entry=342, format=SND_PCM_FORMAT_S16_LE) at pcm.c:3341
#5  0x00007fd42cdae3ff in snd_pcm_areas_copy_wrap (dst_channels=0x7fd3f5ffa8e0, dst_offset=0, dst_size=342, src_channels=0x0, src_offset=2048, src_size=4096, channels=1, frames=342, format=SND_PCM_FORMAT_S16_LE) at pcm.c:3432
#6  0x00007fd405b51f89 in ?? () from /usr/lib64/alsa-lib/libasound_module_pcm_pipewire.so
#7  0x00007fd405b521e4 in ?? () from /usr/lib64/alsa-lib/libasound_module_pcm_pipewire.so
#8  0x00007fd404381ccd in ?? () from /usr/lib64/libpipewire-0.3.so.0
#9  0x00007fd3fc543653 in ?? () from /usr/lib64/spa-0.2/audioconvert/libspa-audioconvert.so
#10 0x00007fd40435b689 in ?? () from /usr/lib64/libpipewire-0.3.so.0
#11 0x00007fd40440800e in ?? () from /usr/lib64/spa-0.2/support/libspa-support.so
#12 0x00007fd404332380 in ?? () from /usr/lib64/libpipewire-0.3.so.0
#13 0x00007fd42ea8e6ea in start_thread () from /lib64/libpthread.so.0
#14 0x00007fd42a02494f in clone () from /lib64/libc.so.6

Using

Name        : libasound2
Version     : 1.2.6.1
Release     : 150400.1.4
Architecture: x86_64
Install Date: Mi 26 Apr 2023 13:02:07 CEST
Group       : System/Libraries
Size        : 1211543
License     : LGPL-2.1-or-later
Signature   : RSA/SHA256, Sa 07 Mai 2022 23:41:20 CEST, Key ID 70af9e8139db7c82
Source RPM  : alsa-1.2.6.1-150400.1.4.src.rpm
Build Date  : Sa 07 Mai 2022 23:38:28 CEST
Build Host  : sheep64
Relocations : (not relocatable)
Packager    : https://www.suse.com/
Vendor      : SUSE LLC <https://www.suse.com/>
URL         : https://www.alsa-project.org
Summary     : Advanced Linux Sound Architecture Library
Description :
This package contains the library for ALSA, Advanced Linux Sound
Architecture.
Distribution: SUSE Linux Enterprise 15

Btw most times I have this crash at the end of calls, and I often don't recognize that twinkle does not run anymore...

fbriere commented 1 year ago

Finally a backtrace:

#6  0x00007fd405b51f89 in ?? () from /usr/lib64/alsa-lib/libasound_module_pcm_pipewire.so

Drat! I did not expect PipeWire to show up this early in the stack...

Could you please generate another backtrace after installing the debuginfo packages for libpipewire, pipewire-alsa and pipewire-spa-plugins? Thanks in advance!

fbriere commented 1 year ago

@urbanware-org Like in my reply to @cyberbeat above, I also suggest you install the debuginfo packages for pipewire-libs and pipewire-alsa, just to be safe.

cyberbeat commented 1 year ago

I also recognized this, and wait for the next crash (if there is any, after my pipewire update to pipewire 0.3.80)

cyberbeat commented 1 year ago

Here is some more debuginfo:

Thread 1 (Thread 0x7f7d8f7fe700 (LWP 6267)):
#0  0x00007f7dca306c6b in raise () from /lib64/libc.so.6
#1  0x00007f7dca308305 in abort () from /lib64/libc.so.6
#2  0x00007f7dca2fec6a in __assert_fail_base () from /lib64/libc.so.6
#3  0x00007f7dca2fecf2 in __assert_fail () from /lib64/libc.so.6
#4  0x00007f7dcd15d352 in snd_pcm_areas_copy (dst_areas=dst_areas@entry=0x7f7d8f7fd8e0, dst_offset=dst_offset@entry=0, src_areas=src_areas@entry=0x0, src_offset=src_offset@entry=1024, channels=channels@entry=1, frames=frames@entry=341, format=SND_PCM_FORMAT_S16_LE) at pcm.c:3341
#5  0x00007f7dcd15d3ff in snd_pcm_areas_copy_wrap (dst_channels=dst_channels@entry=0x7f7d8f7fd8e0, dst_offset=dst_offset@entry=0, dst_size=dst_size@entry=341, src_channels=0x0, src_offset=1024, src_size=4096, channels=1, frames=341, format=SND_PCM_FORMAT_S16_LE) at pcm.c:3432
#6  0x00007f7da5f01049 in snd_pcm_pipewire_process (pw=pw@entry=0x1f74e50, hw_avail=hw_avail@entry=0x7f7d8f7fd968, want=want@entry=341, b=<optimized out>, b=<optimized out>) at ../pipewire-alsa/alsa-plugins/pcm_pipewire.c:315
#7  0x00007f7da5f012a4 in on_stream_process (data=0x1f74e50) at ../pipewire-alsa/alsa-plugins/pcm_pipewire.c:440
#8  0x00007f7da473030d in impl_node_process_output (object=0x2ac3190) at ../src/pipewire/stream.c:1135
#9  0x00007f7da42a86e3 in ?? () from /usr/lib64/spa-0.2/audioconvert/libspa-audioconvert.so
#10 0x00007f7da4709239 in process_node (data=0x2ae5bb0) at ../src/pipewire/impl-node.c:1233
#11 node_on_fd_events (source=<optimized out>) at ../src/pipewire/impl-node.c:1306
#12 0x00007f7da47b709e in ?? () from /usr/lib64/spa-0.2/support/libspa-support.so
#13 0x00007f7da46dfbf0 in do_loop (user_data=0x1f70760) at ../src/pipewire/data-loop.c:65
#14 0x00007f7dcee3d6ea in start_thread () from /lib64/libpthread.so.0
#15 0x00007f7dca3d394f in clone () from /lib64/libc.so.6
urbanware-org commented 1 year ago

I also suggest you install the debuginfo packages for pipewire-libs and pipewire-alsa, just to be safe.

@fbriere All right, I have installed the additional packages this morning.

Unfortunately, I can't provide a backtrace so far as Twinkle did not crash, yet.

cyberbeat commented 1 year ago

I hope the next time, I can also deliver debuginfo for pipewire-spa calls.

urbanware-org commented 1 year ago

So, Twinkle crashed once today and I can finally provide the backtrace.

Thread 45 "twinkle" received signal SIGABRT, Aborted.
[Switching to Thread 0x7fffaffff6c0 (LWP 431014)]
0x00007ffff52afecc in __pthread_kill_implementation () from /lib64/libc.so.6
#0  0x00007ffff52afecc in __pthread_kill_implementation () from /lib64/libc.so.6
#1  0x00007ffff525fab6 in raise () from /lib64/libc.so.6
#2  0x00007ffff52497fc in abort () from /lib64/libc.so.6
#3  0x00007ffff524971b in __assert_fail_base.cold () from /lib64/libc.so.6
#4  0x00007ffff5258696 in __assert_fail () from /lib64/libc.so.6
#5  0x00007ffff7accaac in snd_pcm_areas_copy () from /lib64/libasound.so.2
#6  0x00007ffff7accb53 in snd_pcm_areas_copy_wrap () from /lib64/libasound.so.2
#7  0x00007fffdc158006 in snd_pcm_pipewire_process.isra () from /lib64/alsa-lib/libasound_module_pcm_pipewire.so
#8  0x00007fffdc158132 in on_stream_process () from /lib64/alsa-lib/libasound_module_pcm_pipewire.so
#9  0x00007fffdc0c7710 in impl_node_process_input () from /lib64/libpipewire-0.3.so.0
#10 0x00007fffbc49bc34 in impl_node_process () from /usr/lib64/spa-0.2/audioconvert/libspa-audioconvert.so
#11 0x00007fffdc0ab1c9 in node_on_fd_events () from /lib64/libpipewire-0.3.so.0
#12 0x00007fffdc0268b6 in loop_iterate () from /usr/lib64/spa-0.2/support/libspa-support.so
#13 0x00007fffdc08a2a2 in do_loop () from /lib64/libpipewire-0.3.so.0
#14 0x00007ffff52ae19d in start_thread () from /lib64/libc.so.6
#15 0x00007ffff532fc60 in clone3 () from /lib64/libc.so.6
cyberbeat commented 1 year ago

Now with all debug-info-packages (also pipewire libspa-support), using pipewire 0.3.82, libasound 1.2.6.1

Thread 1 (Thread 0x7f5d167fc700 (LWP 15928)):
#0  0x00007f5d5033ec6b in raise () from /lib64/libc.so.6
#1  0x00007f5d50340305 in abort () from /lib64/libc.so.6
#2  0x00007f5d50336c6a in __assert_fail_base () from /lib64/libc.so.6
#3  0x00007f5d50336cf2 in __assert_fail () from /lib64/libc.so.6
#4  0x00007f5d5319532e in snd_pcm_areas_copy (dst_areas=dst_areas@entry=0x0, dst_offset=dst_offset@entry=2276, src_areas=src_areas@entry=0x7f5d167fb900, src_offset=src_offset@entry=0, channels=channels@entry=1, frames=frames@entry=85, format=SND_PCM_FORMAT_S16_LE) at pcm.c:3340
#5  0x00007f5d531953ff in snd_pcm_areas_copy_wrap (dst_channels=0x0, dst_offset=2276, dst_size=4096, src_channels=src_channels@entry=0x7f5d167fb900, src_offset=src_offset@entry=0, src_size=src_size@entry=85, channels=1, frames=85, format=SND_PCM_FORMAT_S16_LE) at pcm.c:3432
#6  0x00007f5d2c3390ab in snd_pcm_pipewire_process (pw=pw@entry=0x7f5d04150d70, hw_avail=hw_avail@entry=0x7f5d167fb988, want=85, want@entry=3932, b=<optimized out>, b=<optimized out>) at ../pipewire-alsa/alsa-plugins/pcm_pipewire.c:321
#7  0x00007f5d2c3392a4 in on_stream_process (data=0x7f5d04150d70) at ../pipewire-alsa/alsa-plugins/pcm_pipewire.c:440
#8  0x00007f5d2469dcb8 in impl_node_process_input (object=0x7f5d040ac7d0) at ../src/pipewire/stream.c:1050
#9  0x00007f5d1c78b708 in impl_node_process (object=0x7f5d041682e8) at ../spa/plugins/audioconvert/audioadapter.c:1603
#10 0x00007f5d24674619 in process_node (data=0x7f5d04107280) at ../src/pipewire/impl-node.c:1225
#11 node_on_fd_events (source=<optimized out>) at ../src/pipewire/impl-node.c:1298
#12 0x00007f5d2c0eff7e in loop_iterate (object=object@entry=0x7f5d040b8098, timeout=timeout@entry=-1) at ../spa/plugins/support/loop.c:496
#13 0x00007f5d2464aed0 in do_loop (user_data=0x7f5d0412c2b0) at ../src/pipewire/data-loop.c:65
#14 0x00007f5d54e756ea in start_thread () from /lib64/libpthread.so.0
#15 0x00007f5d5040b94f in clone () from /lib64/libc.so.6

@fbriere Could you estimate, if this is an alsa bug, or pipewire bug?

fbriere commented 1 year ago

Now with all debug-info-packages (also pipewire libspa-support), using pipewire 0.3.82, libasound 1.2.6.1

Thanks! I have opened an issue on the PipeWire tracker.

Hi-Angel commented 1 year ago

Should be fixed in the released 0.3.84 Pipewire

cyberbeat commented 1 year ago

Yes, I already use 0.3.84, and did not have any crash until now. Many thanks @fbriere !

urbanware-org commented 1 year ago

I assume that the problem might also be solved for me as well then. However, I cannot verify this (yet) as I no longer receive updates for Fedora 37 after the release of version 39 and don't have the latter running so far.

From this point of view, the issue could be closed, I guess, unless you explicitly want to wait for my confirmation.

fbriere commented 1 year ago

So, Twinkle crashed once today and I can finally provide the backtrace.

Weird, your backtrace contains function names, but lacks argument values and line numbers. First time I've seen something like this. (scratches head) Still, it matches the one from @cyberbeat, and therefore was caused by the same PipeWire bug (now fixed).

Now, may I assume this was with an outgoing call? (It's okay if you don't remember after all this time. :smile:) From your initial description, it seems that incoming calls would cause Twinkle to crash when attempting to play the ringtone, which does not involve PipeWire at all according to your configuration.

Would it be possible for you to post a backtrace of Twinkle crashing on an incoming call? (The lack of argument values and line numbers shouldn't pose too much of a problem here, since I have a good idea of where the bug is actually located, and am merely looking for confirmation.)

fbriere commented 1 year ago

Yes, I already use 0.3.84, and did not have any crash until now. Many thanks @fbriere !

Glad to hear it, and you're welcome!

cyberbeat commented 1 year ago

@fbriere could you have a look also at https://github.com/LubosD/twinkle/issues/323, I know this is hard to debug, but perhaps you have a suggestion, how I can investigate? I also could put some debug outputs in the code and compile an own version, if you give me some hints, where I should look for debugging?

urbanware-org commented 1 year ago

Now, may I assume this was with an outgoing call? (It's okay if you don't remember after all this time. 😄)

Honestly, I do not remember. 😄

Would it be possible for you to post a backtrace of Twinkle crashing on an incoming call?

Sure, I can see what I can get. Within the last days it crashed a couple of times, so I am confident it will do again.

urbanware-org commented 1 year ago

I assume that the problem might also be solved for me as well then. However, I cannot verify this (yet) as I no longer receive updates for Fedora 37 after the release of version 39 and don't have the latter running so far.

Interestingly, I meanwhile can get the PipeWire update to version 0.3.84 for Fedora 37, even though, its EOL is imminent.

Within the last days it crashed a couple of times, so I am confident it will do again.

Anyway, Twinkle did not crash again so far. The in-house upgrade to Fedora 39 at work is scheduled for in two days now. Maybe I can get some backtraces before that.

urbanware-org commented 1 year ago

The in-house upgrade to Fedora 39 at work is scheduled for in two days now

The upgrade was performed last week and the systems are running on Fedora 39 with PipeWire version 0.3.85 now. Everything works as expected so far.

Before, Twinkle also did not crash anymore (still with PipeWire 0.3.83), so I unfortunately can't provide any further backtrace.

urbanware-org commented 1 year ago

Everything works as expected so far.

Still the case, not a single crash.

For my part, this issue could be closed.

zukunft commented 2 months ago

I still have the crashes on Kubuntu 24.04 with KDE-Plasma-Version: 5.27.11 and pipewire 1.0.5. The version number of pipewire does not seem to match with the version numbers above. Maybe it is also interesting for others to explain the version number difference here.

But the main reason for the crashes could be, that Ubuntu still uses twinkle 1.10.2. Here ( https://bugs.launchpad.net/ubuntu/+source/twinkle/+bug/1981347 ) is a request for the upgrade. Maybe others are also interested in voting for this upgrade in ubuntu.

Hi-Angel commented 2 months ago

@zukunft I think you're stumbling upon an unrelated bug, because this one was fixed by newer Pipewire. So it's worth creating a separate report.

(on an unrelated note, when you report to whatever upstream project, it is expected that you have tested with either the latest supported release or ideally with the master branch. 1.10.2 you mention is neither of that. Ubuntu is well known for distributing ancient software, but that means that every report on such software can only go to Ubuntu's launchpad, unless you manually compile and test newer version, thus confirming the problem persists in upstream).

zukunft commented 2 months ago

Yes, possible, that the bug is unrelated, but as you say, I guess, first this ( https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=1054566 ) should be solved.

Hi-Angel commented 2 months ago

but as you say, I guess, first this ( https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=1054566 ) should be solved.

Not necessarily, building a project from sources is not difficult. Twinkly has instructions for building from source code here. So you just git clone https://github.com/LubosD/twinkle && cd twinkle and then follow the commands written there. I see cmake description doesn't provide an actual command, you can use this one cmake ../ -DCMAKE_BUILD_TYPE=Debug -DCMAKE_INSTALL_PREFIX=/usr.

The cmake command will be giving you errors about missing dependencies, you have to google them and install. Actually, to save you time the project has a list here, so you can just go to packages.ubuntu.com and search by keyword. Most often it will likely be the name from that paragraph with -dev postfix, so you can even try that blindnly.

Afterwards make will build the project and I presume you could try running the built executable right from the current directory (I don't know for sure, I never even used twinkle, but usually it Just Works™).

I'd recommend against running make install unless you really have to, because you'd get untracked files all over your system and will most likely screw up your existing twinkle installation. Idk why @LubosD added this line in 6c67703a7d2 without any sort of warning.

Hi-Angel commented 2 months ago

@zukunft …that said, to save you time: I looked at the list of PRs and many have been unanswered for 2 years. Last commit to the project has been an year ago too. So it looks like the project is dead.

zukunft commented 2 months ago

It seems, that we have some activities here ... https://github.com/LubosD/twinkle/pull/324 . I will have a more detailed look at the project and maybe we can fix some more issues.

zukunft commented 2 months ago

I have build and installed version Twinkle 1.10.3, 18 Februar 2022 now and I cannot crash the program any more. From my point of view, this confirms, that upgrading debian to twinkle 1.10.3 would solve the crash problem the all debian/ubuntu user.

Hi-Angel commented 2 months ago

I have build and installed version Twinkle 1.10.3, 18 Februar 2022 now and I cannot crash the program any more. From my point of view, this confirms, that upgrading debian to twinkle 1.10.3 would solve the crash problem the all debian/ubuntu user.

As you're using Kubuntu, note that Ubuntu and Debian repositories are completely unrelated. Canonical are weird regarding updates. Sometimes they avoid upgrading even the app's minor version, but then they locally apply every patch from that minor version, thus basically getting same code as in the newer version, barring the point release difference.

You can report the crash downstream (to launchpad) with the note that upgrading resolves the problem, hoping that the package maintainer will find which commit fixed the bug (or at least ask you to). Though in my vast experience of interacting with Ubuntu launchpad, their reports usually get zero feedback, even highly upvoted ones. It seems to be something Ubuntu-specific, on Fedora and Arch maintainers are much more responsive.

fbriere commented 1 week ago

I tried to build on ubuntu jammy but did not succeed.

Please file a separate issue for this clearly separate issue. Thanks.