[Users] Periodic "connection failed"

Wed Aug 28 13:01:55 CEST 2013

On Wed, Aug 28, 2013 at 04:35:35AM +0100, Paul wrote:

> > Where in the debug message does it report that it tried but failed
> > to engage the mail server? I must have missed it. 
> 
> There is no connection attempt at all in the debug info you sent, but
> in your original message you reported "Connection failed".

I guess I misunderstand something. I find I originally set Claws up to do
an auto retrieval every five minutes, which probably accounts for its
retrieval of messages once in a while on its own (it seems to suceed after
days of trying almost by accident). In the debug message I attached to my
last two messages, I hit the "Get Mail" while debug was running and waited
for a time out, and then sent a message (sent the debut to my own
computer). 

Shouldn't then the debug message contains lines showing it trying to reach
the server, but failing because the connection failed? I believe a recall
lines saying it reached the server to send my message, but I didn't see
lines for my attempt to retrieve them.

Perhaps I misled you. When I do hit the "Get Messages" button, the button
greys out for what seems a long time and then a GUI dialog pops up with the
ERROR message saying "Connection failed" I was not trying to report a line
in the debug message in my original message.

> Also, the method you used to attach the debug is inconvenient - I
> have to drag and drop the attachment to a folder in order for Claws
> to do the work of decoding the message part. Just attach the part,
> (the debug text), not the whole message.

Sorry about that. The debug message I sent from my wife's machine to my own
was plain ASCII, but when attached to my mail ended up binary (C++). I look
again at the debug. I append it here, followed by some questions. 

-----------

claws.c:101:Starting Claws Mail version Claws Mail 3.7.6
main.c:839:runtime GTK+ 2.20.1 / GLib 2.24.2
main.c:847:buildtime GTK+ 2.20.1 / GLib 2.24.2
main.c:856:Compiled-in features:
main.c:861: compface
main.c:867: aspell
main.c:873: gnutls
main.c:879: ipv6
main.c:885: iconv
main.c:891: jpilot
main.c:897: ldap
main.c:903: libetpan 0.58
main.c:909: libsm
main.c:915: NetworkManager
prefs_gtk.c:1037:new file '/home/gloria/.claws-mail/clawsrc'
prefs_gtk.c:996:new section 'Common'
prefs_gtk.c:1037:new file '/home/gloria/.claws-mail/folderitemrc'
prefs_gtk.c:975:cache: /home/gloria/.claws-mail/folderitemrc: No such file or
+directory
prefs_gtk.c:1075:destroying cache
main.c:2507:/dev/mem_notify not available (No such file or directory)
hooks.c:70:registed new hook for 'folder_item_update' as id 1
hooks.c:70:registed new hook for 'folder_update' as id 1
current dir: /home/gloria/.claws-mail
current dir: /home/gloria
folder.c:121:registering folder class mh
folder.c:121:registering folder class imap
folder.c:121:registering folder class news
prefs_gtk.c:85:Reading configuration...
prefs_gtk.c:122:Found [Common]
prefs_gtk.c:147:Finished reading configuration.
prefs_themes.c:372:Creating preferences for themes...
stock_pixmap.c:496:dir /home/gloria/.claws-mail/themes not found, skipping theme
+scanstock_pixmap.c:496:dir /usr/share/claws-mail/themes not found, skipping
+theme scanprefs_actions.c:437:Reading actions configurations...
prefs_display_header.c:420:Reading configuration for displaying headers...
addressbook.c:4148:Reading address index...
addressbook.c:4197:done.
mainwindow.c:1540:Creating main window...
toolbar.c:705:read Toolbar Configuration from toolbar_main.xml
folderview.c:577:Creating folder view...
folderview.c:412:creating tree...
hooks.c:70:registed new hook for 'folder_update' as id 2
hooks.c:70:registed new hook for 'folder_item_update' as id 2
summaryview.c:517:Creating summary view...
hooks.c:70:registed new hook for 'msginfo_update' as id 1
hooks.c:70:registed new hook for 'folder_item_update' as id 3
hooks.c:70:registed new hook for 'folder_update' as id 3
messageview.c:360:Creating message view...
headerview.c:83:Creating header view...
noticeview.c:73:Creating notice view...
mimeview.c:267:Creating MIME view...
noticeview.c:73:Creating notice view...
textview.c:263:Creating text view...
hooks.c:70:registed new hook for 'msginfo_update' as id 2
logwindow.c:87:Creating log window...
hooks.c:70:registed new hook for 'log_append_text' as id 1
logwindow.c:87:Creating log window...
hooks.c:70:registed new hook for 'debug_append_text' as id 1
mainwindow.c:2185:done.
mainwindow.c:3624:Setting widgets... mainwindow.c:3836:done.
hooks.c:70:registed new hook for 'sslcert_ask' as id 1
hooks.c:70:registed new hook for 'progressindicator_hooklist' as id 1
main.c:2627:Failed to get state info from NetworkManager: The name
+org.freedesktop.NetworkManager was not provided by any .service files
main.c:2576:Failed to get online information from NetworkManager: The name
+org.freedesktop.NetworkManager was not provided by any .service files
hooks.c:70:registed new hook for 'sslcert_get_client_cert' as id 1
hooks.c:70:registed new hook for 'sslcert_get_password' as id 1
account.c:199:Reading all config for each account...
account.c:214:Found label: Account: 1
codeconv.c:1481:current locale: en_US.utf8
prefs_gtk.c:85:Reading configuration...
prefs_gtk.c:122:Found [Account: 1]
prefs_gtk.c:147:Finished reading configuration.
prefs_gtk.c:85:Reading configuration...
prefs_gtk.c:122:Found [Account: 1]
prefs_gtk.c:147:Finished reading configuration.
prefs_gtk.c:85:Reading configuration...
prefs_gtk.c:122:Found [Account: 1]
prefs_gtk.c:147:Finished reading configuration.
prefs_gtk.c:85:Reading configuration...
prefs_gtk.c:122:Found [Account: 1]
prefs_gtk.c:147:Finished reading configuration.
prefs_gtk.c:85:Reading configuration...
prefs_gtk.c:122:Found [Account: 1]
prefs_gtk.c:147:Finished reading configuration.
prefs_gtk.c:85:Reading configuration...
prefs_gtk.c:122:Found [Account: 1]
prefs_gtk.c:147:Finished reading configuration.
prefs_gtk.c:85:Reading configuration...
prefs_gtk.c:122:Found [Account: 1]
prefs_gtk.c:147:Finished reading configuration.
prefs_gtk.c:85:Reading configuration...
prefs_gtk.c:122:Found [Account: 1]
prefs_gtk.c:147:Finished reading configuration.
prefs_customheader.c:332:Reading custom header configuration...
folderview.c:325:setting titles...
folderview.c:739:called inc_lock (lock count 1)
folderview.c:740:Setting folder info...
folderview.c:766:called inc_unlock (lock count 0)
summaryview.c:1133:called inc_lock (lock count 1)
summaryview.c:1206:empty folder ((nil) (null) (nil) 0)

summaryview.c:1217:called inc_unlock (lock count 0)
summaryview.c:1227:TIMING summary_show : 0s000ms
prefs_gtk.c:85:Reading configuration...
prefs_gtk.c:85:Reading configuration...
prefs_gtk.c:85:Reading configuration...
prefs_gtk.c:85:Reading configuration...
prefs_gtk.c:85:Reading configuration...
folder.c:1208:Counting total number of messages...
main.c:965:The name com.google.code.Awn was not provided by any .service files
folderview.c:739:called inc_lock (lock count 1)
folderview.c:740:Setting folder info...
msgcache.c:602: Reading swapped message cache from
+/home/gloria/Mail/queue/.claws_cache...
msgcache.c:618:using Noop Converter
msgcache.c:790:done. (0 items read)
msgcache.c:791:Cache size: 0 messages, 0 bytes
msgcache.c:821:reading swapped mark file.
msgcache.c:907:reading swapped tags file.
folder.c:2680:TIMING folder_item_read_cache : 0s000ms
folder.c:2541:Total cache memory usage: 0
msgcache.c:274:TIMING msgcache_get_msg_list : 0s000ms
folderview.c:766:called inc_unlock (lock count 0)
folderview.c:739:called inc_lock (lock count 1)
folderview.c:740:Setting folder info...
msgcache.c:274:TIMING msgcache_get_msg_list : 0s000ms
folderview.c:766:called inc_unlock (lock count 0)
inc.c:1506:added timer = 103
prefs_gtk.c:1072:no cache
main.c:1659:TIMING main startup: 0s264ms
inc.c:1522:removed timer = 103
progressdialog.c:61:Creating progress dialog...
inc.c:774:getting new messages of account
+gloria at gloriabrownministry.net@mail.gloriabrownministry.net:110...
folder.c:4230:tmpparentroot /home/gloria/.claws-mail/tempfolder
folder.c:4250:*TMP* already created
folder.c:2122:Scanning folder processing for cache changes.
mh.c:289:mh_get_num_list(): Scanning processing ...
current dir: /home/gloria/.claws-mail/tempfolder/processing
mh.c:1463:MH: forced mtime of processing to 1377464448
msgcache.c:602: Reading swapped message cache from
+/home/gloria/.claws-mail/tempfolder/processing/.claws_cache...
msgcache.c:618:using Noop Converter
msgcache.c:790:done. (0 items read)
msgcache.c:791:Cache size: 0 messages, 0 bytes
msgcache.c:821:reading swapped mark file.
msgcache.c:907:reading swapped tags file.
folder.c:2680:TIMING folder_item_read_cache : 0s000ms
folder.c:2541:Total cache memory usage: 0
msgcache.c:274:TIMING msgcache_get_msg_list : 0s000ms
msgcache.c:274:TIMING msgcache_get_msg_list : 0s000ms
filtering.c:189:checking 0 messages
alertpanel.c:252:Creating alert panel dialog...
alertpanel.c:211:called inc_lock (lock count 1)
alertpanel.c:221:called inc_unlock (lock count 0)
alertpanel.c:106:return value = 1
mh.c:231:MH scan not required: /home/gloria/.claws-mail/tempfolder/processing
+(1377464448 <= 1377464448)
folder.c:2705:Save cache for folder #mh/TEMP_FOLDER/processing
msgcache.c:1169:        Writing message cache to (null) and (null)...
msgcache.c:1250:done.
msgcache.c:1251:TIMING msgcache_write : 0s000ms
mh.c:1463:MH: forced mtime of processing to 1377464448
session.c:225:session (0xa38f0a8): destroyed
inc.c:1506:added timer = 318
folderview.c:2125:newly selected 0xa36f3a0, opened (nil)
folderview.c:2171:Folder inbox is selected
folderview.c:2187:Opening Folder inbox...
mh.c:231:MH scan not required: /home/gloria/Mail/inbox (1377537797 <=
+1377537797)
msgcache.c:602: Reading swapped message cache from
+/home/gloria/Mail/inbox/.claws_cache...
msgcache.c:618:using Noop Converter
msgcache.c:790:done. (83 items read)
msgcache.c:791:Cache size: 83 messages, 39142 bytes
msgcache.c:821:reading swapped mark file.
msgcache.c:907:reading swapped tags file.
folder.c:2680:TIMING folder_item_read_cache : 0s000ms
folder.c:2541:Total cache memory usage: 39142
msgcache.c:274:TIMING msgcache_get_msg_list : 0s000ms
folder.c:2012:TIMING folder_item_open : 0s000ms
summaryview.c:1027:showing From , must show From
summaryview.c:1133:called inc_lock (lock count 1)
summaryview.c:1239:Scanning folder (inbox)...
msgcache.c:274:TIMING msgcache_get_msg_list : 0s000ms
summaryview.c:1108:TIMING summary_check_consistency : 0s000ms
summaryview.c:1354:TIMING summary_show removing hidden: 0s000ms
summaryview.c:2964:     Setting summary from message data...
procmsg.c:283:TIMING procmsg_get_thread_tree thread by subject: 0s000ms
procmsg.c:290:TIMING procmsg_get_thread_tree : 0s001ms
summaryview.c:3001:TIMING summary_set_ctree_from_list threaded: 0s001ms
summaryview.c:3048:done.
summaryview.c:3051:     msgid hash table size = 83
summaryview.c:3054:     subject hash table size = 0
summaryview.c:2851:Sorting summary...summaryview.c:2865:done.
summaryview.c:2872:TIMING summary_sort : 0s009ms
summaryview.c:3070:TIMING summary_set_ctree_from_list bold_unread: 0s000ms
summaryview.c:3075:TIMING summary_set_ctree_from_list : 0s012ms
summaryview.c:1487:
summaryview.c:1492:called inc_unlock (lock count 0)
summaryview.c:1493:TIMING summary_show : 0s120ms
folder.c:2541:Total cache memory usage: 39142
folderview.c:2247:TIMING folderview_selected : 0s136ms
folderview.c:2125:newly selected 0xa36f3a0, opened 0xa36f3a0
folderview.c:2129:TIMING folderview_selected : 0s000ms
compose.c:7055:Creating compose window...
toolbar.c:705:read Toolbar Configuration from toolbar_compose.xml
addr_compl.c:300:read 2 items in (null)
addr_compl.c:361:start_address_completion((null)) ref count 1
gtkaspell.c:635:Aspell: Created a new gtkaspeller 0xa48c750
gtkaspell.c:643:Aspell: number of existing checkers 1
gtkaspell.c:431:Aspell: created gtkaspell 0xa4a0ca0
gtkaspell.c:1532:Aspell: found dictionary en_PH en_PH
gtkaspell.c:1532:Aspell: found dictionary en_US en_US
gtkaspell.c:1532:Aspell: found dictionary en en
gtkaspell.c:1532:Aspell: found dictionary en_CA en_CA
gtkaspell.c:1532:Aspell: found dictionary en_GB en_GB
template.c:162:template.c:163 reading templates dir
+/home/gloria/.claws-mail/templates
alertpanel.c:252:Creating alert panel dialog...
alertpanel.c:211:called inc_lock (lock count 1)
alertpanel.c:221:called inc_unlock (lock count 0)
alertpanel.c:106:return value = 0
compose.c:5047:called inc_unlock (lock count 0)
compose.c:4932:called inc_lock (lock count 1)
compose.c:5667:queueing message...
compose.c:5711:queuing to /home/gloria/.claws-mail/tmp/queue.0xa436a3049026e4f
codeconv.c:1481:current locale: en_US.utf8
compose.c:6020:Adding To-fields
compose.c:6020:Adding Newsgroups-fields
compose.c:6020:Adding Cc-fields
compose.c:6020:Adding Bcc-fields
utils.c:2092:domain name = gloria.histomat.net
compose.c:6020:Adding Followup-To-fields
compose.c:6020:Adding Reply-To-fields
autofaces.c:41:header content file
+'xface.gloria at gloriabrownministry.net@mail.gloriabrownministry.net_110' not
+found
autofaces.c:41:header content file 'xface' not found
autofaces.c:41:header content file
+'face.gloria at gloriabrownministry.net@mail.gloriabrownministry.net_110' not
+found
autofaces.c:41:header content file 'face' not found
compose.c:5386:src encoding = UTF-8, out encoding = US-ASCII, transfer encoding
+= 7bit
compose.c:5445:main text: 0 bytes encoded as US-ASCII in 0

--------------

That's the debug in its entirety. My questions:

There's a blank line. Never seen that in debug messages. It is normal?

As mentionted before, I don't use a Network Manager, but set up
/etc/network/interfacs manually.

Is the lines below, is Claws counting messages on the server or in a local
folder? In either case, why is it 0 count? If the server, at least it
should see my test message to the machine. No idea what the second line
means. 

  folder.c:1208:Counting total number of messages...
  main.c:965:The name com.google.code.Awn was not provided by any .service \
  	files
  ...
  msgcache.c:790:done. (0 items read)

A bit later are the following lines an attempt to download messages? Is
this the result of my having hit the GUI "Get Mail" button during the
debug? The address is correct.

  main.c:1659:TIMING main startup: 0s264ms
  inc.c:1522:removed timer = 103
  progressdialog.c:61:Creating progress dialog...
  inc.c:774:getting new messages of account
  +gloria at gloriabrownministry.net@mail.gloriabrownministry.net:110...
  folder.c:4230:tmpparentroot /home/gloria/.claws-mail/tempfolder
  folder.c:4250:*TMP* already created

Subsequently I composed a message to mail the debug to my own machine:

  compose.c:7055:Creating compose window...

but then something strange happens. When Claws tries to construct a header
for my outgoing message, it garbles the domain name. There is no such host
as gloria.histomat.net. I don't know what the xface is, but sounds like a
variable ("xface.gloria at gloriabrownministry.net..." is not a mail
account). If a variable, it seems the value for xface had not been set (I
assume it should be null).

The "+xface" line has my wife's correct address. Does this serve to
construct the From: line in the outgoing message header? Debug messages are
usually a mystery to me, but it seems that compose is trying to contruct a
message header and not getting correct info about my wife's machine,
perhaps because of the non-existent domain.

The debug seems to terminate rather abruptly. Is this normal?

> Try to send a new debug output, capturing a retrieval event.

I apologize for having sent the debug as an attachment. I didn't realize
it would be converted to a binary file (C++). I did attempt to "Get Mail"
during the above debug. 

Haines