Problem running nginx in a container

[Francis Daly]

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[]=/_eiVamsWTAQ12l6UF7vBn495f4U5LAGxhZ0nSBHjARdRjXwgf35Z7yvyZwvKejLSOPeJBrY8J_XpMKC_ukp5jM8z9FT0uhT3hH51K4THDw7GWMitAjdQNx1SGw_qF04hNvcQ4_eWaUXxSPiR0vizLEVBScYBZIEXYDHWVTVKbVTYbETLW3kpq214FuLRHhwWLyxjeACQwoxxucaj_uLcm7oyzQjwwUOV9PQKA7l9BPkq0Oq63sFEBS_vVhIplQ6EmFq59lxuSrZiDlhSBOdLIW8h2xD1kz9Twb_-qzwelpHuF-84Lbdg8tUpE7BYbUyU76La5BcFSREyf7qvm8e_mszUfh_Zac-63pk8jrdwmgQEApa0OPJL4NAXTimMG-JmbS9CCPvoGzGmoj12afq0CcwrkmxJI2Z00N2HbfrIns69INt-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[]=/_eiVamsWTAQ12l6UF7vBn495f4U5LAGxhZ0nSBHjARdRjXwgf35Z7yvyZwvKejLSOPeJBrY8J_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[]=/_eiVamsWTAQ12l6UF7vBn495f4U5LAGxhZ0nSBHjARdR"..., 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[]=/_eiVamsWTAQ12l6UF7vBn495f4U5LAGxhZ0nSBHjARdRjXwgf35Z7yvyZwvKejLSOPeJBrY8J_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[]=/_eiVamsWTAQ12l6UF7vBn495f4U5LAGxhZ0nSBHjARdR"..., 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.

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