[Users] Random delays... (bis)

[Pierre Fortin]

On Thu, 8 Dec 2016 19:05:06 +0100 Michael Rasmussen wrote:

>> If anyone can point me to the likely code, I can keep digging from
>> there...
>>   
>Does any of you use the libravatar plugin or some similar plugin which
>requires some form of external resources?

This is actually a great question.  I still can't point to a specific
action(s) that directly results a delay; but I did find and correct some
issues that appear to have slightly reduced the number of delays...

So I now suspect that there may be several issues triggering delays;
hence the randomness.

1. Many months ago, I was working on setting up a local PostFix (never
completed); but I left the test accounts active in CM -- they resulted
in dry polls to a non-existent server. Disabling these test accounts
appears to have helped a tiny bit. However, there is no theorem to prove
randomness or its lack thereof.

2. One account was working fine a few days ago; but noticed in debug
that it was now complaining of authentication failures. Re-entered the
same password to fix that. Almost no traffic on this account, so I don't
see any difference in the delays with this correction.

3. Opening a really old folder (no new messages since 2008), one message
(under 5KB) took ~24 seconds to process.  libravatar was still loaded on
that CM instance; but I'm not sure when the reported timers started.
Here's the debug output for that one:

libravatar_federation.c:49:cached avatar url for domain newegg.com not found
libravatar_federation.c:127:libravatar federated domain for newegg.com not found
libravatar_federation.c:68:new cached avatar url for domain newegg.com: x
libravatar_image.c:152:waiting for thread completion
libravatar_image.c:106:retrieving URL to file: http://cdn.libravatar.org/avatar/c60f759948c4a43f7f395d3bad5fa971?s=48 -> /home/pierre/.claws-mail/avatarcache/c60f759948c4a43f7f395d3bad5fa971
libravatar_image.c:111:not enough data for an avatar image: 0 bytes
libravatar_missing.c:150:New md5 c60f759948c4a43f7f395d3bad5fa971 added with time 1481227379
libravatar_image.c:159:thread completed
textview.c:712:TIMING textview_add_part : 23s854ms
textview.c:1187:Viewing text content of type: plain (length: 1782)
textview.c:828:TIMING textview_add_part : 0s016ms
textview.c:845:TIMING recursive_add_parts : 0s016ms
textview.c:891:TIMING recursive_add_parts : 23s871ms
textview.c:651:TIMING textview_show_part : 23s871ms
summaryview.c:3670:TIMING summary_display_msg_full : 23s876ms
summaryview.c:1571:                ### source:  debug_print("\n");
summaryview.c:1576:called inc_unlock (lock count 0)
summaryview.c:1577:TIMING summary_show : 23s898ms
folder.c:2576:Total cache memory usage: 3778315
folderview.c:2308:TIMING folderview_selected : 23s970ms

In case it helps, the old message from 2008 is attached. However, now that I've visited this long unused folder, there is no delay accessing it or its messages. Comparing the .claws_cache & .claws_mark to my backup; there is no change to those; but the empty file .mh_sequences was touched.
Unloaded & re-loaded libravatar and still no repeat delays entering this folder.  Did I mention random? :D

Determined to track this(these?) delay(s) down...  :)

HTH,
Pierre

-------------- next part --------------
A non-text attachment was scrubbed...
Name: 26
Type: application/octet-stream
Size: 4685 bytes
Desc: not available
URL: <http://lists.claws-mail.org/pipermail/users/attachments/20161208/b6f07966/attachment.obj>