509747 - Thunderbird 3.0b4pre checks for new mail every 30 seconds regardless of account settings (when mail.server.serverN.check_time>=36, PRInt32 overflow occurs)

Status: RESOLVED FIXED

(MailNews Core :: Networking: POP, defect)

Description

[A Carter]

User-Agent:       Mozilla/5.0 (Windows; U; Windows NT 6.0; en-GB; rv:1.8.1.14) Gecko/20080404 Firefox/2.0.0.14
Build Identifier: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9.1.3pre) Gecko/20090811 Shredder/3.0b4pre

Have setup multiple accounts previously.
Under "Server Settings" section - "Check for new messages every xx minutes". Current setting is 37 minutes on 1 account, but mail scanner proxy is getting requests every 30 seconds for new mail.

Happens the same with any account and no matter what the setting is in minutes.

Reproducible: Always

Steps to Reproduce:
As above. Ignores "Check for new messages every ..." setting.

Comment 1

[Ludovic Hirlimann [:Usul]]

Anything in Tools -> Error console ?

Comment 2

[A Carter]

Hi

Only this :-

Warning: Timed textboxes are deprecated. Consider using type="search" instead.
Source File: chrome://messenger/content/messenger.xul
Line: 0

Comment 3

[Ludovic Hirlimann [:Usul]]

Can you have a look into your prefs.js file and make sure that the settings are the proper one. Are you suing Pop, imap ?

Comment 4

[A Carter]

Everything looks fine to me and what I set - the "user_pref("mail.server.server3.check_time", 41);" for example is what I set.

I can get e-mails fine using all accounts (all POP3).

Is there anything I should be looking for?

Comment 5

[WADA:World Anti-bad-Duping Agency]

(In reply to comment #0)
> Current setting is 37 minutes on 1 account,
> but mail scanner proxy is getting requests every 30 seconds for new mail.

Get protocol log with timestamp, and check protocol level flow first.
> https://wiki.mozilla.org/MailNews:Logging
> http://www.mozilla.org/projects/netlib/http/http-debugging.html
> Timestamp of nspr log : Bug 402793 Comment #17

I think following parameter is appropriate for first analysis. 
> SET NSPR_LOG_MODULES=nnsHostResolver:5,sHttp:5,mime:5,imap:5,nntp:5,smtp:5,pop3:5,ldap :5,timestamp

Comment 6

[A Carter]

Attachment: As requested Thunderbird protocol logs.

Thank you for comment.

Attachment is compressed using 7-zip. Protocol log using parameters as requested.

Comment 7

[WADA:World Anti-bad-Duping Agency]

And "requests every 30 seconds which your mail scanner proxy is getting" was really request of periodical mail check to POP3 server for new mail by Tb?

Comment 8

[A Carter]

Yes. From my personal firewall network activity, I can see that the "Thunderbird.exe" process is generating network traffic every 30 seconds to the AVG mail proxy ("avgmc.exe"). The avgmc.exe mail proxy is then checking the mail server.

The actual IP's/ports used are :

Thunderbird connects to :

IP 127.0.0.1, ports 10110, 10111 (AVG mail proxy listens on these ports)

AVG mail proxy (AVGMC.exe) connects to :

<<mail server IP 1>>, port 110 and <<mail server IP 2>>, port 110

Connection is Thunderbird -> AVG Mail Proxy -> Mail server

Comment 9

[WADA:World Anti-bad-Duping Agency]

(In reply to comment #8)
> I can see that the "Thunderbird.exe" process is generating network traffic
> every 30 seconds to the AVG mail proxy ("avgmc.exe").
>(snip)
> Connection is Thunderbird -> AVG Mail Proxy -> Mail server

Protocol log you got is POP3(and some others) level flow of "Thunderbird <-> AVG Mail Proxy". Is there log data for the "network traffic every 30 seconds to the AVG mail proxy"?
See RFC 1939 for POP3 command.
> http://tools.ietf.org/html/rfc1939
> http://en.wikipedia.org/wiki/Post_Office_Protocol

Do you use add-on(extension) relates to POP3 access? If yes, can you reproduce your problem with Tb's safe mode(thundebird.exe -safe-mode)?

> Gecko/20090811 Shredder/3.0b4pre

Do you remember last build which didn't have the problem?

Comment 10

[A Carter]

Attachment: Firewall logs.

> Protocol log you got is POP3(and some others) level flow of "Thunderbird <->
> AVG Mail Proxy". Is there log data for the "network traffic every 30 seconds > to the AVG mail proxy"?

See attached logs.

>> Do you use add-on(extension) relates to POP3 access? If yes, can you reproduce
>> your problem with Tb's safe mode(thundebird.exe -safe-mode)?

None used. Disabled all plugins (just in case) and no change.

>> Do you remember last build which didn't have the problem?

Not sure. Only noticed recently. Maybe 3.0b3 build?

Comment 11

[WADA:World Anti-bad-Duping Agency]

Report of my quick check result with 2009/8/13 build on MS Win-XP.
  "Check for new messages every NN minutes" setting : 
      4 minutes : Problem was not observed. 
     37 minutes : Login/CAPA/STAT/QUIT each 30 seconds was observed.
I'll try to do duplication test and to find regression range.

Can you reproduce problem with mail.server.server3.check_time=9(single digit) or larger value such as 999?

Comment 12

[A Carter]

From my testing.

With a setting of 73 minutes and above (not sure at which point it changes again) it checks at 60 second intervals.

With a setting of 100 minutes it check at 240 second intervals.

Any setting below 73 minutes and it checks at 30 seconds intervals.

Comment 13

[WADA:World Anti-bad-Duping Agency]

From my testing (2009/8/13 build).
   3 min, 4 min  : interval of 3 min(180 seconds) or 4 min(240 seconds)     
   9 min, 35 min : Login/CAPA/STAT/QUIT after 30 seconds was not observed
  36 min, 37 min : Login/CAPA/STAT/QUIT was issued after 30 seconds
Confirming.

Comment 14

[WADA:World Anti-bad-Duping Agency]

Rough regression window using builds I happened to have(with 36 min setting).
> 2009/07/10 OK
> 2009/07/21 OK  rv:1.9.1.2pre Gecko/20090721 Shredder/3.0b4pre
> 2009/07/24 BAD rv:1.9.1.2pre Gecko/20090724 Shredder/3.0b4pre
> 2009/08/01 BAD

Comment 15

[WADA:World Anti-bad-Duping Agency]

Regression range:
(Problem doesn't occur)
> Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9.1.2pre) Gecko/20090723 Shredder/3.0b4pre
(Problem started to occur)
> Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9.1.2pre) Gecko/20090724 Shredder/3.0b4pre

Change log around 7/23.
> http://hg.mozilla.org/comm-central/log/6d6f96b9aeb7
Problem was produced by next change? 
> a0da9ca1c4b2: Bug 488979 - |mailnews/base/src/nsMsgBiffManager.cpp(261) :
>     warning C4244: 'initializing' : conversion from 'double' to 'PRInt64',
>     possible loss of data|; (Av1) Fix nits in SetNextBiffTime();
>     Thu, 23 Jul 2009 23:16:51 +0200 - rev 3121

Comment 16

[Serge Gautherie (:sgautherie)]

(In reply to comment #13)
>   35 min : Login/CAPA/STAT/QUIT after 30 seconds was not observed

35 * 60,000,000 = 2,100,000,000 (<= 2,147,483,647)

>   36 min : Login/CAPA/STAT/QUIT was issued after 30 seconds

PRInt32 overflow, caused by bug 488979.

Comment 17

[Serge Gautherie (:sgautherie)]

Attachment: (Av1) Force 64-bit multiplication, fix nits [Checkin: Comment 19]

Comment 18

[David :Bienvenu]

Comment on attachment 394492 [details] [diff] [review]
(Av1) Force 64-bit multiplication, fix nits
[Checkin: Comment 19]

looks ok, thx.

Comment 19

[Serge Gautherie (:sgautherie)]

Comment on attachment 394492 [details] [diff] [review]
(Av1) Force 64-bit multiplication, fix nits
[Checkin: Comment 19]


http://hg.mozilla.org/comm-central/rev/9e6af989f362