Errorlog shows GET timeout; Accesslog shows POST

[Francis Daly]

On Fri, May 20, 2016 at 03:45:15PM -0400, bclod wrote:

Hi there,

> We've implemented a lightweight APIGW on nginx 1.9.9 using openresty
> packages to customize the handling/proxying logic.  We have dozens clients
> that are able to leverage this implementation just fine.

I suspect that the details of the request/response, or at least the
details of what the request-data flow-response is supposed to be, will
be useful in finding and fixing the problem.

> We have one client that is experiencing some weird issues when trying to
> access our APIGW. This is only for certain requests coming from their app. 
> We strongly believe it's a malformed request from their side but we're
> trying to help them find the issue.

Do you know what your side expects the request to be? (your API design.)

Can you see what request your side receives? (tcpdump/ssldump, or perhaps
nginx-side extra logging.)

If they differ, that points at where the problem is.

> The behavior we see on our side is
> quite strange as well.  The error.log will show a GET request that timed
> out.

The error log entry shows that nginx thinks that the requesting client
closed the connection before nginx was ready to close the connection.

That might be "timed out", or might be "error".

> The access.log shows a POST request for the same request.  Below are
> the two entries; the response time always seems to be around 5 seconds; but
> lowest timeout explicitly set in our configuration is 10 seconds. 

The access log seems very customised to your site; and includes
some variables that are not nginx-default. Perhaps they are
openresty-default? (Google doesn't make it look like they obviously
are.)

You say "timeout explicitly set in our configuration". If it was the
client that closed the connection because its idea of a timeout passed,
then your configuration is irrelevant unless it sets the client-side
timeout.

> |LOCATION:GATEWAY|CN:NA|SSLPROTOCOL:TLSv1|SSLCIPHER:ECDHE-RSA-AES256-SHA|SERVICE:NA|VERSION:1|CLIENT:NA|BACKEND:|HTTPMETHOD:POST|ACCEPT:application/json;

HTTPMETHOD there is $upstream_method, which is not (by default) what
the client sent to nginx.

I think that there's not enough information here to allow someone else
discover the problem. If you can make a reproducible failure case,
that will probably make it easier to discover.

Good luck with it,

	f
-- 
Francis Daly        francis at daoine.org