Sporadic long response times with upstream server

[joncard]

Thank you for your response, and for your patience with my delays. I have
set up a tcpdump log, to see if this may be problem, but it'll have to wait
until the next time the glitch happens to get a reading.

I have admin access to all servers, and host box. I had added timing logs
consistent with (https://www.lunchbadger.com/blog/tra
cking-the-performance-of-express-js-routes-and-middleware) to the Node.js
scripts. So the timeline for the requests seems to be:

2019-02-20T13:36:09.276959Z - Timestamp on load balancer access log
(presumably, this timestamp is on receipt of the request, even though it
logs the timing of of the response. The docs here
(https://docs.aws.amazon.com/elasticloadbalancing/latest/application/load-balancer-access-logs.html#access-log-entry-format)
seem to imply it is the end of the response, but this doesn't make much
sense with the values provided)
[13:36:12.328] 
[13:36:12.329] 
[13:36:12.330]
[13:36:12.359]  - Timestamps in Node.js logs. There are several logs entries
during the fulfillment of the request, written live, so there is no
cconfusion about whether the timestamp reflects the receipt of the request
or end of the response. (For weird reasons I don't think are relevant, the
third one is when the response is sent and the fourth one is when additional
processing for the request is finished after the response is sent. Response
back to Nginx is about 2ms; the additional 28 or 29 seconds is not relevant
to Nginx)
20/Feb/2019:13:36:12 +0000 - Timestamp in Nginx describing the 3.052 second
fulfillment time. Does not have millisecond resolution, but is consistent
with the 3 second reported duration, the timestamp from the load balancer,
and the timing information from Node.js.

The conclusion I have is that the delay is somewhere between the load
balancer receiving the request and Nginx dispatching the request to Node.js,
and Nginx is returning the response from Node.js immediately.

I do not have an explanation for why the timestamp on the load balancer
seems to for the time of the receipt of the request, and not for the time of
finished fulfillment.

All clients are actually the same kind of device. This application is being
hosted by the manufacturer of an RTOS embedded system, and in support of
features for clients running "in the wild". This endpoint is connected to
every 15 minutes by clients running the new release of their OS, and the
same client connected with no problems at 2019-02-20T13:21:08.136315Z, 15
minutes before. It's also why a single response of 3 seconds is being
treated as a big deal, and why we have done so much to ensure fast response
times. The feature can be deactivated, of course, but if it is running, fast
response is very important.

Posted at Nginx Forum: https://forum.nginx.org/read.php?2,283099,283125#msg-283125