no access_log logging for UDP streams

[David Kewley]

On Wed, Feb 14, 2018 at 5:59 AM, Roman Arutyunyan <arut at nginx.com> wrote:

> Hi David,
>
> On Tue, Feb 13, 2018 at 01:01:03PM -0800, David Kewley wrote:
> > I'm using nginx 1.12.1 to proxy TCP and UDP streams. I have in my stream
> {}
> > stanza:
> >
> >   log_format  test  '$time_local';
> >
> >   access_log  /var/log/nginx/stream-access.log  test  buffer=64k
> flush=1s;
> >   error_log   /var/log/nginx/stream-info.log    info;
> >
> >
> > Both TCP and UDP streams log to /var/log/nginx/stream-info.log. Only TCP
> > streams are logged in /var/log/nginx/stream-access.log; UDP streams are
> not.
> >
> > FWIW, client application behavior and tcpdump both show that the upstream
> > UDP server is sending a response that makes it through nginx proxy to the
> > client just fine.
> >
> > Is this lack of UDP stream access_log logging expected, or should I open
> a
> > new bug?
> >
> > If you need to see more details to show exactly what I'm doing, let me
> know
> > which details would be helpful.
>
> Probably your UDP session is not considered finished by nginx.
> Did you specify proxy_responses and proxy_timeout in your config?
> If proxy_responses is unspecified and proxy_timeout is large, it may take a
> long time for a UDP session to expire and be logged.


Thank you, Roman! You pointed me in the right direction.

Now that I do more careful tests, I see the action of the default setting
of "proxy_timeout 10m" in the two logs (access and info). Namely,
info-level error_log shows client and proxy connections at the time they
happen, as well as the disconnect when the 10m timeout happens. Meanwhile
the access_log logs the connection at the time of disconnection (after the
10m timeout).

I'm thinking that in many circumstances, I may not know how many response
packets to expect from the upstream, so proxy_responses may not be optimal.
But setting proxy_timeout shorter may in many cases help me by logging in
access_log sooner.

I've started by setting proxy_timeout 1s in a situation where each
application message stream is expected to be quick and very short-lived.
Now I see entries in access_log quickly.

David
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.nginx.org/pipermail/nginx/attachments/20180214/a5e671c2/attachment.html>