Error 502 Connection is refused

[notext]

Hello, after the upgrade to 8.7 we have been this problem with the web login form.

Code: Select all

HTTP ERROR 502
Problem accessing ZCS upstream server. Cannot connect to the ZCS upstream server. Connection is refused.

We are on Ubuntu 14.04 using the FOSS edition:

Code: Select all

zimbra@server1:~$ zmcontrol -v
Release 8.7.0.GA.1659.UBUNTU14.64 UBUNTU14_64 FOSS edition.

Nginx says in nginx.log:

Code: Select all

2016/08/09 16:51:04 [error] 41949#0: *17 connect() failed (111: Connection refused) while connecting to upstream, client: IP_REDACTED, server: server1.our-domain.net.default, request: "GET / HTTP/1.1", upstream: "https://[::1]:8443/", host: "mail.our-domain.net"
2016/08/09 16:51:04 [error] 41949#0: *17 connect() failed (111: Connection refused) while connecting to upstream, client: IP_REDACTED, server: server1.our-domain.net.default, request: "GET / HTTP/1.1", upstream: "https://127.0.1.1:8443/", host: "mail.our-domain.net"
2016/08/09 16:51:04 [error] 41949#0: *17 no live upstreams while connecting to upstream, client: IP_REDACTED, server: server1.our-domain.net.default, request: "GET / HTTP/1.1", upstream: "https://zimbra_login_ssl/", host: "mail.our-domain.net"

and in nginx.access.log:

Code: Select all

IP_REDACTED:5136 - - [09/Aug/2016:17:23:55 -0500]  "GET / HTTP/1.1" 502 1332 "-" "Mozilla/5.0 (X11; OpenBSD i386; rv:36.0) Gecko/20100101 Firefox/36.0 SeaMonkey/2.33.1" "server1.our-domain.net:8443, server1.our-domain.net:8443"
IP_REDACTED:5136 - - [09/Aug/2016:17:23:55 -0500]  "GET / HTTP/1.1" 502 1332 "-" "Mozilla/5.0 (X11; OpenBSD i386; rv:36.0) Gecko/20100101 Firefox/36.0 SeaMonkey/2.33.1" ""

But ports are open:

Code: Select all

$ sudo netstat -anotp | grep 8443
tcp        0      0 0.0.0.0:8443            0.0.0.0:*               LISTEN      37732/java       off (0.00/0/0)
tcp        0      0 127.0.1.1:8443          127.0.0.1:42049         TIME_WAIT   -                timewait (47.53/0/0)
tcp        0      0 127.0.1.1:8443          127.0.0.1:42048         TIME_WAIT   -                timewait (47.10/0/0)
$ sudo netstat -anotp | grep 8080
tcp        0      0 0.0.0.0:8080            0.0.0.0:*               LISTEN      9522/java        off (0.00/0/0)

Luckily none of our users use the web interface (except me), and the imap and pop3 proxy are working without any problems...

I've detected a weird bug on the admin page which is perhaps related:
On the global config administration page my web proxy configuration is off and ports are zeroed, once I change it and save, the values do not change. Could this have to do with my issue? (See images attached)

zmprov returns:

Code: Select all

zimbra@server1:~$ zmprov -getAllReverseProxyBackends
    server server1.our-domain.net:8080;

also, this command

Code: Select all

zimbra@server1:~$ libexec/zmproxyconfig -e -m -H server1.our-domain.net

...has no effect on the error...

So I'm requesting a little help on this...

[Uma Shankar]

Hi,

As per the error it is the proxy which is not able to connect to the mailbox servers but we need to be sure on the front, before debuging the same.

Could you please confirm if you are able to access the mailbox server over port 8443 or 8080 i.e https://mailboxip:8443

Also, what are the settings here

zmprov gs `zmhostname` | grep -i mailmode ( on both proxy and mailbox server)

Also, are you having any firewall in between proxy and mailbox servers.

Regards,
Uma Shankar

[nisamudeen97]

Hi,

I am also having the same issue while trying to access webmail client on hostname.

nginx.log

Code: Select all

2016/08/19 06:02:10 [error] 20841#0: *11 connect() failed (111: Connection refused) while connecting to upstream, client: "my-public-ip", server: mail.server.com.default, request: "GET / HTTP/1.1", upstream: "https://serverip:8443/", host: "server-ip"

Meanwhile I can accesss webmail url using https://hostname:7443

[notext]

As an update, issue has been resolved after much fiddling with the options on the admin web page (too much, we are not sure anymore what solved the issue, several server reboots where involved though).
Some lingering issues remain, I will post them.

[6125amartin]

I'm also encountering this issue after upgrading to ZCS 8.7.0 OSE on Ubuntu 14.04. Any advice on what to check to fix it ? I can access https://zimbra.example.com:8443

Note that this error is intermittent - you can successfully use the web client on port 443 for several seconds, completing operations successfully, before you encounter this error. When you do encounter this error, if you just repeat the operation enough times (e.g. click on the same folder again), it will eventually succeed. This makes me think it isn't a configuration issue with the proxy or mailboxd since wouldn't that mean it would always fail? This seems more like an issue of throttling, maybe DoSFilter?

[6125amartin]

I was able to resolve this by disabling zimbra-proxy by following the steps at the bottom of this page.

[notext]

As a further enhancement of this issue, we where having all sort of problems, specifically:

• the ajax version of the mailbox was not loading
• the users could not change their configurations (when they could login somehow?)
• calendar was failing from time to time
• and others

All of those errors due to a 502 during a POST to /service/soap/BatchRequest .

nginx.access.log

Code: Select all

IP_REDACTED:64768 - - [25/Aug/2016:11:38:37 -0500]  "POST /service/soap/BatchRequest HTTP/1.1" 502 1332 "https://mail.DOMAIN.REDACTED/" "Mozilla/5.0 (Windows NT 6.3; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/52.0.2743.116 Safari/537.36" "[::1]:8443"
IP_REDACTED:64113 - - [25/Aug/2016:11:40:59 -0500]  "POST /service/soap/BatchRequest HTTP/1.1" 502 1332 "https://mail.DOMAIN.REDACTED/" "Mozilla/5.0 (Windows NT 6.3; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/52.0.2743.116 Safari/537.36" "[::1]:8443"
IP_REDACTED:25562 - - [25/Aug/2016:11:43:19 -0500]  "POST /service/soap/NoOpRequest HTTP/1.1" 502 1332 "https://mail.DOMAIN.REDACTED/" "Mozilla/5.0 (Windows NT 6.3; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/52.0.2743.116 Safari/537.36" "[::1]:8443"

Here is the (very) verbose version:

Code: Select all

2016/09/03 17:10:15 [debug] 41908#0: *24 http empty handler
2016/09/03 17:10:15 [debug] 41908#0: *24 http keepalive handler
2016/09/03 17:10:15 [debug] 41908#0: *24 http process request line
2016/09/03 17:10:15 [debug] 41908#0: *24 http request line: "POST /service/soap/BatchRequest HTTP/1.1"
2016/09/03 17:10:15 [debug] 41908#0: *24 http uri: "/service/soap/BatchRequest"
2016/09/03 17:10:15 [debug] 41908#0: *24 http args: ""
2016/09/03 17:10:15 [debug] 41908#0: *24 http exten: ""
2016/09/03 17:10:15 [debug] 41908#0: *24 http process request header line
2016/09/03 17:10:15 [debug] 41908#0: *24 http header: "Host: mail.DOMAIN_REDACTED"
2016/09/03 17:10:15 [debug] 41908#0: *24 http header: "User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.9; rv:42.0) Gecko/20100101 Firefox/42.0"
2016/09/03 17:10:15 [debug] 41908#0: *24 http header: "Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"
2016/09/03 17:10:15 [debug] 41908#0: *24 http header: "Accept-Language: en-US,en;q=0.5"
2016/09/03 17:10:15 [debug] 41908#0: *24 http header: "Accept-Encoding: gzip, deflate, br"
2016/09/03 17:10:15 [debug] 41908#0: *24 http header: "DNT: 1"
2016/09/03 17:10:15 [debug] 41908#0: *24 http header: "Content-Type: application/soap+xml; charset=utf-8"
2016/09/03 17:10:15 [debug] 41908#0: *24 http header: "X-Zimbra-Csrf-Token: REDACTED"
2016/09/03 17:10:15 [debug] 41908#0: *24 http header: "Referer: https://mail.DOMAIN_REDACTED/"
2016/09/03 17:10:15 [debug] 41908#0: *24 http header: "Content-Length: 643"
2016/09/03 17:10:15 [debug] 41908#0: *24 http alloc large header buffer
2016/09/03 17:10:15 [debug] 41908#0: *24 http large header alloc: 00000000018EB670 8192
2016/09/03 17:10:15 [debug] 41908#0: *24 http large header copy: 548
2016/09/03 17:10:15 [debug] 41908#0: *24 http header: "Cookie: ZM_TEST=true; ZM_AUTH_TOKEN=REDACTED; JSESSIONID=REDACTED; ZM_ADMIN_AUTH_TOKEN=REDACTED"
2016/09/03 17:10:15 [debug] 41908#0: *24 http header: "Connection: keep-alive"
2016/09/03 17:10:15 [debug] 41908#0: *24 http header: "Cache-Control: max-age=0"
2016/09/03 17:10:15 [debug] 41908#0: *24 http header done
2016/09/03 17:10:15 [debug] 41908#0: *24 rewrite phase: 0
2016/09/03 17:10:15 [debug] 41908#0: *24 http script value: "http://zimbra_login"
2016/09/03 17:10:15 [debug] 41908#0: *24 http script set $login_upstream
2016/09/03 17:10:15 [debug] 41908#0: *24 http script var
2016/09/03 17:10:15 [debug] 41908#0: *24 http script var: "ZM_TEST=true; ZM_AUTH_TOKEN=REDACTED; JSESSIONID=REDACTED; ZM_ADMIN_AUTH_TOKEN=REDACTED"
2016/09/03 17:10:15 [debug] 41908#0: *24 http script regex: "ZM_AUTH_TOKEN="
2016/09/03 17:10:15 [notice] 41908#0: *24 "ZM_AUTH_TOKEN=" matches "ZM_TEST=true; ZM_AUTH_TOKEN=REDACTED; JSESSIONID=REDACTED; ZM_ADMIN_AUTH_TOKEN=REDACTED", client: IP_REDACTED, server: server1.DOMAIN_REDACTED.default, request: "POST /service/soap/BatchRequest HTTP/1.1", host: "mail.DOMAIN_REDACTED", referrer: "https://mail.DOMAIN_REDACTED/"
2016/09/03 17:10:15 [debug] 41908#0: *24 http script if
2016/09/03 17:10:15 [debug] 41908#0: *24 http script value: "http://zimbra_webclient"
2016/09/03 17:10:15 [debug] 41908#0: *24 http script set $login_upstream
2016/09/03 17:10:15 [debug] 41908#0: *24 test location: "/"
2016/09/03 17:10:15 [debug] 41908#0: *24 test location: "nginx_status"
2016/09/03 17:10:15 [debug] 41908#0: *24 test location: "service/soap/WaitSetRequest"
2016/09/03 17:10:15 [debug] 41908#0: *24 test location: "service/soap/NoOpRequest"
2016/09/03 17:10:15 [debug] 41908#0: *24 test location: ~ "/(service|principals|dav|\.well-known|home|octopus|shf|user|certauth|spnegoauth|(zimbra/home)|(zimbra/user))/"
2016/09/03 17:10:15 [debug] 41908#0: *24 using configuration "/(service|principals|dav|\.well-known|home|octopus|shf|user|certauth|spnegoauth|(zimbra/home)|(zimbra/user))/"
2016/09/03 17:10:15 [debug] 41908#0: *24 http cl:643 max:0
2016/09/03 17:10:15 [debug] 41908#0: *24 rewrite phase: 2
2016/09/03 17:10:15 [debug] 41908#0: *24 http script value: "8080"
2016/09/03 17:10:15 [debug] 41908#0: *24 http script set $mailhostport
2016/09/03 17:10:15 [debug] 41908#0: *24 http script complex value
2016/09/03 17:10:15 [debug] 41908#0: *24 http script var: "mail.DOMAIN_REDACTED"
2016/09/03 17:10:15 [debug] 41908#0: *24 http script set $relhost
2016/09/03 17:10:15 [debug] 41908#0: *24 http script var
2016/09/03 17:10:15 [debug] 41908#0: *24 http script var: "8080"
2016/09/03 17:10:15 [debug] 41908#0: *24 http script value: "80"
2016/09/03 17:10:15 [debug] 41908#0: *24 http script not equal
2016/09/03 17:10:15 [debug] 41908#0: *24 http script if
2016/09/03 17:10:15 [debug] 41908#0: *24 http script complex value
2016/09/03 17:10:15 [debug] 41908#0: *24 http script var: "mail.DOMAIN_REDACTED"
2016/09/03 17:10:15 [debug] 41908#0: *24 http script copy: ":"
2016/09/03 17:10:15 [debug] 41908#0: *24 http script var: "8080"
2016/09/03 17:10:15 [debug] 41908#0: *24 http script set $relhost
2016/09/03 17:10:15 [debug] 41908#0: *24 http script complex value
2016/09/03 17:10:15 [debug] 41908#0: *24 http script var: "mail.DOMAIN_REDACTED"
2016/09/03 17:10:15 [debug] 41908#0: *24 http script set $virtual_host
2016/09/03 17:10:15 [debug] 41908#0: *24 http script var
2016/09/03 17:10:15 [debug] 41908#0: *24 http script var: "mail.DOMAIN_REDACTED"
2016/09/03 17:10:15 [debug] 41908#0: *24 http script value: ""
2016/09/03 17:10:15 [debug] 41908#0: *24 http script equal
2016/09/03 17:10:15 [debug] 41908#0: *24 http script equal: no
2016/09/03 17:10:15 [debug] 41908#0: *24 http script if
2016/09/03 17:10:15 [debug] 41908#0: *24 http script if: false
2016/09/03 17:10:15 [debug] 41908#0: *24 post rewrite phase: 3
2016/09/03 17:10:15 [debug] 41908#0: *24 generic phase: 4
2016/09/03 17:10:15 [debug] 41908#0: *24 generic phase: 5
2016/09/03 17:10:15 [debug] 41908#0: *24 access phase: 6
2016/09/03 17:10:15 [debug] 41908#0: *24 access phase: 7
2016/09/03 17:10:15 [debug] 41908#0: *24 access phase: 8
2016/09/03 17:10:15 [debug] 41908#0: *24 post access phase: 9
2016/09/03 17:10:15 [debug] 41908#0: *24 http client request body preread 643
2016/09/03 17:10:15 [debug] 41908#0: *24 http request body content length filter
2016/09/03 17:10:15 [debug] 41908#0: *24 http init upstream, client timer: 0
2016/09/03 17:10:15 [debug] 41908#0: *24 http script copy: "X-Forwarded-For: "
2016/09/03 17:10:15 [debug] 41908#0: *24 http script var: "IP_REDACTED"
2016/09/03 17:10:15 [debug] 41908#0: *24 http script copy: "^M
"
2016/09/03 17:10:15 [debug] 41908#0: *24 http script copy: "Host: "
2016/09/03 17:10:15 [debug] 41908#0: *24 http script var: "mail.DOMAIN_REDACTED"
2016/09/03 17:10:15 [debug] 41908#0: *24 http script copy: "^M
"
2016/09/03 17:10:15 [debug] 41908#0: *24 http script copy: "Connection: close^M
"
2016/09/03 17:10:15 [debug] 41908#0: *24 http script copy: "Content-Length: "
2016/09/03 17:10:15 [debug] 41908#0: *24 http script var: "643"
2016/09/03 17:10:15 [debug] 41908#0: *24 http script copy: "^M
"
2016/09/03 17:10:15 [debug] 41908#0: *24 http proxy header: "User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.9; rv:42.0) Gecko/20100101 Firefox/42.0"
2016/09/03 17:10:15 [debug] 41908#0: *24 http proxy header: "Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"
2016/09/03 17:10:15 [debug] 41908#0: *24 http proxy header: "Accept-Language: en-US,en;q=0.5"
2016/09/03 17:10:15 [debug] 41908#0: *24 http proxy header: "Accept-Encoding: gzip, deflate, br"
2016/09/03 17:10:15 [debug] 41908#0: *24 http proxy header: "DNT: 1"
2016/09/03 17:10:15 [debug] 41908#0: *24 http proxy header: "Content-Type: application/soap+xml; charset=utf-8"
2016/09/03 17:10:15 [debug] 41908#0: *24 http proxy header: "X-Zimbra-Csrf-Token: REDACTED"
2016/09/03 17:10:15 [debug] 41908#0: *24 http proxy header: "Referer: https://mail.DOMAIN_REDACTED/"
2016/09/03 17:10:15 [debug] 41908#0: *24 http proxy header: "Cookie: ZM_TEST=true; ZM_AUTH_TOKEN=REDACTED; JSESSIONID=REDACTED; ZM_ADMIN_AUTH_TOKEN=REDACTED"
2016/09/03 17:10:15 [debug] 41908#0: *24 http proxy header: "Cache-Control: max-age=0"
2016/09/03 17:10:15 [debug] 41908#0: *24 http proxy header:
"POST /service/soap/BatchRequest HTTP/1.0^M
X-Forwarded-For: IP_REDACTED^M
Host: mail.DOMAIN_REDACTED^M
Connection: close^M
Content-Length: 643^M
User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.9; rv:42.0) Gecko/20100101 Firefox/42.0^M
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8^M
Accept-Language: en-US,en;q=0.5^M
Accept-Encoding: gzip, deflate, br^M
DNT: 1^M
Content-Type: application/soap+xml; charset=utf-8^M
X-Zimbra-Csrf-Token: REDACTED^M
Referer: https://mail.DOMAIN_REDACTED/^M
Cookie: ZM_TEST=true; ZM_AUTH_TOKEN=REDACTED; JSESSIONID=REDACTED; ZM_ADMIN_AUTH_TOKEN=REDACTED^M
Cache-Control: max-age=0^M
^M
"
2016/09/03 17:10:15 [debug] 41908#0: *24 http cleanup add: 00000000018C9B00
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: examining uri:/service/soap/BatchRequest for REST
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: examining uri:/service/soap/BatchRequest for ActiveSync
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: examining uri:/service/soap/BatchRequest for EWS
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: examining uri:/service/soap/BatchRequest for caldav
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: search for ZM_AUTH_TOKEN
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: examining cookie value:ZM_TEST=true; ZM_AUTH_TOKEN=REDACTED; JSESSIONID=REDACTED; ZM_ADMIN_AUTH_TOKEN=REDACTED
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: found ZM_AUTH_TOKEN:REDACTED
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: got id:USERID_REDACTED from ZM_AUTH_TOKEN
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: routing by ZM_AUTH_TOKEN
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: search for ZM_AUTH_TOKEN
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: examining cookie value:ZM_TEST=true; ZM_AUTH_TOKEN=REDACTED; JSESSIONID=REDACTED; ZM_ADMIN_AUTH_TOKEN=REDACTED
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: found ZM_AUTH_TOKEN:REDACTED
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: got version:8.7.0_GA_1659 from ZM_AUTH_TOKEN
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: route lookup required to proxy request
2016/09/03 17:10:15 [debug] 41908#0: *24 http cleanup add: 00000000018C9B70
2016/09/03 17:10:15 [debug] 41908#0: *24 http finalize request: -4, "/service/soap/BatchRequest?" a:1, c:2
2016/09/03 17:10:15 [debug] 41908#0: *24 http request count:2 blk:0
2016/09/03 17:10:15 [debug] 41908#0: *24 zm lookup: fetch cached route:127.0.0.1:8080 for user:USERID_REDACTED
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: prepare upstream connection, try: 2
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: version in zm_auth_token: 8.7.0_GA_1659
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: upstream server 127.0.0.1:8080 returned by zmlookup is not defined in upstream block, fallback to IPHASH/Fair to pick an upstream from the upstream block
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: get ip hash peer, peers = 2 hash = 1165 selected peer index = 1 0002
2016/09/03 17:10:15 [debug] 41908#0: *24 exact_version_check is on
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: [::1]:8080 elected by iphash
2016/09/03 17:10:15 [debug] 41908#0: *24 http upstream connect: -2
2016/09/03 17:10:15 [debug] 41908#0: *24 http upstream request: "/service/soap/BatchRequest?"
2016/09/03 17:10:15 [debug] 41908#0: *24 http upstream send request handler
2016/09/03 17:10:15 [debug] 41908#0: *24 http upstream send request
2016/09/03 17:10:15 [error] 41908#0: *24 connect() failed (111: Connection refused) while connecting to upstream, client: IP_REDACTED, server: server1.DOMAIN_REDACTED.default, request: "POST /service/soap/BatchRequest HTTP/1.1", upstream: "http://[::1]:8080/service/soap/BatchRequest", host: "mail.DOMAIN_REDACTED", referrer: "https://mail.DOMAIN_REDACTED/"
2016/09/03 17:10:15 [debug] 41908#0: *24 http next upstream, 2
2016/09/03 17:10:15 [debug] 41908#0: *24 [upstream_fair] fp->current = 1, state = 4, pc->tries = 2, pc->data = 00000000018C9BD0
2016/09/03 17:10:15 [debug] 41908#0: *24 [upstream_fair] nreq for peer 1 @ 000000000189AD78/00007F7EEF225178 now -5, total -5, delta -1
2016/09/03 17:10:15 [debug] 41908#0: *24 finalize http upstream request: 502
2016/09/03 17:10:15 [debug] 41908#0: *24 finalize http proxy request
2016/09/03 17:10:15 [debug] 41908#0: *24 close http upstream connection: 23
2016/09/03 17:10:15 [debug] 41908#0: *24 http finalize request: 502, "/service/soap/BatchRequest?" a:1, c:1
2016/09/03 17:10:15 [debug] 41908#0: *24 http special response: 502, "/service/soap/BatchRequest?"
2016/09/03 17:10:15 [debug] 41908#0: *24 internal redirect: "/zmerror_upstream_502.html?"
2016/09/03 17:10:15 [debug] 41908#0: *24 rewrite phase: 0
2016/09/03 17:10:15 [debug] 41908#0: *24 http script value: "http://zimbra_login"
2016/09/03 17:10:15 [debug] 41908#0: *24 http script set $login_upstream
2016/09/03 17:10:15 [debug] 41908#0: *24 http script var
2016/09/03 17:10:15 [debug] 41908#0: *24 http script var: "ZM_TEST=true; ZM_AUTH_TOKEN=REDACTED; JSESSIONID=REDACTED; ZM_ADMIN_AUTH_TOKEN=REDACTED"
2016/09/03 17:10:15 [debug] 41908#0: *24 http script regex: "ZM_AUTH_TOKEN="
2016/09/03 17:10:15 [notice] 41908#0: *24 "ZM_AUTH_TOKEN=" matches "ZM_TEST=true; ZM_AUTH_TOKEN=REDACTED; JSESSIONID=REDACTED; ZM_ADMIN_AUTH_TOKEN=REDACTED", client: IP_REDACTED, server: server1.DOMAIN_REDACTED.default, request: "POST /service/soap/BatchRequest HTTP/1.1", upstream: "http://[::1]:8080/service/soap/BatchRequest", host: "mail.DOMAIN_REDACTED", referrer: "https://mail.DOMAIN_REDACTED/"
2016/09/03 17:10:15 [debug] 41908#0: *24 http script if
2016/09/03 17:10:15 [debug] 41908#0: *24 http script value: "http://zimbra_webclient"
2016/09/03 17:10:15 [debug] 41908#0: *24 http script set $login_upstream
2016/09/03 17:10:15 [debug] 41908#0: *24 test location: "/"
2016/09/03 17:10:15 [debug] 41908#0: *24 test location: "nginx_status"
2016/09/03 17:10:15 [debug] 41908#0: *24 test location: "service/soap/WaitSetRequest"
2016/09/03 17:10:15 [debug] 41908#0: *24 test location: ~ "/(service|principals|dav|\.well-known|home|octopus|shf|user|certauth|spnegoauth|(zimbra/home)|(zimbra/user))/"
2016/09/03 17:10:15 [debug] 41908#0: *24 test location: ~ "^/zmerror_.*\.html$"
2016/09/03 17:10:15 [debug] 41908#0: *24 using configuration "^/zmerror_.*\.html$"
2016/09/03 17:10:15 [debug] 41908#0: *24 http cl:643 max:0
2016/09/03 17:10:15 [debug] 41908#0: *24 rewrite phase: 2
2016/09/03 17:10:15 [debug] 41908#0: *24 post rewrite phase: 3
2016/09/03 17:10:15 [debug] 41908#0: *24 generic phase: 4
2016/09/03 17:10:15 [debug] 41908#0: *24 generic phase: 5
2016/09/03 17:10:15 [debug] 41908#0: *24 access phase: 6
2016/09/03 17:10:15 [debug] 41908#0: *24 access phase: 7
2016/09/03 17:10:15 [debug] 41908#0: *24 access phase: 8
2016/09/03 17:10:15 [debug] 41908#0: *24 post access phase: 9
2016/09/03 17:10:15 [debug] 41908#0: *24 content phase: 10
2016/09/03 17:10:15 [debug] 41908#0: *24 content phase: 11
2016/09/03 17:10:15 [debug] 41908#0: *24 content phase: 12
2016/09/03 17:10:15 [debug] 41908#0: *24 http filename: "/opt/zimbra/data/nginx/html/zmerror_upstream_502.html"
2016/09/03 17:10:15 [debug] 41908#0: *24 http static fd: 23
2016/09/03 17:10:15 [debug] 41908#0: *24 HTTP/1.1 502 Bad Gateway^M
Server: nginx^M
Date: Sat, 03 Sep 2016 22:10:15 GMT^M
Content-Type: text/html^M
Content-Length: 1159^M
Connection: keep-alive^M
ETag: "57605997-487"^M

2016/09/03 17:10:15 [debug] 41908#0: *24 http write filter: l:0 f:0 s:173
2016/09/03 17:10:15 [debug] 41908#0: *24 http output filter "/zmerror_upstream_502.html?"
2016/09/03 17:10:15 [debug] 41908#0: *24 http copy filter: "/zmerror_upstream_502.html?"
2016/09/03 17:10:15 [debug] 41908#0: *24 http postpone filter "/zmerror_upstream_502.html?" 00000000018CA6C8
2016/09/03 17:10:15 [debug] 41908#0: *24 http write filter: l:1 f:0 s:1332
2016/09/03 17:10:15 [debug] 41908#0: *24 http write filter limit 0
2016/09/03 17:10:15 [debug] 41908#0: *24 http write filter 0000000000000000
2016/09/03 17:10:15 [debug] 41908#0: *24 http copy filter: 0 "/zmerror_upstream_502.html?"
2016/09/03 17:10:15 [debug] 41908#0: *24 http finalize request: 0, "/zmerror_upstream_502.html?" a:1, c:2
2016/09/03 17:10:15 [debug] 41908#0: *24 http request count:2 blk:0
2016/09/03 17:10:15 [debug] 41908#0: *24 http finalize request: -4, "/zmerror_upstream_502.html?" a:1, c:1
2016/09/03 17:10:15 [debug] 41908#0: *24 set http keepalive handler
2016/09/03 17:10:15 [debug] 41908#0: *24 http close request
2016/09/03 17:10:15 [debug] 41908#0: *24 http log handler
2016/09/03 17:10:15 [debug] 41908#0: *24 hc free: 0000000000000000 0
2016/09/03 17:10:15 [debug] 41908#0: *24 hc busy: 00000000018A97D0 1

Where this is the important part (see +++++):

Code: Select all

2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: examining cookie value:ZM_TEST=true; ZM_AUTH_TOKEN=REDACTED; JSESSIONID=REDACTED; ZM_ADMIN_AUTH_TOKEN=REDACTED
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: found ZM_AUTH_TOKEN:REDACTED
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: got version:8.7.0_GA_1659 from ZM_AUTH_TOKEN
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: route lookup required to proxy request
2016/09/03 17:10:15 [debug] 41908#0: *24 http cleanup add: 00000000018C9B70
2016/09/03 17:10:15 [debug] 41908#0: *24 http finalize request: -4, "/service/soap/BatchRequest?" a:1, c:2
2016/09/03 17:10:15 [debug] 41908#0: *24 http request count:2 blk:0
2016/09/03 17:10:15 [debug] 41908#0: *24 zm lookup: fetch cached route:127.0.0.1:8080 for user:USERID_REDACTED
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: prepare upstream connection, try: 2
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: version in zm_auth_token: 8.7.0_GA_1659
+++++2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: upstream server 127.0.0.1:8080 returned by zmlookup is not defined in upstream block, fallback to IPHASH/Fair to pick an upstream from the upstream block+++++
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: get ip hash peer, peers = 2 hash = 1165 selected peer index = 1 0002
2016/09/03 17:10:15 [debug] 41908#0: *24 exact_version_check is on
2016/09/03 17:10:15 [debug] 41908#0: *24 zmauth: [::1]:8080 elected by iphash
2016/09/03 17:10:15 [debug] 41908#0: *24 http upstream connect: -2
2016/09/03 17:10:15 [debug] 41908#0: *24 http upstream request: "/service/soap/BatchRequest?"
2016/09/03 17:10:15 [debug] 41908#0: *24 http upstream send request handler
2016/09/03 17:10:15 [debug] 41908#0: *24 http upstream send request
2016/09/03 17:10:15 [error] 41908#0: *24 connect() failed (111: Connection refused) while connecting to upstream, client: IP_REDACTED, server: server1.DOMAIN_REDACTED.default, request: "POST /service/soap/BatchRequest HTTP/1.1", upstream: "http://[::1]:8080/service/soap/BatchRequest", host: "mail.DOMAIN_REDACTED", referrer: "https://mail.DOMAIN_REDACTED/"

I was able to resolve this by disabling zimbra-proxy by following the steps at the bottom of this page.

So yeah, bypassing nginx for webmail seems to solve most issues, we'll see next week (Ugh, I hate having Java facing the internet)...

PS. The wiki has a small mistake:
"zmprov ms `zmhostname` zimbraMailSSLPort 993" should be "zmprov ms `zmhostname` zimbraMailSSLPort 443"

[notext]

Unfortunately it would seem that applying Disable Web [Mail] Proxy In Single ZCS Server Environment stops users from authenticating via IMAP or POP3??? (in ZCS 8.7...)
Changes reverted, we'd rather have 502's on the web interface than not having email at all...

Code: Select all

# name server1.DOMAIN_REDACTED
zimbraAdminPort: 7071
zimbraAdminProxyPort: 9071
zimbraImapBindPort: 7143
zimbraImapCleartextLoginEnabled: TRUE
zimbraImapProxyBindPort: 143
zimbraImapSSLBindPort: 7993
zimbraImapSSLProxyBindPort: 993
zimbraMailMode: both
zimbraMailPort: 8080
zimbraMailProxyPort: 80
zimbraMailReferMode: reverse-proxied
zimbraMailSSLPort: 8443
zimbraMailSSLProxyPort: 443
zimbraPop3BindPort: 7110
zimbraPop3CleartextLoginEnabled: TRUE
zimbraPop3ProxyBindPort: 110
zimbraPop3SSLBindPort: 7995
zimbraPop3SSLProxyBindPort: 995
zimbraReverseProxyAdminEnabled: FALSE
zimbraReverseProxyHttpEnabled: TRUE
zimbraReverseProxyLookupTarget: TRUE
zimbraReverseProxyMailEnabled: TRUE
zimbraReverseProxyMailMode: redirect
zimbraReverseProxySSLToUpstreamEnabled: FALSE

zimbraServiceEnabled: proxy
zimbraServiceEnabled: memcached
zimbraServiceEnabled: mailbox

We will do further testing tonight...

[6125amartin]

You might be able to fix the IMAP/POP3 with no nginx problem by setting these tunables with zmprov:

zimbraImapCleartextLoginEnabled
zimbraPop3CleartextLoginEnabled

I've been working through the 502 errors in another thread as well and appear to have found a solution:
viewtopic.php?p=270573#p270573

After adjusting those settings, I was able to-reenable zimbra-proxy and I have not seen any 502 errors yet...