thunderbird 91.9.1 (jammy) sometimes deadlocks when moving mails from INBOX

[Walter]

SUMMARY
-------

When moving e-mail from my INBOX to subfolders Thunderbird hangs and goes into an unusable state. The '"Thunderbird Mail" is not responding' pops up, and there is no option but to 'Force Quit' (because 'Wait' isn't helping).

This does not happen for every move. But yesterday when sorting my INBOX, it happened more than 5 times in total.

DESCRIPTION
-----------

When moving mail,
- I select one or more from the middle pane;
- drag it/them to the left (folder pane).
- There, I hover above the right folder and wait for it to highlight.
- Upon highlight, I release the mouse.

Normally this moves the e-mail(s) to that folder, but now I get a deadlock in about 1 out of 20 moves.

On Focal, I used all versions, including
- 1:91.7.0+build2-0ubuntu0.20.04.1
- 1:91.8.1+build1-0ubuntu0.20.04.1
- 1:91.9.1+build1-0ubuntu0.20.04.1

On Jammy, I'm at:
- 1:91.9.1+build1-0ubuntu0.22.04.1

The first time I noticed this issue, was while I'm on Jammy. But, I hadn't cleaned my mailbox in a while, so it _might_ be related to the Thunderbird version. Although I my money would be on the version in conjunction with Jammy (Wayland?).)

OBSERVATIONS
------------

- My INBOX is not big. It contained 2,500 mails or so. (And very few large e-mails.) The destination folders aren't particularly big either. And I didn't see a pattern related to which destination folder.

- When starting thunderbird from the command line, I get lots of these:

###!!! [Parent][DispatchAsyncMessage] Error: PClientManager::Msg_ExpectFutureClientSource Processing error: message was deserialized, but the handler returned false (indicating failure)
IPDL protocol error: Handler returned error code!
###!!! [Parent][DispatchAsyncMessage] Error: PClientManager::Msg_ForgetFutureClientSource Processing error: message was deserialized, but the handler returned false (indicating failure)
Unsupported modifier, resource creation failed.
XXX: resource creation failed
IPDL protocol error: Handler returned error code!

  (But I have no idea what they mean, or whether those log lines were emitted in the Focal version.)

- Thunderbird runs as a family of three:

/usr/lib/thunderbird/thunderbird
\_ /usr/lib/thunderbird/thunderbird -contentproc -childID 1 -isForBrowser -prefsLen 1 -prefMapSize 263514 -jsInit 285636 -parentBuildID 20220520005021 -appdir /usr/lib/thunderbird 549186 true tab
\_ /usr/lib/thunderbird/thunderbird -contentproc -childID 2 -isForBrowser -prefsLen 1 -prefMapSize 263514 -jsInit 285636 -parentBuildID 20220520005021 -appdir /usr/lib/thunderbird 549186 true tab

- Main PID has 248 threads, child 1 has 23, child 2 has 22.

ENVIRONMENT
-----------

$ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu 22.04 LTS
Release: 22.04
Codename: jammy

$ env | grep ^[GXW] | sort | grep -v GPG
GDMSESSION=ubuntu
GNOME_DESKTOP_SESSION_ID=this-is-deprecated
GNOME_SETUP_DISPLAY=:1
GNOME_SHELL_SESSION_MODE=ubuntu
GNOME_TERMINAL_SCREEN=/org/gnome/Terminal/screen/6a49f69b_ac07_4c6d_b681_a0dada8d38d3
GNOME_TERMINAL_SERVICE=:1.704
GTK_MODULES=gail:atk-bridge
WAYLAND_DISPLAY=wayland-0
XAUTHORITY=/run/user/1000/.mutter-Xwaylandauth.0J31M1
XDG_CONFIG_DIRS=/etc/xdg/xdg-ubuntu:/etc/xdg
XDG_CURRENT_DESKTOP=ubuntu:GNOME
XDG_DATA_DIRS=/usr/share/ubuntu:/usr/local/share/:/usr/share/:/var/lib/snapd/desktop
XDG_MENU_PREFIX=gnome-
XDG_RUNTIME_DIR=/run/user/1000
XDG_SESSION_CLASS=user
XDG_SESSION_DESKTOP=ubuntu
XDG_SESSION_TYPE=wayland
XMODIFIERS=@im=ibus

CHILD 1 STRACE
--------------

(the following keeps repeating every 2 or 3 seconds)

$ sudo strace -tt -fp 549263 -e'!futex,poll,epoll_wait,restart_syscall'
strace: Process 549263 attached with 23 threads
[pid 549277] 11:04:12.121020 write(9, "\372", 1) = 1
[pid 549263] 11:04:12.121709 read(8, "\372", 1) = 1
[pid 549263] 11:04:12.122327 write(9, "\372", 1) = 1
[pid 549263] 11:04:12.122635 write(13, "\0", 1) = 1
[pid 549265] 11:04:12.122921 read(12, "\0", 1) = 1
[pid 549265] 11:04:12.123142 sendmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="8\0\0\0\24\0\0\0\4\0^\0\1\0\0\0\0\0\0\0\377\377\377\377\377\377\377\377\2733\377\377"..., iov_len=64}, {iov_base="\10\223\2\351\0\230\264f\372\";9E\314\0\0\0\0\0\0\0\0\0\0\0\0\0\0", iov_len=28}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_DONTWAIT <unfinished ...>
[pid 549263] 11:04:12.123327 read(8, <unfinished ...>
[pid 549265] 11:04:12.123393 <... sendmsg resumed>) = 92
[pid 549263] 11:04:12.123634 <... read resumed>"\372", 1) = 1
[pid 549265] 11:04:12.123759 recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="8\0\0\0\24\0\0\0\1\0^\0\1\0\0\0\0\0\0\0\377\377\377\377\377\377\377\377$f\0\0"..., iov_len=4096}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, MSG_DONTWAIT) = 92
[pid 549265] 11:04:12.123978 write(9, "\372", 1) = 1
[pid 549265] 11:04:12.124299 recvmsg(3, {msg_namelen=0}, MSG_DONTWAIT) = -1 EAGAIN (Resource temporarily unavailable)
[pid 549263] 11:04:12.124966 read(8, "\372", 1) = 1
[pid 549263] 11:04:12.125697 write(13, "\0", 1) = 1
[pid 549265] 11:04:12.125982 read(12, "\0", 1) = 1
[pid 549265] 11:04:12.126254 sendmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="0\0\0\0\24\0\0\0\5\0^\0\1\0\0\0\0\0\0\0\377\377\377\377\377\377\377\377\2723\377\377"..., iov_len=64}, {iov_base="\372\";9F\314\0\0\0\0\0\0\0\0\0\0\0\0\0\0", iov_len=20}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_DONTWAIT <unfinished ...>
[pid 549263] 11:04:12.126395 write(9, "\372", 1 <unfinished ...>
[pid 549265] 11:04:12.126515 <... sendmsg resumed>) = 84
[pid 549263] 11:04:12.126603 <... write resumed>) = 1
[pid 549263] 11:04:12.127199 read(8, "\372", 1) = 1
[pid 549263] 11:04:12.127536 write(13, "\0", 1) = 1
[pid 549265] 11:04:12.127668 read(12, "\0", 1) = 1
[pid 549265] 11:04:12.127872 sendmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="8\0\0\0\24\0\0\0\4\0^\0\1\0\0\0\0\0\0\0\377\377\377\377\377\377\377\377\2713\377\377"..., iov_len=64}, {iov_base="\10\223\2\351\0\230\264f\372\";9G\314\0\0\0\0\0\0\0\0\0\0\0\0\0\0", iov_len=28}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_DONTWAIT) = 92
[pid 549265] 11:04:12.128305 recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="8\0\0\0\24\0\0\0\1\0^\0\1\0\0\0\0\0\0\0\377\377\377\377\377\377\377\377%f\0\0"..., iov_len=4096}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, MSG_DONTWAIT) = 92
[pid 549265] 11:04:12.128533 write(9, "\372", 1) = 1
[pid 549263] 11:04:12.128705 read(8, <unfinished ...>
[pid 549265] 11:04:12.128777 recvmsg(3, <unfinished ...>
[pid 549263] 11:04:12.128836 <... read resumed>"\372", 1) = 1
[pid 549265] 11:04:12.128892 <... recvmsg resumed>{msg_namelen=0}, MSG_DONTWAIT) = -1 EAGAIN (Resource temporarily unavailable)
[pid 549263] 11:04:12.128950 write(9, "\372", 1) = 1
[pid 549263] 11:04:12.129162 read(8, "\372", 1) = 1
[pid 549263] 11:04:12.129571 write(9, "\372", 1) = 1
[pid 549263] 11:04:12.129852 read(8, "\372", 1) = 1
[pid 549263] 11:04:12.130217 write(13, "\0", 1) = 1
[pid 549265] 11:04:12.130361 read(12, "\0", 1) = 1
[pid 549265] 11:04:12.130489 sendmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="0\0\0\0\24\0\0\0\5\0^\0\1\0\0\0\0\0\0\0\377\377\377\377\377\377\377\377\2703\377\377"..., iov_len=64}, {iov_base="\372\";9H\314\0\0\0\0\0\0\0\0\0\0\0\0\0\0", iov_len=20}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_DONTWAIT) = 84
[pid 549277] 11:04:12.142977 write(9, "\372", 1) = 1
[pid 549263] 11:04:12.143281 read(8, "\372", 1) = 1
[pid 549263] 11:04:12.143697 write(9, "\372", 1) = 1
[pid 549263] 11:04:12.143971 write(13, "\0", 1) = 1
[pid 549265] 11:04:12.144125 read(12, "\0", 1) = 1
[pid 549265] 11:04:12.144319 sendmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="8\0\0\0\24\0\0\0\4\0^\0\1\0\0\0\0\0\0\0\377\377\377\377\377\377\377\377\2673\377\377"..., iov_len=64}, {iov_base="\10\223\2\351\0\230\264f\372\";9I\314\0\0\0\0\0\0\0\0\0\0\0\0\0\0", iov_len=28}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_DONTWAIT <unfinished ...>
[pid 549263] 11:04:12.144456 read(8, <unfinished ...>
[pid 549265] 11:04:12.144512 <... sendmsg resumed>) = 92
[pid 549263] 11:04:12.144727 <... read resumed>"\372", 1) = 1
[pid 549265] 11:04:12.144830 recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="8\0\0\0\24\0\0\0\1\0^\0\1\0\0\0\0\0\0\0\377\377\377\377\377\377\377\377&f\0\0"..., iov_len=4096}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, MSG_DONTWAIT) = 92
[pid 549265] 11:04:12.145078 write(9, "\372", 1) = 1
[pid 549265] 11:04:12.145403 recvmsg(3, {msg_namelen=0}, MSG_DONTWAIT) = -1 EAGAIN (Resource temporarily unavailable)
[pid 549263] 11:04:12.145643 read(8, "\372", 1) = 1
[pid 549263] 11:04:12.146242 write(9, "\372", 1) = 1
[pid 549263] 11:04:12.146523 read(8, "\372", 1) = 1
[pid 549263] 11:04:12.146888 write(13, "\0", 1) = 1
[pid 549265] 11:04:12.147055 read(12, "\0", 1) = 1
[pid 549265] 11:04:12.147295 sendmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="0\0\0\0\24\0\0\0\5\0^\0\1\0\0\0\0\0\0\0\377\377\377\377\377\377\377\377\2663\377\377"..., iov_len=64}, {iov_base="\372\";9J\314\0\0\0\0\0\0\0\0\0\0\0\0\0\0", iov_len=20}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_DONTWAIT) = 84

CHILD 2 STRACE
--------------

(the following keeps repeating every 60 seconds)

$ sudo strace -tt -fp 549304 -e'!futex,poll,epoll_wait,restart_syscall'
strace: Process 549304 attached with 22 threads
[pid 549316] 11:06:01.925062 write(9, "\372", 1) = 1
[pid 549304] 11:06:01.926017 read(8, "\372", 1) = 1
[pid 549304] 11:06:01.926992 write(9, "\372", 1) = 1
[pid 549304] 11:06:01.927588 read(8, "\372", 1) = 1

Let me know if I can get your any additional info.

Cheers,
Walter Doekes
OSSO B.V.

[Walter (wdoekes)]

ADDITIONAL INFO
---------------

I now started thunderbird using:

$ XDG_SESSION_TYPE=x11 WAYLAND_DISPLAY= thunderbird

(I don't think those envvars do _exactly_ what I was looking for. For instance, I notice that ossobv/xpaste still doesn't get access to the send_event: https://github.com/ossobv/xpaste/blob/ea8b2ff9f839f9ecc345fd9d04014b99def5b112/xpaste#L182 )

It _does_ look like it changes things for the better because I haven't had it deadlock on me yet. And I've been moving mails for 45 minutes now.

The stdout/stderr definitely reports a change:

$ diff before after -U30
--- before 2022-06-06 13:23:30.137659175 +0200
+++ after 2022-06-06 13:23:13.921604292 +0200
@@ -1,40 +1,58 @@
-$ thunderbird
+$ XDG_SESSION_TYPE=x11 WAYLAND_DISPLAY= thunderbird
 [calBackendLoader] Using Thunderbird's libical backend
 [LDAPModuleLoader] Using LDAPDirectory.jsm
 [MsgSendModuleLoader] Using MessageSend.jsm
 [SmtpModuleLoader] Using SmtpService.jsm
+[GFX1-]: glxtest: Could not connect to wayland socket
 console.debug: "Trying to load /usr/lib/thunderbird/libotr.so"
 console.debug: "Trying to load libotr.so from system's standard library locations"
 console.debug: "Trying to load libotr.so.5 from system's standard library locations"
 console.debug: "Trying to load libotr.so from system's standard library locations"
 console.log: (new Error("Cannot load required OTR library", "resource:///modules/OTRLib.jsm", 109))
-Unsupported modifier, resource creation failed.
-XXX: resource creation failed
 console.debug: "Successfully loaded OpenPGP library librnp.so version 0.16+git20220124.f06439f7.MZLA from /usr/lib/thunderbird/librnp.so"
-Unsupported modifier, resource creation failed.
-XXX: resource creation failed
 console.debug: "Found 0 public keys and 0 secret keys (0 protected, 0 unprotected)"
 console.debug: "Successfully loaded optional OpenPGP library libgpgme.so.11 from system's standard library locations"
 console.debug: "gpgme version: 1.16.0-unknown"
-Unsupported modifier, resource creation failed.
-XXX: resource creation failed
 console.warn: services.settings: thunderbird/hijack-blocklists has signature disabled
-Unsupported modifier, resource creation failed.
-XXX: resource creation failed
-Unsupported modifier, resource creation failed.
-XXX: resource creation failed
-Unsupported modifier, resource creation failed.
-XXX: resource creation failed
-Unsupported modifier, resource creation failed.
-XXX: resource creation failed
-Unsupported modifier, resource creation failed.
-XXX: resource creation failed
-Unsupported modifier, resource creation failed.
-XXX: resource creation failed
+console.error: gloda.datastore: "got error in _asyncTrackerListener.handleError(): 19: constraint failed"
 IPDL protocol error: Handler returned error code!

 ###!!! [Parent][DispatchAsyncMessage] Error: PClientManager::Msg_ExpectFutureClientSource Processing error: message was deserialized, but the handler returned false (indicating failure)

 IPDL protocol error: Handler returned error code!

 ###!!! [Parent][DispatchAsyncMessage] Error: PClientManager::Msg_ForgetFutureClientSource Processing error: message was deserialized, but the handler returned false (ind...

[Olivier Tilloy (osomon)]

Thanks for this very complete report Walter. It looks like this might be an upstream bug that affects thunderbird when running natively on Wayland. Would you mind reporting it in the upstream tracker (https://bugzilla.mozilla.org/enter_bug.cgi?product=Thunderbird) and sharing the link to it here?

[Walter-mozilla (walter-mozilla)]

Created attachment 9280118
lp1977715.txt

User Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/102.0.5005.61 Safari/537.36

Steps to reproduce:

On Ubuntu/Jammy, using 1:91.9.1+build1-0ubuntu0.22.04.1, I'm dragging mail from the main INBOX to other (sub)folders. This works, for a couple of moves, but then Thunderbird becomes completely unresponsive and the GNOME window-is-not-responding message pops up.

Actual results:

Thunderbird deadlocks and cannot wake up. Only the Force Quit button works. After which I can restart Thunderbird and resume cleaning of my INBOX.

Expected results:

Thunderbird should just keep running so I can keep moving e-mails to different subfolders.

====

Verbose explanation and debug info here:
https://bugs.launchpad.net/ubuntu/+source/thunderbird/+bug/1977715
(also attached as lp1977715.txt )

Basically it appears like Wayland has something to do with this.
When starting thunderbird with XDG_SESSION_TYPE=x11 WAYLAND_DISPLAY= it looks like Thunderbird behaves normally and no deadlocks occur.

One of the things that stand out, is that without Wayland enabled, the following messages are not observed on stderr anymore:

> Unsupported modifier, resource creation failed.
> XXX: resource creation failed

But that may be unrelated.

[Walter (wdoekes)]

Upstream bug report:
https://bugzilla.mozilla.org/show_bug.cgi?id=1773140

[Olivier Tilloy (osomon)]

Thanks!

[Vseerror (vseerror)]

Does this still reproduce for you when using version 102?

[Walter (wdoekes)]

No it does not.

I've been cleaning up my inbox a bit, and I got it to crash really fast before. Now I've been running for days without issues.

LGTM

[Walter-mozilla (walter-mozilla)]

Looks fixed to me. I've been cleaning up some more mail and it hasn't hung once. LGTM :)

[Pppx (pppx)]

Resolved per whiteboard and Comment 2