Re: ot: how to t/s TBird problems ?

[Shawn Heisey]

On 3/21/23 07:27, Christopher Wensink wrote:

Jim,

can you explain the format of the Date header, what each digit should 
represent?


Chris


A date value that's a big number like that is "seconds since epoch". 
The epoch is 1970-01-01 00:00:00 UTC.  This is a common way of telling 
time on POSIX systems like Linux.  Java uses something similar but not 
identical -- milliseconds since epoch.


The number 1665532450 is equivalent to Tuesday, October 11, 2022 
11:54:10 PM in the UTC timezone.


https://www.epochconverter.com/

The digits in the number have no specific meaning.  It's just a big 
decimal number.


Thanks,
Shawn

Re: ot: how to t/s TBird problems ?

[Christopher Wensink]

Jim,

can you explain the format of the Date header, what each digit should 
represent?


Chris

On 10/12/2022 6:23 PM, Jim Popovitch wrote:

On Fri, 1665532449-12-31 at 00:00 +, Voytek Eymont wrote:

Received: from 125.168.124.3
(SquirrelMail authenticated user voy...@sbt.net.au)
by geko.sbt.net.au with HTTP; Wed, 12 Oct 2022 11:12:43 +1100
Message-ID:

<28778ae2850dfc7fcf20b1dceff94876.squir...@geko.sbt.net.au>

Date: 1665532450
Subject: ot: how to t/s TBird problems ?
From: "Voytek Eymont" 
To: dovecot@dovecot.org
User-Agent: SquirrelMail/1.5.2 [SVN]
MIME-Version: 1.0


Why is your "Date:" header set to 1665532450?


-Jim P.



--
Christopher Wensink
IS Administrator
Five Star Plastics, Inc
1339 Continental Drive
Eau Claire, WI 54701
Office:  715-831-1682
Mobile:  715-563-3112
Fax:  715-831-6075
cwens...@five-star-plastics.com
www.five-star-plastics.com

Re: ot: how to t/s TBird problems ?

[Paul Kudla]

may or may not be off topic

how many emails in the inbox or folder in question

i generally find thunderbird for example can handle an inbox of up to 
20,000 emails in it without much issue (assuming half decent network 
connection etc)


after that it slows down

outlook don't even use if more then 200

rarely see a 40 second delay unless actually doing a physical search on 
the server side then rebuilding would become an issue?


it's usually best to divert large inbox's to other subfolders if possible.

might help?




Happy Wednesday !!!
Thanks - paul

Paul Kudla


Scom.ca Internet Services 
004-1009 Byron Street South
Whitby, Ontario - Canada
L1N 4S3

Toronto 416.642.7266
Main 1.866.411.7266
Fax 1.888.892.7266
Email p...@scom.ca

On 10/24/2022 7:54 PM, Joseph Tam wrote:


Voytek Eymont) wrote:


yesterday it was
---
I'm still experiencing a 40 second delay to retrieve emails for
xxx


If *this* is the problem you saw (and not the 2 hour delay mentioned further
in the thread), you can get a hint where the problem lies if you see a 40s
gap in the session logs: it will tell you who was doing what when the pause
happened (e.g. during authentication? During LIST fetch?  During message
fetch?)

For example, if dovecot was busy mulching through a large INBOX rebuilding
indices, I can see how it can chew up 40s under some circumstances.

Joseph Tam 

Re: ot: how to t/s TBird problems ?

[Joseph Tam]

Voytek Eymont) wrote:

> yesterday it was
> ---
> I'm still experiencing a 40 second delay to retrieve emails for
> xxx

If *this* is the problem you saw (and not the 2 hour delay mentioned further
in the thread), you can get a hint where the problem lies if you see a 40s
gap in the session logs: it will tell you who was doing what when the pause
happened (e.g. during authentication? During LIST fetch?  During message
fetch?)

For example, if dovecot was busy mulching through a large INBOX rebuilding
indices, I can see how it can chew up 40s under some circumstances.

Joseph Tam 

Re: ot: how to t/s TBird problems ?

[Jan Hugo Prins]

Even more easy, start by examining the mail headers to see where the mail was 
blocked.

Jhp

On October 23, 2022 4:05:51 PM GMT+02:00, Aki Tuomi 
 wrote:
>Hi!
>
>This is very unlikely to be a dovecot issue itself. There is nothing inside 
>dovecot that would horde your emails for 2 hours before "delivering" them.
>
>You should 
>
> - Enable mail_log plugin. This will tell you when mails are delivered, when 
> deleted etc, see 
> https://doc.dovecot.org/configuration_manual/plugins/mail_event_logging
> - Examine your logs
> - Check `doveadm fetch 'date.received date.sent date.saved' mailbox INBOX 
> '*'` ( this will print you the last email in INBOX, note the quotes)
>
>Aki
>
>> On 23/10/2022 16:49 EEST Chris Wensink  
>> wrote:
>> 
>>  
>> Over the last several months we have seen what seems like large delays in 
>> email delivery as well,  we get emails at 11AM that are time stamped at 
>> 9:10.  I thought it was a networking issue, but I can’t be sure.  I wish I 
>> knew more about coding, to look under the hood to examine things further.
>> 
>> Sent from my iPhone
>> 
>> > On Oct 23, 2022, at 7:17 AM, Voytek Eymont  wrote:
>> > 
>> > 
>> > 
>> >> On Sat, October 22, 2022 11:29 am, Joseph Tam wrote:
>> >> 
>> >> I haven't seen anyone else replying, but there doesn't seem anything
>> >> anomalous with the output.  The session commands-repliesd is is more or
>> >> less what I expect, although to make sense of this, you'll have to splice
>> >> the input and output files together using timestamps to see the sequential
>> >> flow of data.
>> > ...
>> >> Typically, if some resource limit is hit, one side or the other will
>> >> create a log or notification.  Your INBOX is large, but not outrageous. 
>> >> You
>> >> can test it directly by creating smaller subsets of the INBOX messages and
>> >> see if the problem goes away.
>> > 
>> > Joseph,
>> > 
>> > thank you very much for the follow up!
>> > you won't believe it, literally minutes before your email I got this email
>> > from the 'problem user' (below)
>> > 
>> > thank you to all who responded!
>> > 
>> > - I guess if TB debug log was enabled (as was suggested)- maybe the issue
>> > would become apparent from TB debug log ?
>> > 
>> > - I guess i should encourage POP users to switch to IMAP anyhow ?
>> > 
>> > got this from problem user:
>> > ---
>> > Mozilla Thunderbird released an update which I just installed.
>> > 
>> > Problem solved.
>> > 
>> > I guess Tbird had a problem that the new release addressed.
>> > 
>> > I'm sorry for the inconvenience.
>> > 
>> > I'm mystified why my issue was only with one account. Perhaps it was
>> > something to do with the size of the database.
>> > 
>> > ---
>> > yesterday it was
>> > ---
>> > I'm still experiencing a 40 second delay to retrieve emails for
>> > xxx
>> > 
>> > I have changed the pop port to 110 for the server but that did not
>> > work at all.
>> > 
>> > I have reinstalled my email client TBird but no change, anyway all the
>> > other accounts on TBird are working ok but they are MAPI not POP.
>> > 
>> > 
>> > Voytek
>> >

-- 
Sent from my Android device with K-9 Mail. Please excuse my brevity.

Re: ot: how to t/s TBird problems ?

[Aki Tuomi]

Hi!

This is very unlikely to be a dovecot issue itself. There is nothing inside 
dovecot that would horde your emails for 2 hours before "delivering" them.

You should 

 - Enable mail_log plugin. This will tell you when mails are delivered, when 
deleted etc, see 
https://doc.dovecot.org/configuration_manual/plugins/mail_event_logging/
 - Examine your logs
 - Check `doveadm fetch 'date.received date.sent date.saved' mailbox INBOX '*'` 
( this will print you the last email in INBOX, note the quotes)

Aki

> On 23/10/2022 16:49 EEST Chris Wensink  
> wrote:
> 
>  
> Over the last several months we have seen what seems like large delays in 
> email delivery as well,  we get emails at 11AM that are time stamped at 9:10. 
>  I thought it was a networking issue, but I can’t be sure.  I wish I knew 
> more about coding, to look under the hood to examine things further.
> 
> Sent from my iPhone
> 
> > On Oct 23, 2022, at 7:17 AM, Voytek Eymont  wrote:
> > 
> > 
> > 
> >> On Sat, October 22, 2022 11:29 am, Joseph Tam wrote:
> >> 
> >> I haven't seen anyone else replying, but there doesn't seem anything
> >> anomalous with the output.  The session commands-repliesd is is more or
> >> less what I expect, although to make sense of this, you'll have to splice
> >> the input and output files together using timestamps to see the sequential
> >> flow of data.
> > ...
> >> Typically, if some resource limit is hit, one side or the other will
> >> create a log or notification.  Your INBOX is large, but not outrageous. You
> >> can test it directly by creating smaller subsets of the INBOX messages and
> >> see if the problem goes away.
> > 
> > Joseph,
> > 
> > thank you very much for the follow up!
> > you won't believe it, literally minutes before your email I got this email
> > from the 'problem user' (below)
> > 
> > thank you to all who responded!
> > 
> > - I guess if TB debug log was enabled (as was suggested)- maybe the issue
> > would become apparent from TB debug log ?
> > 
> > - I guess i should encourage POP users to switch to IMAP anyhow ?
> > 
> > got this from problem user:
> > ---
> > Mozilla Thunderbird released an update which I just installed.
> > 
> > Problem solved.
> > 
> > I guess Tbird had a problem that the new release addressed.
> > 
> > I'm sorry for the inconvenience.
> > 
> > I'm mystified why my issue was only with one account. Perhaps it was
> > something to do with the size of the database.
> > 
> > ---
> > yesterday it was
> > ---
> > I'm still experiencing a 40 second delay to retrieve emails for
> > xxx
> > 
> > I have changed the pop port to 110 for the server but that did not
> > work at all.
> > 
> > I have reinstalled my email client TBird but no change, anyway all the
> > other accounts on TBird are working ok but they are MAPI not POP.
> > 
> > 
> > Voytek
> >

Re: ot: how to t/s TBird problems ?

[Chris Wensink]

Over the last several months we have seen what seems like large delays in email 
delivery as well,  we get emails at 11AM that are time stamped at 9:10.  I 
thought it was a networking issue, but I can’t be sure.  I wish I knew more 
about coding, to look under the hood to examine things further.

Sent from my iPhone

> On Oct 23, 2022, at 7:17 AM, Voytek Eymont  wrote:
> 
> 
> 
>> On Sat, October 22, 2022 11:29 am, Joseph Tam wrote:
>> 
>> I haven't seen anyone else replying, but there doesn't seem anything
>> anomalous with the output.  The session commands-repliesd is is more or
>> less what I expect, although to make sense of this, you'll have to splice
>> the input and output files together using timestamps to see the sequential
>> flow of data.
> ...
>> Typically, if some resource limit is hit, one side or the other will
>> create a log or notification.  Your INBOX is large, but not outrageous. You
>> can test it directly by creating smaller subsets of the INBOX messages and
>> see if the problem goes away.
> 
> Joseph,
> 
> thank you very much for the follow up!
> you won't believe it, literally minutes before your email I got this email
> from the 'problem user' (below)
> 
> thank you to all who responded!
> 
> - I guess if TB debug log was enabled (as was suggested)- maybe the issue
> would become apparent from TB debug log ?
> 
> - I guess i should encourage POP users to switch to IMAP anyhow ?
> 
> got this from problem user:
> ---
> Mozilla Thunderbird released an update which I just installed.
> 
> Problem solved.
> 
> I guess Tbird had a problem that the new release addressed.
> 
> I'm sorry for the inconvenience.
> 
> I'm mystified why my issue was only with one account. Perhaps it was
> something to do with the size of the database.
> 
> ---
> yesterday it was
> ---
> I'm still experiencing a 40 second delay to retrieve emails for
> xxx
> 
> I have changed the pop port to 110 for the server but that did not
> work at all.
> 
> I have reinstalled my email client TBird but no change, anyway all the
> other accounts on TBird are working ok but they are MAPI not POP.
> 
> 
> Voytek
> 

Re: ot: how to t/s TBird problems ?

[Voytek Eymont]

On Sat, October 22, 2022 11:29 am, Joseph Tam wrote:

> I haven't seen anyone else replying, but there doesn't seem anything
> anomalous with the output.  The session commands-repliesd is is more or
> less what I expect, although to make sense of this, you'll have to splice
> the input and output files together using timestamps to see the sequential
> flow of data.
...
> Typically, if some resource limit is hit, one side or the other will
> create a log or notification.  Your INBOX is large, but not outrageous. You
> can test it directly by creating smaller subsets of the INBOX messages and
> see if the problem goes away.

Joseph,

thank you very much for the follow up!
you won't believe it, literally minutes before your email I got this email
from the 'problem user' (below)

thank you to all who responded!

 - I guess if TB debug log was enabled (as was suggested)- maybe the issue
would become apparent from TB debug log ?

- I guess i should encourage POP users to switch to IMAP anyhow ?

got this from problem user:
---
Mozilla Thunderbird released an update which I just installed.

Problem solved.

I guess Tbird had a problem that the new release addressed.

I'm sorry for the inconvenience.

I'm mystified why my issue was only with one account. Perhaps it was
something to do with the size of the database.

---
yesterday it was
---
I'm still experiencing a 40 second delay to retrieve emails for
xxx

I have changed the pop port to 110 for the server but that did not
work at all.

I have reinstalled my email client TBird but no change, anyway all the
other accounts on TBird are working ok but they are MAPI not POP.


Voytek

Re: ot: how to t/s TBird problems ?

[Joseph Tam]

Voytek Eymont writes:

> I've enabled logging as per your suggestion:
>
> -rw--- 1 vmail vmail 127 Oct 16 21:38 20221016-213738.25640.1.in
> -rw--- 1 vmail vmail 8546603 Oct 16 21:38 20221016-213738.25640.1.out
> -rw--- 1 vmail vmail  96 Oct 16 21:58 20221016-215757.26075.1.in
> -rw--- 1 vmail vmail 8343463 Oct 16 21:58 20221016-215757.26075.1.out
>
> # cat 20221016-213738.25640.1.in
> 1665916659.491025 STAT
> 1665916659.550829 LIST
> 1665916676.430794 UIDL
> 1665916693.761281 RETR 114437
> 1665916694.440965 QUIT
> # cat 20221016-215757.26075.1.in
> 1665917878.786953 STAT
> 1665917878.863136 LIST
> 1665917905.610805 UIDL
> 1665917924.491198 QUIT
> #
>
> what should I look in the .out file ?
>
> some of the file is like:
> 
> 1665916661.234807 114436 70097
> 1665916661.234814 114437 154498
> 1665916661.234821 .
> 1665916676.430870 +OK
> 1665916676.981415 1 24b95283283a
> 1665916676.981459 2 24ba5283283a
> 
>
> 1665916679.434297 114436 00033fcf5283283a
> 1665916679.434327 114437 00033fd05283283a
> 1665916679.434349 .
> 1665916694.048139 +OK 154498 octets
> 1665916694.048199 Return-Path: 
> 

I haven't seen anyone else replying, but there doesn't seem anything
anomalous with the output.  The session commands-repliesd is
is more or less what I expect, although to make sense of this, you'll
have to splice the input and output files together using timestamps to
see the sequential flow of data.

I forget what the symptoms you originally reported, but theoretically,
you could simulate either client or server by feeding in the above data
and see how the other end behaves.

If dovecot is serving out the correct data, then TB is somehow
misinterpreting it.

> on an uneducated guess, the mailbox is just 'too large' ?
> POP has difficulty handling so many files ?

Typically, if some resource limit is hit, one side or the other will
create a log or notification.  Your INBOX is large, but not outrageous.
You can test it directly by creating smaller subsets of the INBOX messages
and see if the problem goes away.

Joseph Tam 

Re: ot: how to t/s TBird problems ?

[Voytek Eymont]

thank you for all replies.

On Thu, October 13, 2022 9:22 am, Joseph Tam wrote:

> to obtain session transcripts of what server/client are doing.
>
> I don't see any obvious errors from the logs that indicate any failure.
> I do see the INBOX is rather large so maybe a timeout is involved.

Joseph, yes, it has around 114437 emails

# ls  |wc
 114437  114437 6800828

I've enabled logging as per your suggestion:

-rw--- 1 vmail vmail 127 Oct 16 21:38 20221016-213738.25640.1.in
-rw--- 1 vmail vmail 8546603 Oct 16 21:38 20221016-213738.25640.1.out
-rw--- 1 vmail vmail  96 Oct 16 21:58 20221016-215757.26075.1.in
-rw--- 1 vmail vmail 8343463 Oct 16 21:58 20221016-215757.26075.1.out


# cat 20221016-213738.25640.1.in
1665916659.491025 STAT
1665916659.550829 LIST
1665916676.430794 UIDL
1665916693.761281 RETR 114437
1665916694.440965 QUIT
# cat 20221016-215757.26075.1.in
1665917878.786953 STAT
1665917878.863136 LIST
1665917905.610805 UIDL
1665917924.491198 QUIT
#

what should I look in the .out file ?

some of the file is like:


1665916661.234807 114436 70097
1665916661.234814 114437 154498
1665916661.234821 .
1665916676.430870 +OK
1665916676.981415 1 24b95283283a
1665916676.981459 2 24ba5283283a


1665916679.434297 114436 00033fcf5283283a
1665916679.434327 114437 00033fd05283283a
1665916679.434349 .
1665916694.048139 +OK 154498 octets
1665916694.048199 Return-Path: 


on an uneducated guess, the mailbox is just 'too large' ?
POP has difficulty handling so many files ?

On Thu, October 13, 2022 5:44 am, Brendan Braybrook wrote:
> maybe send the protocol debug out of thunderbird to the list too? (that'd
> show exactly what pop3 command thunderbird was hanging on).

Brendan,

thanks, I'll try the server logging first, as I can do it myself

On Thu, October 13, 2022 10:23 am, Jim Popovitch wrote:
> On Fri, 1665532449-12-31 at 00:00 +, Voytek Eymont wrote:

>> Date: 1665532450

> Why is your "Date:" header set to 1665532450?

Jim,

I think it's an issue with SquirrelMail, I think I've seen it before,
sometimes...?


Voytek

Re: ot: how to t/s TBird problems ?

[Jim Popovitch]

On Fri, 1665532449-12-31 at 00:00 +, Voytek Eymont wrote:
> Received: from 125.168.124.3
> (SquirrelMail authenticated user voy...@sbt.net.au)
> by geko.sbt.net.au with HTTP; Wed, 12 Oct 2022 11:12:43 +1100
> Message-ID:
<28778ae2850dfc7fcf20b1dceff94876.squir...@geko.sbt.net.au>
> Date: 1665532450
> Subject: ot: how to t/s TBird problems ?
> From: "Voytek Eymont" 
> To: dovecot@dovecot.org
> User-Agent: SquirrelMail/1.5.2 [SVN]
> MIME-Version: 1.0


Why is your "Date:" header set to 1665532450?


-Jim P.

Re: ot: how to t/s TBird problems ?

[Joseph Tam]

> I recently upgraded my Thunderbird email client and have experienced
> problems since.
> It appears that when Tbird polls for new messages it gets held up
> waiting for a response from the server
> I'm using POP port 995.
> Any ideas as to why I'm having a problem ?
> ---
>
> how to investigate such issue ?

I suspect you'll need to do session logging e.g.

protocol pop3 {
...
rawlog_dir = /writable/logdir/%u
}

then

mkdir /writable/logdir/user
chmod 0777 /writable/logdir/user

to obtain session transcripts of what server/client are doing.

I don't see any obvious errors from the logs that indicate any failure.
I do see the INBOX is rather large so maybe a timeout is involved.

Joseph Tam