Mutt high CPU load

szilard

Hi,
I am using mutt-2.2.9v3-sasl-slang on up-to-date OBSD 7.3 with a fastmail account.
The host is a laptop which I frequently send to sleep. The network connection is provided by wlan and Mutt is running in a tmux session.
Now around 5 times from 10 wake from sleep I find mutt frozen while causing 100% cpu load, so I have to kill it.
I have tried the other mutt package variants, but there is no difference. Any hint how to debug / solve the issue?

rvp

szilard Any hint how to debug / solve the issue?

This is a bit difficult if mutt isn't compiled with debugging (-g). Still, try this:

lldb /PATH/TO/mutt
(lldb) run

Then, when mutt "hangs", type Ctrl-C. That should break you into the debugger. There, type:

(lldb) bt

You could also try the bt command on a live process--if it doesn't kill mutt outright. When it hangs, open another window and type:

lldb -p PID

(where PID is the process-ID of mutt), hen run bt (backtrace). Of course, this would provide much info. if mutt's compiled with -g.

szilard

Thanks for the hints @rvp!
I have started mutt in debug mode (-d 5) and got the following log:

[2023-07-17 20:58:52] mutt_index_menu[831]: Got op -2
[2023-07-17 20:58:52] 6> a0078 STATUS "INBOX" (UIDNEXT UIDVALIDITY UNSEEN RECENT)
[2023-07-17 20:58:52] 6< * STATUS INBOX (RECENT 13 UIDNEXT 4570 UIDVALIDITY 1613402745 UNSEEN 1)
[2023-07-17 20:58:52] INBOX (UIDVALIDITY: 1613402745, UIDNEXT: 4570) 0 messages, 13 recent, 1 unseen
[2023-07-17 20:58:52] Running default STATUS handler
[2023-07-17 20:58:52] Found INBOX in buffy list (OV: 1613402745 ON: 4557 U: 1)
[2023-07-17 20:58:52] 6< a0078 OK Completed
[2023-07-17 20:58:52] IMAP queue drained

Attaching lldb to the existing PID killed mutt, so no further info, right now, but from now on i'll keep mutt running always in lldb to be able to attach to it.

rvp

szilard but from now on i'll keep mutt running always in lldb to be able to attach to it.

ktrace -p PID followed by a Ctrl-C after some time may also tell us which syscall mutt is stuck in. You may need to do sysctl -w kern.global_ptrace=1 first.

And, when this happens, can you ping or connect to the server in question? On my laptop, if I'm remembering this right, OpenBSD-7.3 didn't resume my alc0 interface correctly after a suspend and so networking over that interface never worked without a power-off.

jmcunx

When in relation to wake-up do you start mutt ? I have noticed if the network is not fully up or had some odd issue, mutt will freeze and maybe use high CPU. Same with firefox and friends.

Maybe a silly suggestion by me 🙂

But can you check your network before running mutt, or maybe check the network when this issue occurs.

szilard

jmcunx When in relation to wake-up do you start mutt ?

No, let's consider the following situation:

Laptop running OBSD 7.3 connected to WLAN AP "A" while running mutt and other programs.
I send laptop to sleep
Wake the laptop

Expected result:

OBSD detect the loss of the connection with WLAN AP "A"
OBSD detects the WLAP AP "A" nearby and attempts to connect to it
OBSD connects to WLAN AP "A"
every program should work

Preceived result:

OBSD detect the loss of the connection with WLAN AP "A"
OBSD detects the WLAP AP "A" nearby and attempts to connect to it
ifconfig says the laptop is connected to WLAN AP "A".
mutt freezes.

---------- Also -----------

Laptop running OBSD 7.3 connected to WLAN AP "A" while running mutt and other programs.
I send laptop to sleep
I move to a different physical location, far away from WLAN AP "A", but near to WLAN AP "B"
Wake the laptop

Expected result:

OBSD detect the loss of the connection with WLAN AP "A"
OBSD detects the WLAP AP "B" nearby and attempts to connect to it (access was previously set up)
OBSD connects to WLAN AP "B"
every program should work

Preceived result:

OBSD detect the loss of the connection with WLAN AP "A"
OBSD detects the WLAP AP "B" nearby and attempts to connect to it
ifconfig says the laptop is connected to WLAN AP "B".
No outbound connection can be made, ping doesn't works, only restart helps
All running network-depending application either freezes or just doesn't do much,
mutt freezes.

jmcunx

szilard

So for me to understand, when you sleep, is mutt connected to your email server ? That to me is the issue. See below if that assumption is true.

I am fairly sure when sleep happens, the network is disconnected. Mutt probably has no way of knowing there is no network, thus the hang when it is awaken. To me this is an issue with mutt, not OpenBSD. But I doubt mutt can be changed to get around this issue and remain a 'lite' email client.

For a work-around, I believe you should modify/create the /etc/apm/suspend and/or /etc/apm/hibernate scripts to kill mutt. See:

http://eradman.com/posts/openbsd-workstation.html

szilard

See top output:

26404 szilard   64    0   17M   21M onproc/2  -        14:33 99.56% mutt

nettester

Oh, the eternal joys of sleep states... Sleep and friends is probably some of the most broken functionality ever - across all operating systems. At least there aren't any binary blobs involved here so it should be fixable, even if it takes some time.

Until then a possible approach could be to check how OpenBSD handles wakeup hooks and use those to forcefully reset the network interface in question. No guaranties that'll work/help but at least it would be my first attempt to maybe get rid of the symptoms for now.

nettester

jmcunx I am purely guessing here but (unless mutt has some really fragile networking code) a clean network shutdown on suspend seems somewhat unlikely here. Well, at least if it doesn't just happen so fast that mutt fails to recognize it before going to sleep. I mean it's not exactly far fetched to assume that mutt has some way to recognize when it's connection breaks. That doesn't seem to trigger though. So there either has to be some kind of code that ignores return codes turning something that should really wait for data into an eternal spinlock or said return codes are bogus (like select instantly returning without failure but no events despite timeout) and thus tricking mutt into thinking everything is fine. I somewhat lean to the second option as i have a hard time imagining something as well tested as mutt to blindly continue despite receiving errors.

That being said you bring up an interesting aspect: What about using said hooks to make sure the network is brought down cleanly? A simple test would be to bring the relevant interface down while mutt is running. If that also causes mutt to freak out there is something fishy going on with it but if not cleanly bringing down the interface on suspend might very well avoid waking up with a "ghost network" later.

rvp

nettester So there either has to be some kind of code that ignores return codes turning something that should really wait for data into an eternal spinlock or said return codes are bogus (like select instantly returning without failure but no events despite timeout) and thus tricking mutt into thinking everything is fine.

Another scenario is the system-time going backwards across a suspend, and mutt not expecting that to happen.

For example, see the raw_socket_poll() function in mutt_socket.c. It uses gettimeofday() pairs to (portably) determine if select() returned with a "short" sleep, and then compensate for that. The way it does this is fine in most cases--except if the second gettimeofday() returns a time before that of the first gettimeofday(). Then the code will sleep for much longer than anticipated.

gettimeofday() should not be used for monotonic time intervals. If you want a monotonic interval, the system generally provides a better one.

@szilard Please try this patch:

diff -urN mutt-2.2.10.orig/mutt_socket.c mutt-2.2.10/mutt_socket.c
--- mutt-2.2.10.orig/mutt_socket.c	2023-03-25 19:50:20.000000000 +0000
+++ mutt-2.2.10/mutt_socket.c	2023-07-21 14:10:02.712062000 +0000
@@ -517,7 +517,8 @@
 {
   fd_set rfds;
   unsigned long long wait_millis, post_t_millis;
-  struct timeval tv, pre_t, post_t;
+  struct timeval tv;
+  struct timespec pre_t, post_t;
   int rv;
 
   if (conn->fd < 0)
@@ -533,9 +534,9 @@
     FD_ZERO (&rfds);
     FD_SET (conn->fd, &rfds);
 
-    gettimeofday (&pre_t, NULL);
+    clock_gettime (CLOCK_MONOTONIC, &pre_t);
     rv = select (conn->fd + 1, &rfds, NULL, NULL, &tv);
-    gettimeofday (&post_t, NULL);
+    clock_gettime (CLOCK_MONOTONIC, &post_t);
 
     if (rv > 0 ||
         (rv < 0 && errno != EINTR))
@@ -545,9 +546,9 @@
       mutt_query_exit ();
 
     wait_millis += ((unsigned long long)pre_t.tv_sec * 1000ULL) +
-      (unsigned long long)(pre_t.tv_usec / 1000);
+      (unsigned long long)(pre_t.tv_nsec / (1000 * 1000));
     post_t_millis = ((unsigned long long)post_t.tv_sec * 1000ULL) +
-      (unsigned long long)(post_t.tv_usec / 1000);
+      (unsigned long long)(post_t.tv_nsec / (1000 * 1000));
     if (wait_millis <= post_t_millis)
       return 0;
     wait_millis -= post_t_millis;

EDIT: Upon reflection, this scenario would only result in unwanted sleeps, not the high CPU-loading you observed. So, compile mutt for debugging and run it in the debugger. We should be able to see what's spinning.