[horde] Proxy errors to downstream Horde server

Mon Jun 10 12:10:36 UTC 2013

>> Quoting Simon Wilson <simon at simonandkate.net>:
>>
>>> My Horde box is reverse proxied by an Apache box - that box  
>>> consistently logs these errors about every one to two minutes:
>>>
>>> [Sun Jun 09 20:56:35 2013] [error] [client 59.167.157.243]  
>>> (70007)The timeout specified has expired: proxy: error reading  
>>> status line from remote server 192.168.1.230
>>> [Sun Jun 09 20:56:35 2013] [error] [client 59.167.157.243] proxy:  
>>> Error reading from remote server returned by  
>>> /Microsoft-Server-ActiveSync
>>>
>>> [Sun Jun 09 20:58:36 2013] [error] [client 59.167.157.243]  
>>> (70007)The timeout specified has expired: proxy: error reading  
>>> status line from remote server 192.168.1.230
>>> [Sun Jun 09 20:58:36 2013] [error] [client 59.167.157.243] proxy:  
>>> Error reading from remote server returned by  
>>> /Microsoft-Server-ActiveSync
>>>
>>> [Sun Jun 09 21:00:39 2013] [error] [client 59.167.157.243]  
>>> (70007)The timeout specified has expired: proxy: error reading  
>>> status line from remote server 192.168.1.230
>>> [Sun Jun 09 21:00:39 2013] [error] [client 59.167.157.243] proxy:  
>>> Error reading from remote server returned by  
>>> /Microsoft-Server-ActiveSync
>>>
>>> Everything seems to be working OK, and there are no issues logged  
>>> at the actual Horde server...
>>> The proxy's apache access log has entries like this recorded as  
>>> originating at 120 seconds before each error pair:
>>>
>>> 59.167.157.243 - - [09/Jun/2013:20:54:35 +1000] "POST  
>>> /Microsoft-Server-ActiveSync?Cmd=Ping&User=simon%40simonandkate.net&DeviceId=SEC10D1C297BE813&DeviceType=SAMSUNGGTI9500 HTTP/1.1" 502 434 "-"  
>>> "SAMSUNG-GT-I9500/101.40202"
>>>
>>> 59.167.157.243 - - [09/Jun/2013:20:56:36 +1000] "POST  
>>> /Microsoft-Server-ActiveSync?Cmd=Ping&User=simon%40simonandkate.net&DeviceId=SEC10D1C297BE813&DeviceType=SAMSUNGGTI9500 HTTP/1.1" 502 434 "-"  
>>> "SAMSUNG-GT-I9500/101.40202"
>>>
>>> 59.167.157.243 - - [09/Jun/2013:20:58:39 +1000] "POST  
>>> /Microsoft-Server-ActiveSync?Cmd=Ping&User=simon%40simonandkate.net&DeviceId=SEC10D1C297BE813&DeviceType=SAMSUNGGTI9500 HTTP/1.1" 502 434 "-"  
>>> "SAMSUNG-GT-I9500/101.40202"
>>
>> These are almost certainly a result of the proxy timeout being  
>> reached before the PING has finished running on the server. If you  
>> google for something like "apache reverseproxy activesync 502" you  
>> will find information regarding this and how to fix it.
>
> Thanks Mike... there are a lot of topics in google that dance around  
> it but not much definitive. I will try keep alives, and extending  
> connection timeout and see how that goes.
>
>>
>>> So my Samsung S4 is sending that POST request every minute or two  
>>> (seems excessive?)
>>
>> This is because the device is sensing that the PING failed or the  
>> connection dropped, so it retries it again. At some point, the  
>> client is supposed to throttle itself.
>>
>>> and it is logged by the proxy server, and every time it is  
>>> followed 120 seconds later by the proxy server logging the pair of  
>>> errors, and a 502 recorded by the proxy.
>>>
>>> The internal Horde server appears to be receiving the requests. e.g.:
>>>
>>> 192.168.1.155 - simon at simonandkate.net [09/Jun/2013:20:58:37  
>>> +1000] "POST  
>>> /Microsoft-Server-ActiveSync?Cmd=Ping&User=simon%40simonandkate.net&DeviceId=SEC10D1C297BE813&DeviceType=SAMSUNGGTI9500 HTTP/1.1" 200  
>>> -
>>>
>>> The Horde server's Apache error logs are empty, so it is happy  
>>> that it's done what it needs to (200 result), but for some reason  
>>> it's not sending something back to the proxy. The Samsung  
>>> ActiveSync functionally is working fine.
>>>
>>>
>>> When my Apple devices Post, e.g.:
>>>
>>>
>>> 59.167.157.243 - - [09/Jun/2013:21:06:24 +1000] "POST  
>>> /Microsoft-Server-ActiveSync?User=katie&DeviceId=ApplDLXFT8GMDKNW&DeviceType=iPad&Cmd=Ping HTTP/1.1" 200 27 "-"  
>>> "Apple-iPad2C2/1002.329"
>>>
>>> It's doing it approximately every 10 to 15 minutes (as opposed to  
>>> every 1 or 2 for the Samsung).
>>>
>>> This is the corresponding request on the Horde internal box:
>>>
>>> 192.168.1.155 - katie [09/Jun/2013:21:06:22 +1000] "POST  
>>> /Microsoft-Server-ActiveSync?User=katie&DeviceId=ApplDLXFT8GMDKNW&DeviceType=iPad&Cmd=Ping HTTP/1.1" 200  
>>> 27
>>>
>>> So that is complete end to end with 200s.
>>>
>>>
>>> Something about the Samsung's POST request or the way it is being  
>>> handled by the proxy or Horde is causing it to get 502s and  
>>> generate errors, where the Apples requests complete fine. As a  
>>> result, the Samsung is POSTing every 1 or 2 minutes...
>>
>> Either because the heartbeat interval is different for each client  
>> or it's coincidence that the PING ended naturally due to a detected  
>> change when the iOS device was being watched.
>>
>>
>> -- 
>> mike
>>
>
> To be honest I think I may be better off having the Horde server as  
> the first stop, and have it then proxy to the other sites, rather  
> than the current arrangement where the static server proxies the  
> Horde server.
>
> But that will have to wait until the end of the month. It appears to  
> be working OK despite the 502 errors, so I'll try the config fixes  
> and then decide what to do.
>
> Thanks Mike for your response.
>
> Simon.
>
> --

A quick config change to the proxypass timeout with "connectiontimeout  
300 timeout 300" makes no discernable difference, so even with 5  
minutes timeout I am still getting just as many of the 502s.

How long should the ping process take? and how do I identify when it  
starts finished in the device log?

 From what I can see a pid is held from the auth request at the start  
of a PING through to that pid disappearing from the logs for between 2  
and 4 minutes.

Or is there something else that it continues to do that needs to be  
kept alive for the PING request?

Simon.

--
Simon Wilson
M: 0400 12 11 16
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-keys
Size: 1339 bytes
Desc: PGP Public Key
URL: <http://lists.horde.org/archives/horde/attachments/20130610/1a774d1b/attachment.bin>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 198 bytes
Desc: PGP Digital Signature
URL: <http://lists.horde.org/archives/horde/attachments/20130610/1a774d1b/attachment-0001.bin>