Re: Problem with IMAP Server and Header Cache
On Wed, Jan 25, 2023 at 10:13:58PM +0100, Christian Brabandt wrote: No. I mean it happens whenever mutt quits (or has been forcefully shutdown). Sometimes I also notice a normal quit takes very long (I assume it somehow writes/updates the header cache and this may also take a while?) I can "fix" it by manually deleting the header cache, but then mutt starts loading all those messages again and it again takes a bit until the mailbox is open. Hmmm... I see in the log that even in the "working" case it's taking a good 15 seconds to load in the messages from the seqset/header cache. It's a big mailbox, though, so maybe that's to be expected. I noticed you are using 1.13.2. Are you in a position to try building a newer version of mutt? There have been several important fixes to QRESYNC since then (including a bug in the seqset iterator). It doesn't *look* like that's the issue here, but it would still be a good idea to try 2.2.9 if possible. While you are at it, you might also try building with a different header cache backend. Perhaps tokyocabinet is having issues. I would suggest kyotocabinet or perhaps lmdb and see how they work. On ubuntu, just run $ sudo apt build-dep mutt $ sudo apt install libkyotocabinet-dev liblmdb-dev $ ./configure --enable-compressed --enable-debug --enable-fcntl \ --enable-hcache --enable-gpgme --enable-imap --enable-smtp \ --enable-pop --enable-sidebar --with-curses --with-gnutls \ --with-gss --with-idn --with-sasl \ --with-kyotocabinet (or --with-lmdb) $ make $ sudo make install -- Kevin J. McCarthy GPG Fingerprint: 8975 A9B3 3AA3 7910 385C 5308 ADEF 7684 8031 6BDA signature.asc Description: PGP signature
Re: Problem with IMAP Server and Header Cache
On Mi, 25 Jan 2023, Kevin J. McCarthy wrote: > On Wed, Jan 25, 2023 at 07:54:49PM +0100, Christian Brabandt wrote: > > For some reason, whenever mutt disconnects and I want it to reload a > > mailbox with 100k messages in it, it usually hangs for very long until > > it finally disconnects. > > Do you mean this only happens after a disconnect within mutt, and only when > you try to reopen the same mailbox without closing mutt? Or does > this happen in other circumstances too. No. I mean it happens whenever mutt quits (or has been forcefully shutdown). Sometimes I also notice a normal quit takes very long (I assume it somehow writes/updates the header cache and this may also take a while?) I can "fix" it by manually deleting the header cache, but then mutt starts loading all those messages again and it again takes a bit until the mailbox is open. > > It's possible to re-connect and then it seems to load the mailbox just > > fine. > > It would be interesting to see the debug log for that same section when it > "works". (Up until the "Fetching flag updates..." part). > > My first guess is that the seqset is corrupted somehow, or perhaps the > header cache has a problem, but that wouldn't explain why it sometimes > works. Let me see what I can do for you :) [...] [2023-01-25 19:55:22] Reorder: x = 0; hdr_count = 1 [2023-01-25 19:55:22] Reorder: x = 0; hdr_count = 1 [2023-01-25 19:55:22] Reorder: x = 0; hdr_count = 1 [2023-01-25 19:55:22] Reorder: x = 0; hdr_count = 1 [2023-01-25 19:55:22] New mail in =github, =vim, =opensuse, =zsh-users, =git, =oss-security, =Trash, =AKV, =spam [2023-01-25 19:55:23] Copying 8 messages to Trash... [2023-01-25 19:55:23] 4> DONE^M a0195 UID COPY 59266:59267,59269:59274 "Trash"^M [2023-01-25 19:55:23] 4< a0194 OK Idle completed (9.408 + 9.408 + 9.408 secs). [2023-01-25 19:55:23] 4< a0195 OK [COPYUID 1384369013 59266:59267,59269:59274 204042:204049] Copy completed (0.235 + 0.000 + 0.234 secs). [2023-01-25 19:55:23] 4> a0196 IDLE^M [2023-01-25 19:55:23] 4< + idling [2023-01-25 19:55:23] Marking 9 messages deleted... [2023-01-25 19:55:23] 5671 kept, 9 deleted. [2023-01-25 19:55:24] Reading configuration file '/home/chrisbra/.mutt/profile.256bit.de'. [2023-01-25 19:55:24] Reading imap://localhost/github... [2023-01-25 19:55:24] Selecting github... [2023-01-25 19:55:24] 4> DONE^M a0197 UID STORE 59266:59274 +FLAGS.SILENT (\Deleted)^M a0198 CLOSE^M a0199 STATUS "Entwurf" (MESSAGES)^M a0200 SELECT "github" (CONDSTORE)^M [2023-01-25 19:55:24] 4< a0196 OK Idle completed (1.130 + 1.129 + 1.129 secs). [2023-01-25 19:55:24] 4< * 5672 FETCH (UID 59266 MODSEQ (28292)) [2023-01-25 19:55:24] 4< * 5673 FETCH (UID 59267 MODSEQ (28292)) [2023-01-25 19:55:24] 4< * 5674 FETCH (UID 59268 MODSEQ (28292)) [2023-01-25 19:55:24] 4< * 5675 FETCH (UID 59269 MODSEQ (28292)) [2023-01-25 19:55:24] 4< * 5676 FETCH (UID 59270 MODSEQ (28292)) [2023-01-25 19:55:24] 4< * 5677 FETCH (UID 59271 MODSEQ (28292)) [2023-01-25 19:55:24] 4< * 5678 FETCH (UID 59272 MODSEQ (28292)) [2023-01-25 19:55:24] 4< * 5679 FETCH (UID 59273 MODSEQ (28292)) [2023-01-25 19:55:24] 4< * 5680 FETCH (UID 59274 MODSEQ (28292)) [2023-01-25 19:55:24] 4< a0197 OK Store completed (0.001 + 0.000 secs). [2023-01-25 19:55:25] 4< a0198 OK Close completed (0.064 + 0.000 + 0.063 secs). [2023-01-25 19:55:25] 4< * STATUS Entwurf (MESSAGES 0) [2023-01-25 19:55:25] 4< a0199 OK Status completed (0.001 + 0.000 secs). [2023-01-25 19:55:25] 4< * FLAGS (\Answered \Flagged \Deleted \Seen \Draft $Forwarded) [2023-01-25 19:55:25] 4< * OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft $Forwarded \*)] Flags permitted. [2023-01-25 19:55:25] 4< * 113684 EXISTS [2023-01-25 19:55:25] Handling EXISTS [2023-01-25 19:55:25] cmd_handle_untagged: New mail in github - 113684 messages total. [2023-01-25 19:55:25] 4< * 0 RECENT [2023-01-25 19:55:25] 4< * OK [UNSEEN 4] First unseen. [2023-01-25 19:55:25] 4< * OK [UIDVALIDITY 1384369187] UIDs valid [2023-01-25 19:55:25] 4< * OK [UIDNEXT 351160] Predicted next UID [2023-01-25 19:55:25] 4< * OK [HIGHESTMODSEQ 166533] Highest [2023-01-25 19:55:25] 4< a0200 OK [READ-WRITE] Select completed (0.002 + 0.000 + 0.001 secs). [2023-01-25 19:55:25] imap_cmd_finish: Fetching new mail [2023-01-25 19:55:25] Fetching message headers... 0 [2023-01-25 19:55:25] Reading uid seqset from header cache [2023-01-25 19:55:42] Fetching flag updates... 0/113684 (0%) [2023-01-25 19:55:42] 4> a0201 UID FETCH 1:351159 (FLAGS) (CHANGEDSINCE 166043 VANISHED)^M [2023-01-25 19:55:43] 4< * VANISHED (EARLIER) 1:220747,220749:227153,227155:227211,227213:227885,227887:227910,227914,227916:227917,227921:236315,236938:236941,238724,238726:238727,238731,238734,238748,238751,238915,239394:239397,239520:239521,239524,239545,239547,239550,239552,239554,239556:239557,240023,240094:240096+,240195:240196,242193:242195,242237:242240,242246,242249:242250,242262:242263,242267:242269,242298,242300,242303,242310:242311,242453:242454,242458:242459,2
Re: Problem with IMAP Server and Header Cache
On Wed, Jan 25, 2023 at 07:54:49PM +0100, Christian Brabandt wrote: For some reason, whenever mutt disconnects and I want it to reload a mailbox with 100k messages in it, it usually hangs for very long until it finally disconnects. Do you mean this only happens after a disconnect within mutt, and only when you try to reopen the same mailbox without closing mutt? Or does this happen in other circumstances too. It's possible to re-connect and then it seems to load the mailbox just fine. It would be interesting to see the debug log for that same section when it "works". (Up until the "Fetching flag updates..." part). My first guess is that the seqset is corrupted somehow, or perhaps the header cache has a problem, but that wouldn't explain why it sometimes works. -- Kevin J. McCarthy GPG Fingerprint: 8975 A9B3 3AA3 7910 385C 5308 ADEF 7684 8031 6BDA signature.asc Description: PGP signature
Problem with IMAP Server and Header Cache
Hey, I am using mutt usually in a long running screen session to read mail from a local IMAP server (Dovecoat in this case). For some reason, whenever mutt disconnects and I want it to reload a mailbox with 100k messages in it, it usually hangs for very long until it finally disconnects. It's possible to re-connect and then it seems to load the mailbox just fine. I have lived with that problem for some time already, but today I thought, it might make sense to actually create a muttdebug file, so here I am :) This is an extract of the muttdebug file: [2023-01-25 11:44:17] 4< * STATUS Drafts (RECENT 0 UIDNEXT 2 UIDVALIDITY 1464715206 UNSEEN 0) [2023-01-25 11:44:17] 4< a0075 OK Status completed (0.001 + 0.000 secs). [2023-01-25 11:44:19] mutt_complete: completing =git [2023-01-25 11:44:19] 4> a0076 LIST "" "git%"^M [2023-01-25 11:44:19] 4< * LIST (\HasNoChildren \UnMarked) "." git [2023-01-25 11:44:19] 4< * LIST (\HasNoChildren \UnMarked) "." github [2023-01-25 11:44:19] 4< a0076 OK List completed (0.001 + 0.000 secs). [2023-01-25 11:44:20] mutt_complete: completing =gith [2023-01-25 11:44:20] 4> a0077 LIST "" "gith%"^M [2023-01-25 11:44:20] 4< * LIST (\HasNoChildren \UnMarked) "." github [2023-01-25 11:44:20] 4< a0077 OK List completed (0.001 + 0.000 secs). [2023-01-25 11:44:20] Mailbox is unchanged. [2023-01-25 11:44:21] Reading configuration file '/home/chrisbra/.mutt/profile.256bit.de'. [2023-01-25 11:44:22] Reading imap://localhost/github... [2023-01-25 11:44:22] Selecting github... [2023-01-25 11:44:22] 4> a0078 CLOSE^M a0079 STATUS "Entwurf" (MESSAGES)^M a0080 SELECT "github" (CONDSTORE)^M [2023-01-25 11:44:22] 4< a0078 OK Close completed (0.001 + 0.000 secs). [2023-01-25 11:44:22] 4< * STATUS Entwurf (MESSAGES 0) [2023-01-25 11:44:22] 4< a0079 OK Status completed (0.001 + 0.000 secs). [2023-01-25 11:44:22] 4< * FLAGS (\Answered \Flagged \Deleted \Seen \Draft $Forwarded) [2023-01-25 11:44:22] 4< * OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft $Forwarded \*)] Flags permitted. [2023-01-25 11:44:22] 4< * 113560 EXISTS [2023-01-25 11:44:22] Handling EXISTS [2023-01-25 11:44:22] cmd_handle_untagged: New mail in github - 113560 messages total. [2023-01-25 11:44:22] 4< * 0 RECENT [2023-01-25 11:44:22] 4< * OK [UNSEEN 4] First unseen. [2023-01-25 11:44:22] 4< * OK [UIDVALIDITY 1384369187] UIDs valid [2023-01-25 11:44:22] 4< * OK [UIDNEXT 351036] Predicted next UID [2023-01-25 11:44:22] 4< * OK [HIGHESTMODSEQ 166330] Highest [2023-01-25 11:44:22] 4< a0080 OK [READ-WRITE] Select completed (0.001 + 0.000 secs). [2023-01-25 11:44:22] Reading uid seqset from header cache [2023-01-25 14:24:42] Fetching flag updates... 0/113560 (0%) [2023-01-25 14:24:42] 4> a0081 UID FETCH 1:351000 (FLAGS) (CHANGEDSINCE 166043 VANISHED)^M [2023-01-25 14:24:42] 4< * BYE Disconnected for inactivity. [2023-01-25 14:24:42] Handling BYE [2023-01-25 14:24:42] Disconnected for inactivity. [2023-01-25 14:24:44] Fetching message headers... 0/113560 (0%) [2023-01-25 14:24:44] Error opening mailbox [2023-01-25 14:24:45] In mutt_reflow_windows [2023-01-25 19:47:18] In mutt_reflow_windows As you can see, mutt seems to be busy reading the header-cache file until the server finally disconnects. Any idea on how to fix this issue or work-around it? Mutt version below, should come straight from Ubuntu 20.04. Thanks, Chris #v+ chrisbra@256bit:~$ mutt -v Mutt 1.13.2 (2019-12-18) Copyright (C) 1996-2016 Michael R. Elkins and others. Mutt comes with ABSOLUTELY NO WARRANTY; for details type `mutt -vv'. Mutt is free software, and you are welcome to redistribute it under certain conditions; type `mutt -vv' for details. System: Linux 5.4.0-137-generic (x86_64) ncurses: ncurses 6.2.20200212 (compiled with 6.2) libidn: 1.33 (compiled with 1.33) hcache backend: tokyocabinet 1.4.48 Compiler: Using built-in specs. COLLECT_GCC=gcc COLLECT_LTO_WRAPPER=/usr/lib/gcc/x86_64-linux-gnu/9/lto-wrapper OFFLOAD_TARGET_NAMES=nvptx-none:hsa OFFLOAD_TARGET_DEFAULT=1 Target: x86_64-linux-gnu Configured with: ../src/configure -v --with-pkgversion='Ubuntu 9.4.0-1ubuntu1~20.04.1' --with-bugurl=file:///usr/share/doc/gcc-9/README.Bugs --enable-languages=c,ada,c++,go,brig,d,fortran,objc,obj-c++,gm2 --prefix=/usr --with-gcc-major-version-only --program-suffix=-9 --program-prefix=x86_64-linux-gnu- --enable-shared --enable-linker-build-id --libexecdir=/usr/lib --without-included-gettext --enable-threads=posix --libdir=/usr/lib --enable-nls --enable-clocale=gnu --enable-libstdcxx-debug --enable-libstdcxx-time=yes --with-default-libstdcxx-abi=new --enable-gnu-unique-object --disable-vtable-verify --enable-plugin --enable-default-pie --with-system-zlib --with-target-system-zlib=auto --enable-objc-gc=auto --enable-multiarch --disable-werror --with-arch-32=i686 --with-abi=m64 --with-multilib-list=m32,m64,mx32 --enable-multilib --with-tune=generic --enable-offload-targets=nvptx-none=/build/gcc-9-Av3uEd/gcc-9-9.4.0/debian/tmp-nvptx/usr,hsa
