Problem running nginx in a container

Tue Feb 8 05:31:55 UTC 2022

Hi, I ran another case with error_log debug.  Here are 4 files:

error.log.2: https://1drv.ms/u/s!ApcymW6zCVpnuxyYecXcaIlqrVWu?e=WmgaVO
error.log.1: https://1drv.ms/u/s!ApcymW6zCVpnuxt2oIE3eLklkND0?e=ZlJNGH
access.log.2: https://1drv.ms/u/s!ApcymW6zCVpnuxgl1jCmHH8O-Pmi?e=GJGQgI
access.log.1: https://1drv.ms/u/s!ApcymW6zCVpnuxpdqNOQOt3pOMbX?e=Hmtz9Z

The files ending in .2 is when docker-compose up -d was used. The files
ending in .1 is when the docker-compose restart was used.

I turned on log_level to debug on the php-fpm side and I cannot see anything
that can explain what is going on.

See below in your reply I posted a question.

Francis Daly Wrote:
-------------------------------------------------------
> On Sun, Feb 06, 2022 at 10:08:49PM -0500, marioja2 wrote:
> 
> Hi there,
> 
> > I checked and the output when starting from docker-compose up -d or
> > docker-compose restart is identical. I include it here:
> > https://1drv.ms/u/s!ApcymW6zCVpnuwKQOFFbSCLiZhn9?e=bvrpJU
> 
> Thanks; that is useful to see what nginx thinks the config is.
> 
> > Generally, you want something of the form:
> > 
> > I make *this* request
> > I get *this* response
> > I want *that* response instead
> > 
> > ideally with enough information to allow someone else to repeat what
> you are
> > doing.
> 
> > I ran strace on nginx and I have to trace files.  This is the trace
> file
> > when start with docker-compose up -d:
> > https://1drv.ms/u/s!ApcymW6zCVpnun28ya8wIBQi9qEt?e=AqzHfI
> > This is the trace file when I start with docker-compose restart:
> > https://1drv.ms/u/s!ApcymW6zCVpnuwFnO5IT-2bERyHI?e=FzZxuD
> 
> In this case, I think that the strace output does show something
> useful, because...
> 
> > webmail_1    | 2022/02/07 02:08:18 [warn] 25#25: *145 a client
> request body
> > is buffered to a temporary file
> /var/lib/nginx/tmp/client_body/0000000005,
> > client: 192.168.200.6, server: , request: "POST
> >
> /?/Upload/&q[]=/_eiVamsWTAQ12l6UF7vBn495f4U5LAGxhZ0nSBHjARdRjXwgf35Z7y
> vyZwvKejLSOPeJBrY8J_XpMKC_ukp5jM8z9FT0uhT3hH51K4THDw7GWMitAjdQNx1SGw_q
> F04hNvcQ4_eWaUXxSPiR0vizLEVBScYBZIEXYDHWVTVKbVTYbETLW3kpq214FuLRHhwWLy
> xjeACQwoxxucaj_uLcm7oyzQjwwUOV9PQKA7l9BPkq0Oq63sFEBS_vVhIplQ6EmFq59lxu
> SrZiDlhSBOdLIW8h2xD1kz9Twb_-qzwelpHuF-84Lbdg8tUpE7BYbUyU76La5BcFSREyf7
> qvm8e_mszUfh_Zac-63pk8jrdwmgQEApa0OPJL4NAXTimMG-JmbS9CCPvoGzGmoj12afq0
> CcwrkmxJI2Z00N2HbfrIns69INt-G-x34tdDwo2k/
> > HTTP/1.1", host: "mailu.company.local:444", referrer:
> > "https://mailu.company.local:444/webmail/"
> 
> The request that you care about is a POST to a url which includes the
> word Upload.
> 
> $ grep -n Upload nginx_strace.26
> 636:     0.000041 recvfrom(15, "POST
> /?/Upload/&q[]=/_eiVamsWTAQ12l6UF7vBn495f4U5LAGxhZ0nSBHjARdRjXwgf35Z7y
> vyZwvKejLSOPeJBrY8J_XpMK"..., 1024, 0, NULL, NULL) = 1024
> 2502:     0.000096 writev(17,
> [{iov_base="\1\1\0\1\0\10\0\0\0\1\1\0\0\0\0\0\1\4\0\1\r\35\3\0\f\200\0
> \1\313QUERY_STRING/Upload/&q[]=/_eiVamsWTAQ12l6UF7vBn495f4U5LAGxhZ0nSB
> HjARdR"..., iov_len=3400}], 1) = 3400
> 2964:     0.000062 writev(15, [{iov_base="HTTP/1.1 200 OK\r\nDate:
> Mon, 07 Feb 2022 01:36:10 GMT\r\nContent-Type: application/json;
> charset=utf-8"..., iov_len=436}, {iov_base="46\r\n", iov_len=4},
> {iov_base="{\"Action\":\"Upload\",\"Result\":{\"ErrorCode\":1,\"Error\
> ":\"File is too big\"}}", iov_len=70}, {iov_base="\r\n", iov_len=2},
> {iov_base="0\r\n\r\n", iov_len=5}], 5) = 517
> 
> $ grep -n Upload nginx_strace.25
> 488:     0.000134 recvfrom(15, "POST
> /?/Upload/&q[]=/_eiVamsWTAQ12l6UF7vBn495f4U5LAGxhZ0nSBHjARdRjXwgf35Z7y
> vyZwvKejLSOPeJBrY8J_XpMK"..., 1024, 0, NULL, NULL) = 1024
> 2393:     0.000183 writev(17,
> [{iov_base="\1\1\0\1\0\10\0\0\0\1\1\0\0\0\0\0\1\4\0\1\r\35\3\0\f\200\0
> \1\313QUERY_STRING/Upload/&q[]=/_eiVamsWTAQ12l6UF7vBn495f4U5LAGxhZ0nSB
> HjARdR"..., iov_len=3400}], 1) = 3400
> 2847:     0.000064 writev(15, [{iov_base="HTTP/1.1 200 OK\r\nDate:
> Mon, 07 Feb 2022 01:37:26 GMT\r\nContent-Type: application/json;
> charset=utf-8"..., iov_len=410}, {iov_base="bd\r\n", iov_len=4},
> {iov_base="{\"Action\":\"Upload\",\"Result\":{\"Attachment\":{\"Name\"
> :\"5kplayer-setup (2).exe\",\"TempName\":\"upload-post-"...,
> iov_len=189}, {iov_base="\r\n", iov_len=2}, {iov_base="0\r\n\r\n",
> iov_len=5}], 5) = 610
> 
> That looks like, in both cases, nginx sent a HTTP success (200 OK)
> message, with differing json body content. One has Result: Attachment;
> the other has Result: ErrorCode.
> 
> In both cases, it appears that the response came after nginx wrote the
> request to the fastcgi server.

I am not sure what you mean by "the response came after nginx wrote the
request to the fastcgi server".  I thought the response is the HTTP response
to the person that issued the POST (which in my case is another container
running nginx also) I do not understand what the fastcgi server has to do
here. I do not understand the configuration in rainloop.conf for the php-fpm
stuff nor do I understand where it plays in the whole transaction.

> 
> So, unless you have something unusual going on, that "File is too big"
> came from the php-fpm service, not from nginx.
> 
> That does not help resolve the inconsistency between an "up" and a
> "restart" on the docker-compose side; but it does suggest that the
> difference is on the php side, not the nginx side.
> 
> 
> So possibly, try the same thing, but see if you can find the php /
> fastcgi server state in both cases, and see if there is any obvious
> difference there.
> 
> If you do want to get fuller nginx logging, then in the rainloop.conf
> file:
> 
> > >     # /dev/stdout (Default), <path>, off
> > >     access_log off;
> > > 
> > >     # /dev/stderr (Default), <path>, debug, info, notice, warn,
> error, 
> > > crit, alert, emerg
> > >     error_log /dev/stderr warn;
> 
> Remove those lines, so that the "http"-level config will apply.
> 
> > > The error that occurs after docker-compse up -d is that a 5MB 
> > > attachment posted to the webmail container fails.
> > 
> > I'm guessing that's a HTTP 413 coming direct from nginx; not any
> message
> > from the fastcgi service; and not a HTTP 502 coming direct from
> nginx?
> 
> From the strace output, I think I guessed wrong. The error seems not
> to
> be coming from nginx.
> 
> Cheers,
> 
> 	f
> -- 
> Francis Daly        francis at daoine.org
> _______________________________________________
> nginx mailing list -- nginx at nginx.org
> To unsubscribe send an email to nginx-leave at nginx.org

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