381708 - Slow, several seconds, to display even with short messages (name query, nbns, local server, proxy, pac, isInNet, hostname vs realhostname) where occurs on where mail.server.server<n>.hostname and mail.server.server<n>.realhostname different [exchange]

Status: RESOLVED DUPLICATE of bug 1483485

(MailNews Core :: Networking: IMAP, defect)

Description

[Steven Singer]

User-Agent:       Mozilla/5.0 (Windows; U; Windows NT 5.0; en-US; rv:1.8.1.2) Gecko/20070222 SeaMonkey/1.1.1 Mnenhy/0.7.5.666
Build Identifier: Mozilla/5.0 (Windows; U; Windows NT 5.0; en-US; rv:1.8.1.2) Gecko/20070222 SeaMonkey/1.1.1 Mnenhy/0.7.5.666

When selecting a message (by clicking or pressing 'n' or deleting the preceeding message), there is a long delay (several seconds) before the contents of the message are displayed. This has been observed with IMAP folders but may affect other remote access protocols. The delay is long enough to make browsing through messages painful.

The delay is independent of the length of the message or the size of the IMAP folder. The delay occurs between clicking on the message (or pressing 'n' etc.) and the highlight changing. Once the new message is highlighted the message then displays quickly.

It doesn't occur on all IMAP servers. For a server with the problem, all folders are affected equally regardless of their size. The delay definitely shows in the time before the message is highlighted.

Some investigation reveals that the problem occurs on IMAP folders in which mail.server.server<n>.hostname and mail.server.server<n>.realhostname differ and ...hostname contains a name that cannot be resolved.

It appears that some part of the system is attempting to resolve hostname before displaying the message. If the name can be resolved - even if it points to the wrong system or even a system without IMAP at all - then there's no delay. If the name cannot be resolved then there is a delay.

Tracing with Ethereal shows that the delay is definitely related to name lookup (possibly just for unqualified host names) and is probably PC specific as it relates to the NetBIOS name service (NBNS).

Specifically, I can see DNS requests trying to look up hostname with different domain names. These all are answered quickly by the DNS server to indicate that the host doesn't exist. These are then followed by two NBNS name queries to the appropriate server. These are also responded to quickly with the answer that the host doesn't exist. Then, however, three broadcast NBNS name queries are performed. There is no response to these (as the host doesn't exist). Each of these three broadcast requests has a 0.75 second timeout. This gives a total delay just for the NBNS broadcasts of 2.25 seconds. This is the bulk of the UI delay observed.

All this occurs while the IMAP TCP connection is already open. Only after the third NBNS broadcast times out does traffic resume on the IMAP connection. Hence, the IMAP logs show nothing unusual.

If the hostname is changed to name that can be resolved (even if the host is turned off) then no delay occurs. The name resolution takes place immediately, but no attempt is made to connect to the resolved address. It looks like it's a pure name lookup that's being performed.

Note that if you select multiple messages in the UI, say by clicking to select the first and ctrl-clicking to select others, the delay occurs only for the first message. The first message will be displayed, once multiple messages are selected, the display pane goes blank. This suggests that it's something in the code that displays a message that's causing the problem.

If my machine weren't using NBNS broadcast for name lookups then I suspect the problem wouldn't be seen as the failed DNS lookups or failed NBNS requests to the server would be over quickly. However, I think it's still the case that the application shouldn't even be trying to lookup hostname. hostname shouldn't go anywhere near the network - that's what realhostname is for.

In a flash of inspiration I've just (that is after I've written the above text and spent many months, if not years, swearing at slow IMAP) tried playing with my proxy settings. If I have no proxy or a manual proxy (both with and without hostname listed as an exception) or some automatic proxy configuration (.pac) files then there's no problem. However, as soon as I get my pac file to call the function isInNet() it all goes slow. A little debugging reveals that when a message is clicked on, FindProxyForURL() gets called with host = hostname (not realhostname) and url = "imap://username@hostname/..." (again hostname, not realhostname). No proxy queries are made with realhostname and, as already noted, the imap connection to realhostname is already up. So it looks like the application is giving the proxy a chance to do something with a URL containing hostname. It's not clear that this is useful (and it is harmful in my case).

A minimal .pac file to show the problem is:

function FindProxyForURL(url, host)
{
  isInNet(host, "10.0.0.0", "255.0.0.0");
  return "DIRECT";
}

Note that this example discards the value from isInNet in this case as it's the call that causes the problem not anything done as a result of the call.

I've done as much elimination as I can. It's just changing the setting of hostname and the presence of isInNet() in the pac file that make the problem come and go. I did try all the usual stuff first - compacting folders, deleting and regenerating msf files etc.

I've tried many searches to find similar bugs, but not found anything that matches these symptoms. Bug 349953 has some similar symptoms but is marked as a 64 bit issue. Most other bugs show only on large folders or large messages. That's not the case here. I found bug 381387 in my search too but that looks like different symptoms. Bug 208287 is also relevant, but I think this report warrants a separate bug as your pac file could work just fine for real addresses  and it looks like you have IMAP set up to point to a real address but some long forgotten setting that's not visible on the UI can make things work badly.

A workaround may be to alter hostname, but that is painful to do as all references in prefs.js and msgFilterRules.dat (if not elsewhere) refer to hostname (I think). 

Another workaround I haven't tried might be to make an entry in this machine's hosts file for the invalid hostname. That might prevent the network activity. Unfortunately, the local IS department doesn't like users playing with that (it makes it hard for them to move servers). So, I can't use this idea, but other people might.

Fortunately, I am using my own pac file, so I've reordered it to make the call to isInNet() go away in this case. Not all people can use their own .pac file  nor should they be expected to know how to write them. If their ISP or IS department sets it up incorrectly, they may not be able to bypass it.

I've not tried the nightly build of SeaMonkey as I need it to be stable in my daily use.

It may well be that this problem is peculiar to my original pac file setup - the fact that I'm calling isInNet on plain host names as it may be only plain host names that trigger the NBNS broadcast lookup (and hence the long timeouts). I seem to think it was set up that way to handle some VPN stuff (as VPN access shouldn't be proxied as it's the VPN's job to get that traffic through the firewall, but plain host names could refer to sites at either end of the link). It's possible my pac file was just plain wrong. However, I still think it's wrong that hostname is ever used as a network address. This problem was a real pain to track down as the symptoms show a long way away from where the fault is.

I'm using SeaMonkey, so I've reported the bug against Mozilla Application Suite. I suspect it applies to Thunderbird too (or perhaps should be reported just there).


Reproducible: Always

Steps to Reproduce:
0.You need to be running on a Windows system that is going to perform NBNS lookups. You need a to be using a proxy automatic configuration file (.pac) file with a call to isInNet() (as detailed in the description).
1.Create an IMAP account as normal for an account with several messages in any folder.
2.Select the folder and then select messages within the folder. Note how responsive the system is.
3.Close the whole application (to release prefs.js).
4.Edit prefs.js, create a new line for mail.server.server<n>.realhostname with the hostname copied from mail.server.server<n>.hostname.
5.Edit mail.server.server<n>.hostname to contain the name of a server that has no entry in the name server database.
6.Save prefs.js
7.Restart the application.
8.Go back to the IMAP folder and select messages within the folder. Note how responsive it is.
9.Repeat steps 3, 5, 6 and 7 this time altering hostname to contain the name of a host that can be resolved (even one that doesn't have an IMAP service or is turned off).
10.Go back to the IMAP folder and select messages within the folder. Note how responsive it is.
Actual Results:  
The responsiveness at step 8 was much worse than that at both steps 2 and 10. At step 8 it took several seconds for each message to be displayed. In steps 2 and 10, each message was displayed in less than a second.

Expected Results:  
The responsiveness at steps 2, 8 and 10 should be the same. Messages should be displayed quickly regardless of the setting of hostname as hostname should not be used for any network actions.

I think this problem has been present for a while (possibly back as far as Netscape 7). 

My machine is a PC running Windows 2000 (32 bit) with a 2.6 GHz processor and 896 MB of RAM. At the time of the problem, only 400 MB of RAM is in use so swapping is not an issue. The IMAP server is Microsoft Exchange Server 2003, but I don't think that's relevant either.

Comment 1

[Wayne Mery (:wsmwk)]

(In reply to comment #0)
>...
> I've not tried the nightly build of SeaMonkey as I need it to be stable in my
> daily use. 

on average nightlies are not too bad.  just protect yourself and back up your profile before you start.

this needs a networking guru

Comment 2

[Wayne Mery (:wsmwk)]

unsure who can direct this to the right person(s) - cc: emre, benc, darin as starting points. 

Steven, how is the cpu usage?  Running trunk may be a better common starting point for devs to help you.  I am told that recent SM nightlies a relatively stable - ftp://ftp.mozilla.org/pub/seamonkey/nightly/latest-trunk/  you can backup with mozbackup

Comment 3

[Steven Singer]

CPU load wasn't an issue. It's a pure networking delay problem. When Windows is asked to to resolve the name it tries many different mechanism. Eventually it ends up at an NBNS broadcast. Windows uses a 0.75 second timeout (so is independent of CPU load) and tries three times (as NBNS broadcast is unreliable). This explains the whole UI delay.

This problem appears to be an interaction between three components:

  1) Windows uses NBNS broadcast to resolve unknown hostnames and this can take over 2 seconds to determine that a hostname does not exist (arguably poor protocol design, but not a bug).

  2) Some proxy scripts (arguably badly designed ones) attempt to do an address lookup of every address they're passed.

  3) Reading IMAP folders passes hostname rather than realhostname to the proxy ever time you open a message even though it doesn't use the results of the lookup (as the IMAP connection is already open). I believe this is a bug, I am prepared to be told that there is a good reason for this.

I don't need help to resolve the problem as I've fixed it for me by altering my proxy script - thus eliminating one of the conditions needed for the problem to manifest.

I'm reporting this as a courtesy so other people stuck in the same situation might find out what the fix is and so that the problem can be fixed in future releases so people who try Thunderbird don't stop using it because it's too slow.

I feel I've given a detailed technical analysis of the problem (well beyond what was required for a meaningful bug report) and a good reproduction case. When it gets to a networking guru it should make sense. The analysis of whether the bug still exists should be no more than logging whether hostname or realhostname gets passed to a proxy script when browsing IMAP folders. I'd expect finding the piece of code that generates that URL to be easy for someone familiar with the code. However, deciding whether the URL should contain hostname or realhostname might be a trickier proposition.

If the problem can't be reproduced then I'll see if I can get more information. However, the time I can spend on this is limited since this problem showed at work which means I would have to use work time and work resources to investigate. I can't speculatively run the latest overnight builds just to see if the problem has gone away. That's why I provided a detailed reproduction method. I've even tried looking in the source code to see if there was an obvious fix I could suggest but I got lost in a maze of twisty classes all subtly different :-). I got to the call to getHost() in nsImapUrl::GetUri but couldn't work out if that was hostname or realhostname, whether that was the URI passed to the proxy script or if that URI is meant to contain hostname or realhostname.

I'm sorry I don't have the time to help more.

Comment 4

[WADA:World Anti-bad-Duping Agency]

(In reply to comment #0)
> A little debugging reveals that when a message is clicked on,
> FindProxyForURL() gets called with host = hostname (not realhostname)
> and url = "imap://username@hostname/..." (again hostname, not realhostname).

When IMAP/POP3, internal URI representaion of mail folder is based on hostname/userName instead of realhostname/realuserName (for directory/file path, key of password manager entry, etc.), and network access is based on realhostname/realuserName.
Following is folder location of Inbox in this case. (folder property when trunk) 
> imap://[e-mail]/INBOX
>   hostname     : imap-gmail.mail.server
>   realhostname : imap.gmail.com
>   userName     : Y-One
>   realuserName : [e-mail]
And, as you say, no problem in usual IMAP access. (I don't use proxy)

Passing the internal imap: URI directory to pac seems to be cause of the problem.

Comment 5

[WADA:World Anti-bad-Duping Agency]

Phenomenon could be observed by following test, with Tb version 3.0a1pre (2008050203), with Gmail IMAP account in Comment #4.

(A) Proxy setting : file:///C:/proxy.pac
(B) PAC file (C:\proxy.pac, on MS Win-XP SP2)
> function FindProxyForURL(url, host) {
> var x1=url.substr(0,4).toLowerCase(); var x2=host.substr(0,4).toLowerCase();
> if(x1=="imap"||x2=="imap") { alert(url+"\n"+host); } {return "DIRECT";}
> }
(C) Messages in Error Console
> PAC-alert: imap://[e-mail]:993/select%3E/INBOX
>            imap-gmail.mail.server
> PAC-alert: imap://imap.gmail.com:993/
>            imap.gmail.com
> PAC-alert: imap://[e-mail]:993/select%3E/Drafts
>            imap-gmail.mail.server
> PAC-alert: imap://imap.gmail.com:993/
>            imap.gmail.com

When first open of IMAP folder, internal URI based on hostname/userName is passed to pac script. When connecting to IMAP server, IMAP URI based on realhostname/realuserName is passed to pac script.

Comment 6

[WADA:World Anti-bad-Duping Agency]

"Slow down is visible or not" depends on pac script logic and environment.
As seen in following Wikipedia article for proxy, if pac script calls dnsResolve for all unknown URI or server, and if DNS lookup for invalid/undefined host name takes long in user's environment, slow down can become visible.
> http://en.wikipedia.org/wiki/Proxy_auto-config
> Limitations
> The function dnsResolve (and similar other functions) perform a DNS lookup
> that can block your browser for a long time if the DNS server does not respond.

Really severity=major issue? severity=minor(never be trival), isn't it?

Comment 7

[WADA:World Anti-bad-Duping Agency]

FYI.
A least three issues are involved in this bug's phenomenon.
 (1) Needless PAC call for internal mail folder URI based on hostname/userName.  
     > PAC-alert: imap://[e-mail]:993/select%3E/INBOX
     This can cause long temporary freeze, if PAC file is not well coded and
     produces problem of (2).
     This issue possibly exists on POP3 or NNTP too.
 (2) If PAC file uses dnsResolve(and similar other functions) inappropriately
     in inappropriate environment, it takes very very long.
 (3) Because call of PAC file is executed under UI task,
     problem of (2) will cause temporary(but sufficiently long) UI hang.
     (Bug 235853)

Comment 8

[RNicoletto]

Is this bug related to bug 208287?

Comment 9

[Steven Singer]

With respect to comment #8, as I noted in the original problem description, bug 208287 is only tangentially related.

The delay that I was seeing was the IsInNet() delay, however, I don't believe that fixing bug 208287 will fix this bug.

Bug 208287 describes how the UI freezes during IsInNet() calls. Fixing that bug would make the UI responsive during the lookup but, if I understand the problem correctly, won't allow the user access to their mail message any sooner (it'll just allow the user to play with the UI while waiting for their mail). I think this means that point 3 in comment #7 is irrelevant - it's points 1 and 2 that are critical. In my case the freeze was only a few seconds - not enough for me to notice that the UI was non-responsive but certainly enough to make reading mail a chore.

The problem here is that an inappropriate hostname is being resolved. The hostname that's being looked up is not used for any network access at all. In fact, as I stated in the original bug report, whilst the inappropriate lookup is occurring the correct TCP/IP connection already exists.

With respect to comment #5, I'll note that when I was seeing the problem, the inappropriate lookup occurred every time a new mail message was selected within a folder. If the delay had been just when the folder was opened then I probably wouldn't have noticed.

As a completely separate issue, it may be worth investigating if a poorly written PAC file (or poorly configured system) could cause problems with reading mail even if realhostname and hostname are the same and valid. I'm thinking of a situation as in comment #5 of bug 208287. Arguably, if the TCP/IP connection to the IMAP (or POP3 or NNTP) server is already up then we shouldn't be using the PAC file at all. A fix to avoid calling the PAC file once the TCP/IP connection was up would reduce the occurrence of this bug to just once per session.

Out of curiosity, what is the result of the PAC call for the mail folder URI used for (point 1 in comment #5)? Can it sensibly return different proxies on a per folder basis? How would this interact with the TCP/IP connection already being up?

Comment 10

[Wayne Mery (:wsmwk)]

Steven, see this in v3.0.1? 

maybe too much to hope for

Comment 11

[David :Bienvenu]

Steven, thx for all the research. It's somewhat surprising that this is happening with an existing, cached connection. I don't think we would be resolving hostnames in that case.

If this is still happening, nsSocketTransport or DNS logging might be interesting.

Comment 12

[Wayne Mery (:wsmwk)]

Steven, 
do you still see this problem with your testcase in version 3?  

And if so, can you supply log per ...
(In reply to comment #11)
> If this is still happening, nsSocketTransport or DNS logging might be
> interesting.

see https://wiki.mozilla.org/MailNews:Logging

Comment 13

[Joshua Cranmer [:jcranmer]]

RESOLVED INCOMPLETE due to lack of response to last question. If you feel this change was made in error, please respond to this bug with your reasons why.

Comment 14

[Steven Singer]

I am still here and listening to what's going on. However, as per comment #3 the problem doesn't show for me any more as I've changed my configuration and I don't have time to investigate builds to see if it's fixed.

Hence, there shouldn't be people asking me whether the problem still reproduces. I can't tell any more. I no longer have a test case.

Comment #5 and so on suggest that the problem is well enough understood for anyone to reproduce it.

Much as I'd love to help, I simply don't have the time.

Comment 15

[Wayne Mery (:wsmwk)]

reopening ... bienvenu writes: IMAP Uri's use the "fake" hostname, but the internal URL's use the real hostname. I'm not sure where the PAC lookup happens, but it might be using the URI with the fake hostname, so it might be something we could fix in the imap code.

Comment 16

[gene smith]

Not sure about this, a lot to parse here. However, I think it involves misuse of "hostname" when it has been superseded by "realhostname" that only occurs when you change the server name for your account, and things are slowing down due to dns and/or proxy usage. Something similar occurred in Bug 1414607, so might consider this and that dups or at least closely related.

Comment 17

[Wayne Mery (:wsmwk)]

Steven, are you still able to recreate and reproduce the slowness?

Comment 18

[Steven Singer]

As I noted in comment #14, the configuration which showed the problem has long since gone (and my memory isn't far behind).

So, I had a play on my current system (Thunderbird 115.6.0, Windows 11).

I could set the system to use a proxy.pac file as per comment #4 (Settings->General->Network and disk space->Connection->Settings...). With developer tools connected, alert() calls from the proxy.pac show up in the console.

On my real mail setups, which all have hostname set correctly, I was seeing the occasional log message, but, importantly, not a log message every time I switched to a new email message. However, I don't know if the original repeated lookups were due to having a failing lookup when using the wrong server name.

I did notice that if I changed the server name in the user-friendly way (through Account settings-><name of account>->Server Settings->Server Name) then hostname got updated rather than realhostname getting created. I think this means that this split hostname/realhostname setting, with one name being unresolvable, can't occur on modern Thunderbird. Since an unresolvable hostname was perhaps the most significant part of the original reproduction (as it can allow a proxy.pac file that works in most testing, but fails in this unusual setup), I think this whole issue goes away.

You referred to bug 1483485, and it looks like that bug did remove realhostname. If that's correct then this bug can be closed as a duplicate of that (or whatever the correct procedure is).

Comment 19

[Wayne Mery (:wsmwk)]

Thanks for the feedback