Since upgrading to version 3.9.2, Three or four times I have found Claws looping in the morning when I attempt to read overnight's email. "top" shows "claws" is at 99.x%. Claws is not responsive - and the only way to close it is by killing it. After bringing claws back up, it works as usual. No other running apps are affected. If you have any suggestions on how I can get you better information - other than a tight loop - please let me know.
Linux asrock 3.4.42-2.28-desktop #1 SMP PREEMPT Mon Apr 29 09:18:32 UTC 2013 (a7a14eb) x86_64 x86_64 x86_64 GNU/Linux Linux: openSUSE 12.2
what does the --debug info say at these times?
I'll turn --debug on...
Had this happen overnight -- very long time since I've had this sort of problem, so I don't run --debug. Tried to gather as much info as possible regardless, in case something helps... CM 3.9.2 had successfully checked 5 accounts. Log reports 136, 2, 7, 0, 0 messages on servers; but none new, so nothing received on this scan cycle. Then on 6th account, it logged this: [03:50:14] * message: Account 'account6': Connecting to POP3 server: pop.gmail.com:995... [03:50:14] POP3< +OK Gpop ready for requests from 69.40.59.38 bz6pf55457185qab.7 [03:50:14] POP3> USER account6@gmail.com No idea if the password was sent or not. There is very rarely mail received on this account; a moot point here since progress stopped before being able to check for mail. strace gives this tight loop sequence (no idea which is the loop beginning): fcntl(23, F_GETFL) = 0x802 (flags O_RDWR|O_NONBLOCK) recvfrom(7, 0x26c96e4, 4096, 0, 0, 0) = -1 EAGAIN (Resource temporarily unavailable) poll([{fd=8, events=POLLIN}, {fd=7, events=POLLIN}, {fd=9, events=POLLIN}, {fd=10, events=POLLIN}, {fd=15, events=POLLIN}, {fd=14, events=POLLIN}, {fd=17, events=POLLIN}, {fd=6, events=POLLIN|POLLPRI}], 8, 0) = 0 (Timeout) select(24, [23], NULL, NULL, {0, 0}) = 1 (in [23], left {0, 0}) recvfrom(7, 0x26c96e4, 4096, 0, 0, 0) = -1 EAGAIN (Resource temporarily unavailable) poll([{fd=8, events=POLLIN}, {fd=7, events=POLLIN}, {fd=9, events=POLLIN}, {fd=10, events=POLLIN}, {fd=15, events=POLLIN}, {fd=14, events=POLLIN}, {fd=17, events=POLLIN}, {fd=6, events=POLLIN|POLLPRI}], 8, 0) = 0 (Timeout) Hope the following gdb output is useful... near bottom, I walked up the stacks in case that helps. Attached gdb... fin_msg out of bounds seems to be potentially important here... other comments inline... (gdb) bt full #0 0x00007fdcbf99b520 in pthread_mutex_unlock@plt () from /lib64/libglib-2.0.so.0 No symbol table info available. #1 0x00007fdcbfa054b1 in g_mutex_unlock () from /lib64/libglib-2.0.so.0 No symbol table info available. #2 0x00007fdcbf9c99ad in g_main_context_check () from /lib64/libglib-2.0.so.0 No symbol table info available. #3 0x00007fdcbf9c9e46 in ?? () from /lib64/libglib-2.0.so.0 No symbol table info available. #4 0x00007fdcbf9c9fd4 in g_main_context_iteration () from /lib64/libglib-2.0.so.0 No symbol table info available. #5 0x00007fdcc359ff61 in gtk_main_iteration () from /lib64/libgtk-x11-2.0.so.0 No symbol table info available. #6 0x00000000004ab183 in folderview_check_new (folder=0x2d35cc0) at folderview.c:1184 str = 0x3c86910 "Scanning folder vCalendar/.meetings..." list = 0x28d3a60 item = 0x2d35f90 folderview = 0x28d4c00 ctree = 0x26d5400 node = 0x3024f00 new_msgs = 0 former_new_msgs = 0 former_new = 0 former_unread = 0 former_total = 32767 #7 0x00007fdcaed450b4 in vcal_webcal_check (data=0x0) at vcalendar.c:1309 root = 0x2d35cc0 #8 0x00007fdcbf9ca78b in ?? () from /lib64/libglib-2.0.so.0 No symbol table info available. #9 0x00007fdcbf9c9bc3 in g_main_context_dispatch () from /lib64/libglib-2.0.so.0 No symbol table info available. #10 0x00007fdcbf9c9f10 in ?? () from /lib64/libglib-2.0.so.0 No symbol table info available. #11 0x00007fdcbf9c9fd4 in g_main_context_iteration () from /lib64/libglib-2.0.so.0 No symbol table info available. #12 0x00007fdcc359ff61 in gtk_main_iteration () from /lib64/libgtk-x11-2.0.so.0 No symbol table info available. #13 0x00000000004cbfc9 in inc_pop3_session_do (session=0x3cb0410) at inc.c:864 pop3_session = 0x3a078c0 inc_dialog = 0x2d63270 server = 0x2a42c90 "pop.gmail.com" account_name = 0x2a42c70 "account6" port = 995 buf = 0x3c62850 "p\260\204\003" #14 0x00000000004cb5dd in inc_start (inc_dialog=0x2d63270) at inc.c:632 filtered = 0x0 unfiltered = 0x0 session = 0x3cb0410 qlist = 0x0 pop3_session = 0x3a078c0 inc_state = INC_SUCCESS error_num = 0 new_msgs = 0 msg = 0x35cb570 "UTF-8" fin_msg = 0x1e78546de <Address 0x1e78546de out of bounds> <============== processing = 0x2704970 inbox = 0x2b4f440 msglist = 0x0 msglist_element = 0x0 cancelled = 0 #15 0x00000000004caa76 in inc_all_account_mail (mainwin=0x276c000, autocheck=1, notify=0) at inc.c:403 list = 0x0 queue_list = 0x3e5ff00 inc_dialog = 0x2d63270 new_msgs = 0 account_new_msgs = 0 #16 0x00000000004cdcd1 in inc_autocheck_func (data=0x276c000) at inc.c:1559 mainwin = 0x276c000 #17 0x00007fdcbf9ca78b in ?? () from /lib64/libglib-2.0.so.0 No symbol table info available. #18 0x00007fdcbf9c9bc3 in g_main_context_dispatch () from /lib64/libglib-2.0.so.0 No symbol table info available. #19 0x00007fdcbf9c9f10 in ?? () from /lib64/libglib-2.0.so.0 No symbol table info available. #20 0x00007fdcbf9ca30a in g_main_loop_run () from /lib64/libglib-2.0.so.0 No symbol table info available. #21 0x00007fdcc359fd57 in gtk_main () from /lib64/libgtk-x11-2.0.so.0 No symbol table info available. #22 0x00000000004d0a8c in main (argc=1, argv=0x7fff8d7b3948) at main.c:1721 connection = 0x26e6088 error = 0x0 userrc = 0x26f00b0 "/home/pierre/.claws-mail/imapcache" <==== NEVER setup or used IMAP (in case) mainwin = 0x276c000 folderview = 0x28d4c00 icon = 0x2756c50 crash_file_present = 1 num_folder_class = 1 asked_for_migration = 0 start_done = 0 plug_list = 0x0 never_ran = 0 mainwin_shown = 1 start = {tv_sec = 1372060355, tv_usec = 386776} end = {tv_sec = 1372060359, tv_usec = 118195} diff = {tv_sec = 3, tv_usec = 731419} timing_name = 0x6e38d6 "startup" __FUNCTION__ = "main" ## trying to step gives... (gdb) next Single stepping until exit from function pthread_mutex_unlock@plt, which has no line number information. 0x00007fdcbe9279e0 in pthread_mutex_unlock () from /lib64/libpthread.so.0 (gdb) Single stepping until exit from function pthread_mutex_unlock, which has no line number information. 0x00007fdcbe927960 in __pthread_mutex_unlock_usercnt () from /lib64/libpthread.so.0 (gdb) Single stepping until exit from function __pthread_mutex_unlock_usercnt, which has no line number information. 0x00007fdcbfa054b1 in g_mutex_unlock () from /lib64/libglib-2.0.so.0 (gdb) Single stepping until exit from function g_mutex_unlock, which has no line number information. 0x00007fdcbf9c99ad in g_main_context_check () from /lib64/libglib-2.0.so.0 (gdb) Single stepping until exit from function g_main_context_check, which has no line number information. 0x00007fdcbf9c9e46 in ?? () from /lib64/libglib-2.0.so.0 (gdb) Cannot find bounds of current function ## each subsequent 'next' returns above bounds error; so... (gdb) cont Continuing. ## let CM loop for several seconds (~10-15) ^C Program received signal SIGINT, Interrupt. 0x00007fdcbf9c97ab in g_main_context_query () from /lib64/libglib-2.0.so.0 (gdb) bt full ## in this bt full, I've redacted those entries which have not changed from the above one. #0 0x00007fdcbf9c97ab in g_main_context_query () from /lib64/libglib-2.0.so.0 No symbol table info available. #1 0x00007fdcbf9c9e1a in ?? () from /lib64/libglib-2.0.so.0 No symbol table info available. #2 0x00007fdcbf9c9fd4 in g_main_context_iteration () from /lib64/libglib-2.0.so.0 No symbol table info available. #3 0x00007fdcc359ff61 in gtk_main_iteration () from /lib64/libgtk-x11-2.0.so.0 No symbol table info available. ##### #4 thru #20 in this bt full are identical to #6 thru #22 in previous one. ## Walking the stacks... (gdb) up #1 0x00007fdcbf9c9e1a in ?? () from /lib64/libglib-2.0.so.0 (gdb) up #2 0x00007fdcbf9c9fd4 in g_main_context_iteration () from /lib64/libglib-2.0.so.0 (gdb) #3 0x00007fdcc359ff61 in gtk_main_iteration () from /lib64/libgtk-x11-2.0.so.0 (gdb) #4 0x00000000004ab183 in folderview_check_new (folder=0x2d35cc0) at folderview.c:1184 1184 GTK_EVENTS_FLUSH(); (gdb) #5 0x00007fdcaed450b4 in vcal_webcal_check (data=0x0) at vcalendar.c:1309 1309 folderview_check_new(root); (gdb) #6 0x00007fdcbf9ca78b in ?? () from /lib64/libglib-2.0.so.0 (gdb) #7 0x00007fdcbf9c9bc3 in g_main_context_dispatch () from /lib64/libglib-2.0.so.0 (gdb) #8 0x00007fdcbf9c9f10 in ?? () from /lib64/libglib-2.0.so.0 (gdb) #9 0x00007fdcbf9c9fd4 in g_main_context_iteration () from /lib64/libglib-2.0.so.0 (gdb) #10 0x00007fdcc359ff61 in gtk_main_iteration () from /lib64/libgtk-x11-2.0.so.0 (gdb) #11 0x00000000004cbfc9 in inc_pop3_session_do (session=0x3cb0410) at inc.c:864 864 gtk_main_iteration(); (gdb) #12 0x00000000004cb5dd in inc_start (inc_dialog=0x2d63270) at inc.c:632 632 inc_state = inc_pop3_session_do(session); (gdb) #13 0x00000000004caa76 in inc_all_account_mail (mainwin=0x276c000, autocheck=1, notify=0) at inc.c:403 403 new_msgs += inc_start(inc_dialog); (gdb) #14 0x00000000004cdcd1 in inc_autocheck_func (data=0x276c000) at inc.c:1559 1559 inc_all_account_mail(mainwin, TRUE, prefs_common.newmail_notify_auto); (gdb) #15 0x00007fdcbf9ca78b in ?? () from /lib64/libglib-2.0.so.0 (gdb) #16 0x00007fdcbf9c9bc3 in g_main_context_dispatch () from /lib64/libglib-2.0.so.0 (gdb) #17 0x00007fdcbf9c9f10 in ?? () from /lib64/libglib-2.0.so.0 (gdb) #18 0x00007fdcbf9ca30a in g_main_loop_run () from /lib64/libglib-2.0.so.0 (gdb) #19 0x00007fdcc359fd57 in gtk_main () from /lib64/libgtk-x11-2.0.so.0 (gdb) #20 0x00000000004d0a8c in main (argc=1, argv=0x7fff8d7b3948) at main.c:1721 1721 gtk_main(); ## Walked back down, and tried stepping again... (gdb) next Single stepping until exit from function g_main_context_query, which has no line number information. 0x00007fdcbf9c9e1a in ?? () from /lib64/libglib-2.0.so.0 (gdb) Cannot find bounds of current function #### tried continuing again since this bug is likely hard to reproduce... This time, got this in the backtrace: (gdb) bt full #0 0x00007fdcbe448493 in select () from /lib64/libc.so.6 No symbol table info available. #1 0x000000000064b02d in ssl_sock_check (source=0x31de590) at socket.c:489 sock = 0x3598570 timeout = {tv_sec = 0, tv_usec = 0} fds = {__fds_bits = {8388608, 0 <repeats 15 times>}} condition = G_IO_IN #2 0x00007fdcbf9c99b3 in g_main_context_check () from /lib64/libglib-2.0.so.0 No symbol table info available. #3 0x00007fdcbf9c9e46 in ?? () from /lib64/libglib-2.0.so.0 No symbol table info available. #4 0x00007fdcbf9c9f6f in g_main_context_pending () from /lib64/libglib-2.0.so.0 No symbol table info available. #5 0x00007fdcc359ff29 in gtk_events_pending () from /lib64/libgtk-x11-2.0.so.0 No symbol table info available. #### remainder same as above ### Based on these stacks, it appears CM is doing various things; but keeps coming back to the code that's looping... HTH (gdb) up #1 0x000000000064b02d in ssl_sock_check (source=0x31de590) at socket.c:489 489 select(sock->sock + 1, (gdb) #2 0x00007fdcbf9c99b3 in g_main_context_check () from /lib64/libglib-2.0.so.0 (gdb) #3 0x00007fdcbf9c9e46 in ?? () from /lib64/libglib-2.0.so.0 (gdb) #4 0x00007fdcbf9c9f6f in g_main_context_pending () from /lib64/libglib-2.0.so.0 (gdb) #5 0x00007fdcc359ff29 in gtk_events_pending () from /lib64/libgtk-x11-2.0.so.0 (gdb) #6 0x00000000004ab188 in folderview_check_new (folder=0x2d35cc0) at folderview.c:1184 1184 GTK_EVENTS_FLUSH(); (gdb) #7 0x00007fdcaed450b4 in vcal_webcal_check (data=0x0) at vcalendar.c:1309 1309 folderview_check_new(root); (gdb) #8 0x00007fdcbf9ca78b in ?? () from /lib64/libglib-2.0.so.0 (gdb) #9 0x00007fdcbf9c9bc3 in g_main_context_dispatch () from /lib64/libglib-2.0.so.0 (gdb) #10 0x00007fdcbf9c9f10 in ?? () from /lib64/libglib-2.0.so.0 (gdb) #11 0x00007fdcbf9c9fd4 in g_main_context_iteration () from /lib64/libglib-2.0.so.0 (gdb) #12 0x00007fdcc359ff61 in gtk_main_iteration () from /lib64/libgtk-x11-2.0.so.0 (gdb) #13 0x00000000004cbfc9 in inc_pop3_session_do (session=0x3cb0410) at inc.c:864 864 gtk_main_iteration(); (gdb) #14 0x00000000004cb5dd in inc_start (inc_dialog=0x2d63270) at inc.c:632 632 inc_state = inc_pop3_session_do(session); (gdb) #15 0x00000000004caa76 in inc_all_account_mail (mainwin=0x276c000, autocheck=1, notify=0) at inc.c:403 403 new_msgs += inc_start(inc_dialog); (gdb) #16 0x00000000004cdcd1 in inc_autocheck_func (data=0x276c000) at inc.c:1559 1559 inc_all_account_mail(mainwin, TRUE, prefs_common.newmail_notify_auto); (gdb) #17 0x00007fdcbf9ca78b in ?? () from /lib64/libglib-2.0.so.0 (gdb) #18 0x00007fdcbf9c9bc3 in g_main_context_dispatch () from /lib64/libglib-2.0.so.0 (gdb) #19 0x00007fdcbf9c9f10 in ?? () from /lib64/libglib-2.0.so.0 (gdb) #20 0x00007fdcbf9ca30a in g_main_loop_run () from /lib64/libglib-2.0.so.0 (gdb) #21 0x00007fdcc359fd57 in gtk_main () from /lib64/libgtk-x11-2.0.so.0 (gdb) #22 0x00000000004d0a8c in main (argc=1, argv=0x7fff8d7b3948) at main.c:1721 1721 gtk_main();
Ever since I started logging, Claws hasn't failed with the loop issue. Bummer...
Since I hadn't experienced a loop in a LONG time, figured I'd better get the most info possible, even without symbols in case there's enough of a clue... at least I know my loop occurred which checking the 6th of 7 accounts (all dry POP3 polls), in the middle of the night while I slept... HTH
Before I started logging everything, claws would hang up in a loop overnight a couple of times a week. (As I noted in my original bug submission, the looping failure always occurs over night - never during regular business hours). As per my previous comment - claws hasn't failed once since I began logging. I'm beginning to suspect that logging is changing the timing and/or some interaction sufficiently to cause the bug to "disappear".
lbickley, does your provider disconnent you every 24h and does this happen in the night? Never had that issue, only using IMAP accounts. > Attached gdb... fin_msg out of bounds seems to be potentially important here... other comments inline... Agree, cannot check as inc_start / inc_pop3_session_do not used here. folderview_check_new seems interesting to me. > userrc = 0x26f00b0 "/home/pierre/.claws-mail/imapcache" <==== NEVER userrc = 0x84eadd0 "/home/kardan/.claws-mail/newscache <- here
Created attachment 1279 [details] tail -10000 of long claws.log
I just sent a tail -10000 of my log file after a tight loop! On reviewing my first emails this morning, I moved an email from one folder to another - and claws hung in a tight loop. I let it run for several minutes and then killed it with a kill -9. I didn't send the entire log as it is now 113981154 long! If you want the whole log, I can post it to an FTP site for you to pick up. This bug is not the same as the hangs I experienced without an email move - but hopefully this post and log still provide good info. In response to an prior question: My ISP does not regularly reboot once a night. We monitor all the services we received from our ISP: DNS, SMTP, etc. - and typically we see a "glitch" of five minutes or so every week to a month. We do not use IMAP - but have POP accounts (with and without SSL, etc.). Cheers, Lyle
i don't see anything relevant in the attached log
I think I'll stop logging. Ever since I started logging, the hang (loop) has not occurred. It will be interesting to see of the problem reappears... Lyle
now news for a month, assuming 'resolved'. re-open if you have some further relevant info on this.