Route Handler incorrect redirect

[kimh]

Hi guys,

I've got an issue with a new install of NE6.

Setup:

LDAP server - srv1
LDAP replicate - srv2
Mailbox server - srv3
mx server - srv4
proxy server - srv5

So new install had some issues with proxy configuration but that is all good now. Everything else appears good.

Now when I try and open a newly created mailbox the following happens:

open web page which redirects to https as I set it up (I have setup domain nest for a new domain and the virtual hostname of the proxy I am hitting)

get prompted for username/password all good.
put in correct credentials
then get the 500 gateway error from nginx

Now did the usual looking around for the error and most people had issues with DNS or timeouts etc..

I started looking at the logs on the proxy (nginx.log) and the single mailbox server (mailbox.log) and noticed something odd, there is the following error:

I've change the IP and DNS entries to the list above

[error] 1382#0: *6 zmauth: route handler srv3:7072 sent route srv1:8080, client: x.x.x.x, server: mail, request: "GET / HTTP/1.1", host: "domain.x"
2010/10/23 13:04:03 [error] 1382#0: *6 connect() failed (111: Connection refused) while connecting to upstream, client: x.x.x.x, server: mail, request: "GET / HTTP/1.1", upstream: "http://srv1:8080/", host: "domain.x"


So I'm looking at it and thinking thats my primary LDAP server that the proxy lookup target mailbox server is sending the proxy server to???

So dropped out of this setup and onto my old setup:

single ldap server
2 mailbox servers
single mx server
single prosy server

and looked at those logs and noticed that either of the mailbox server (both are reverse proxy lookup servers) and they both send the user to the correct mailbox server not the LDAP server on port 8080.

Both setups sit in an extranet and are split with mx and proxy on outer firewall and the mailbox and ldap servers on the inner firewall. both are on the same firewall rules as my old system, they run on the same IP range and the rules setup on the firewalls are for the subnet not individual IP's

The firewall logs show no errors so its not the firewall doing something stupid and the current system is working fine. There must be something wrong with the config on the new system I'm wanting to migrate to.

I'm running the latest version of NE6 with the latest patching on all servers.

I'm guessing its something in the Zimbra config, maybe on the mailbox server that for some reason thinks my primary LDAP server is a mailbox server which it is not.

Now I followed the installation documentation for adding a replica LDAP server and added to all servers, I ran the extra functions on the mailbox servers for postfix again as per the installation guide.

DNS dig and nsllokups are all good. every server is able to correctly work out names and mx records so its not DNS related.

Anyone got any idea?

Thanks

Kim

[kimh]

More data from logs across the farm:

Again as above, I've rebooted everything and tested again, check all dns and reverse dns of all servers and all correct..

So on the proxy server:

2010/10/23 21:10:27 [error] 7219#0: *26 zmauth: route handler x.x.x.x of mailbox server:7072 sent route x.x.x.x of primary ldap server:8080, client: x.x.x.x, server: mail, request: "GET /zimbra/ HTTP/1.1", host: "mail.domain.net", referrer: "https://mail.domain.net/"
2010/10/23 21:10:27 [error] 7219#0: *26 connect() failed (111: Connection refused) while connecting to upstream, client: x.x.x.x, server: mail, request: "GET /zimbra/ HTTP/1.1", upstream: "http://x.x.x.x of primary ldap server:8080/zimbra/", host: "mail.domain.net", referrer: "https://mail.comain.net/"



zmprov run from primary LDAP server:

zmprov details of domain info shows:

zimbraMailDeliveryAddress: kim@domain.net
zimbraMailForwardingAddressMaxLength: 4096
zimbraMailForwardingAddressMaxNumAddrs: 100
zimbraMailHost: shows as the only mailbox server which is correct
zimbraMailIdleSessionTimeout: 0
zimbraMailMessageLifetime: 0
zimbraMailMinPollingInterval: 1m
zimbraMailPurgeUseChangeDateForTrash: TRUE
zimbraMailQuota: 0
zimbraMailSignatureMaxLength: 10240
zimbraMailSpamLifetime: 7d
zimbraMailStatus: enabled
zimbraMailTransport: lmtp:shows as the only mailbox server which is correct:7025
zimbraMailTrashLifetime: 7d


logs from smtp mail server:

smtp mail server routes email to correct mailbox:

Oct 23 21:00:36 mailx1 postfix/smtpd[10881]: connect from client reseolves correct[x.x.x.x]
Oct 23 21:00:53 mailx1 zimbramon[6449]: 6449:err: Service status change: mailx1.domain.net stats changed from stopped to running
Oct 23 21:01:30 mailx1 postfix/smtpd[10881]: E2ED0E0C1: client=client resolves correct[x.x.x.x]
Oct 23 21:02:16 mailx1 postfix/cleanup[11373]: E2ED0E0C1: message-id=<20101023130130.E2ED0E0C1@mailx1.domain.net>
Oct 23 21:02:16 mailx1 postfix/qmgr[9263]: E2ED0E0C1: from=<admin@domain.net>, size=474, nrcpt=1 (queue active)
Oct 23 21:02:20 mailx1 postfix/smtpd[10881]: disconnect from client resolves correct[x.x.x.x]
Oct 23 21:02:24 mailx1 amavis[6885]: (06885-01) ESMTP::10024 /opt/zimbra/data/amavisd/tmp/amavis-20101023T210219-06885: <admin@domain.net> -> <kim@domain.net> SIZE=474 Received: from mailx1.domain.net ([127.0.0.1]) by localhost (mailx1.domain.net [127.0.0.1]) (amavisd-new, port 10024) with ESMTP for <kim@domain.net>; Sat, 23 Oct 2010 21:02:19 +0800 (WST)
Oct 23 21:02:24 mailx1 amavis[6885]: (06885-01) Checking: EqvAGidQ+WnG MYNETS [172.16.17.6] <admin@domain.net> -> <kim@domain.net>
Oct 23 21:02:30 mailx1 postfix/smtpd[12556]: connect from localhost.localdomain[127.0.0.1]
Oct 23 21:02:30 mailx1 postfix/smtpd[12556]: 3E3E4E0D8: client=localhost.localdomain[127.0.0.1]
Oct 23 21:02:30 mailx1 postfix/cleanup[11373]: 3E3E4E0D8: message-id=<20101023130130.E2ED0E0C1@mailx1.domain.net>
Oct 23 21:02:30 mailx1 postfix/qmgr[9263]: 3E3E4E0D8: from=<admin@domain.net>, size=1132, nrcpt=1 (queue active)
Oct 23 21:02:30 mailx1 amavis[6885]: (06885-01) FWD via SMTP: <admin@domain.net> -> <kim@domain.net>,BODY=7BIT 250 2.0.0 Ok, id=06885-01, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 3E3E4E0D8
Oct 23 21:02:30 mailx1 amavis[6885]: (06885-01) Passed CLEAN, MYNETS LOCAL [x.x.x.x] [x.x.x.x] <admin@domain.net> -> <kim@domain.net>, Message-ID: <20101023130130.E2ED0E0C1@mailx1.domain.net>, mail_id: EqvAGidQ+WnG, Hits: 0.788, size: 474, queued_as: 3E3E4E0D8, 12535 ms
Oct 23 21:02:30 mailx1 postfix/smtp[12201]: E2ED0E0C1: to=<kim@domain.net>, relay=127.0.0.1[127.0.0.1]:10024, delay=67, delays=53/0.06/3/11, dsn=2.0.0, status=sent (250 2.0.0 Ok, id=06885-01, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 3E3E4E0D8)
Oct 23 21:02:30 mailx1 postfix/qmgr[9263]: E2ED0E0C1: removed
Oct 23 21:02:30 mailx1 amavis[6885]: (06885-01) extra modules loaded: /opt/zimbra/zimbramon/lib/x86_64-linux-gnu-thread-multi/auto/Net/SSLeay/autosplit.ix, /opt/zimbra/zimbramon/lib/x86_64-linux-gnu-thread-multi/auto/Net/SSLeay/randomize.al, IO/Socket/SSL.pm, Net/LDAP/Extension.pm, Net/SSLeay.pm
Oct 23 21:02:32 mailx1 postfix/lmtp[12559]: 3E3E4E0D8: to=<kim@domain.net>, relay=the correct mailbox server hosting this mailbox[x.x.x.x]:7025, delay=2.4, delays=0.03/0.03/0.03/2.3, dsn=2.1.5, status=sent (250 2.1.5 Delivery OK)
Oct 23 21:02:32 mailx1 postfix/qmgr[9263]: 3E3E4E0D8: removed


So SMTP gets the correct info from the same mailbox server where to route emails to for the mailbox the I am trying to access via webmail that gets a proxy redirect to what is actually my primary LDAP server.


Functions listed as installed on servers:
svr1 primary ldap server - only ldap
svr2 replication ldap server - only ldap
svr3 mailbox server - mailbox, spell checker, logger
svr4 mta server - mta, anti spam, anti virus
srv5 proxy server - imap and pop proxy (i have also turned on http proxy and set mailbox server for reverse proxy lookup target and it is set correctly)


When you go into the admin panel and have a look at mailbox servers avaliable there is only the single mailbox server..

[kimh]

ok so I have done some more testing but still coming up blank for an answer..

No config changes at this point. Setup email client for POP and IMAP testing..

POP test

2010/10/24 13:30:11 [info] 7141#0: *10 client x.x.x.x connected to 0.0.0.0:995
2010/10/24 13:30:14 [error] 7141#0: *10 recv() failed (111: Connection refused) while reading response from upstream, client: x.x.x.x, server: 0.0.0.0:995, login: "kim@domain.net", upstream: (ip address of primary ldap server):7110, [x.x.x.x(client ip):1041-x.x.x.x(ip of proxy server):995] <=> [x.x.x.x(ip of proxy server):56481-0.0.0.0:0]

IMAP test

2010/10/24 13:40:05 [info] 7141#0: *18 client x.x.x.x connected to 0.0.0.0:993
2010/10/24 13:40:05 [error] 7141#0: *18 recv() failed (111: Connection refused) while reading response from upstream, client: x.x.x.x, server: 0.0.0.0:993, login: "kim@domain.net", upstream: (ip address of primary ldap server):7143, [x.x.x.x(client ip):1044-x.x.x.x(ip of proxy server):993] <=> [x.x.x.x(ip of proxy server):42901-0.0.0.0:0]

So same issue as with http and https testing. The proxy gets routed to my primay LDAP server to retrive the email for the account rather than the mailbox server that is also the only proxy lookup target at this point..

Does anyone have an idea on even where to start looking in the config? I'd rather diagnose than just rebuild the setup.

[kimh]

Anyone got any ideas?

[kimh]

mmm I'm guessing no one has a clue. I kind of wanted to work this out rather than a rebuild.

It's seems to be an issue with the proxy information passed from the primary mailbox server to the proxy server. I have setup a second mailbox server. Moved the couple of email boxes. Done a clear on the proxy and then connected to the email fine. move them back clear proxy cache again and reconnect and it worked for a bit, restart things to see it still all ok and BANG fail..

The proxy information again has the primary LDAP only server as its reverse proxy mailbox server within the proxy info and you get the dreaded nginx bad gateway error, this info from what I understand is sourced from the first mailbox server.

I might try a bit more and remove the primary from the list of reverse lookups and see it it runs cleanly but I'm guessing that will probably break things so don't like my chances.

I would have thought I would have got a reply from one of the Zimbra admins as this cant be the only time this has happened but there isn't enough info I can get to do much more diagnostics.

[kimh]

ok so more info....

zmprov garpb shows both mailbox servers the are reverse lookup targets on port 8080 - correct
zmprov gfc zimbraReverseProxyLookupTarget returns FALSE - correct
grep zmroutehandlers /opt/zimbra/conf/nginx/includes/nginx.conf.web on the proxy shows both of the mailbox servers on port 7072 - correct
zmprov garpu shows same as grep from nginx config
zmprov gamcs shows the only proxy server on port 11211 - correct
zmprov gamau shows both mailbox servers again on port 7071 https - correct


What else can I post here from the config?

One of the Zimbra admins must know something surely. This potentially could be a bug on the software, I have no idea because I'm not sure what else to look for to see if it's a configuration error, installation error or software error.

Kim

[kimh]

Any Admins online?

[kimh]

anyone??????

[kimh]

Has anyone read this and got any ideas? I ended up doing a full reload and some of the issues disappeared.

Now on Ubuntu 10 with Zimbra 6.0.10. While I'm not seeing the errors anymore as above I still get errors on the zmproxy server.

Errors such as [warn] upstream response is buffered to a temporary file
[error] zmauth: route handler did not send server or port
[error] zmauth: route handler x.x..x sent route x.x.x.

Now these are intermittent in the nginx logs but I did rebuild on my PC the other day and when I went to download my mailbox into Outlook (using zimbra connector) after a while it just stopped (my mailbox is about 250MB).
I tried logging onto the web client and got connection errors. There is nothing in he logs to show what was happening so I've got nowhere to start and I even up'd the logging levels to try and catch...


Has anyone got some ideas?

Kim

[mhammett]

Kinda disappointing that no one has helped out.