search

openresty / docker-openresty

Docker tooling for OpenResty
https://hub.docker.com/r/openresty/openresty
BSD 2-Clause "Simplified" License
937 stars 525 forks source link

Logs do not appear in docker-compose #91

Open drasko opened 5 years ago

drasko commented 5 years ago

I am runnig openresty docker from docker-compose with other services, and only openresty do not print anything on stdout.

I have no idea where access.log and error.log are going, and if they are buffered or what - but they are no printed in the logs of docker-cmpose.

drasko commented 5 years ago

Also this:

content_by_lua '
   ngx.log(ngx.ERR, "Hello HTTP")
   ngx.log(ngx.ERR, ngx.var.ssl_client_cert)
';

is never printed on the screen.

drasko commented 5 years ago

Very strange, upon:

docker-compose -f docker/docker-compose.yml restart openresty

openresty spits all previous log on stdout and from there on starts sending access logs on stdout. Looks like something was cached previously. How to disable this caching?

Also, ony access.log is printed, i still does not print ngx.log(ngx.ERR, "Hello HTTP").

drasko commented 5 years ago

Indeed, docker-compose -f docker/docker-compose.yml restart openresty makes container dump all the logs on restart. I thought that these logs are outputed on stdout and never saved. If they are - where are these logs saved?

neomantra commented 5 years ago

The Usage section of the README says:

docker-openresty symlinks /usr/local/openresty/nginx/logs/access.log and error.log to /dev/stdout and /dev/stderr respectively, so that Docker logging works correctly. If you change the log paths in your nginx.conf, you should symlink those paths as well. This is not possible with the windows image.

This symlinking happens in the Dockerfile.

drasko commented 5 years ago

@neomantra yes, I am aware of this, and I saw that same technique is applied in official NginX Dockerfile.

However - NginX logs work like a charm, everything is printed on stdout and visible in docker-compose logs. But OpenResty logs are not, and they have this strange behavior - upon starting composition OpenResty container is silent. Then upon restart (restarting only this one container, while keeping other in composition running), it spits out all logs and from there on continues outputting access log on stdout.

What I am trying to do is to enable OpenResty for Mainflux IoT platform, and I just pushed the docker-compose.yml and nginx.conf on resty branch over there.

drasko commented 5 years ago

Is it possible that docker buffers stdout and not printing logs but saving them somewhere? because I can see that upon restart of this container all previous logs are spit on the screen...

And from this restart on logging works as it is supposed.

BTW, different engineers from our team thested this on different machines - same behaviour.

neomantra commented 5 years ago

What happens if you do docker logs on the raw container... meaning outside of your docker-compose run .

Edit: I mean, start with docker-compose and witness the buffering... then look at the raw containers with docker ps and try to docker logs the relevant one... do you see anything? Restart image as you say... then what's it look like?

drasko commented 5 years ago

Running container without docker-compose (and with without adding custom nginx.conf) logging works just fine:

drasko@Marx:~/go/src/github.com/mainflux/mainflux$ docker run -p 127.0.0.1:8000:80 openresty/openresty:alpine
172.17.0.1 - - [16/Mar/2019:15:44:32 +0000] "GET / HTTP/1.1" 200 649 "-" "curl/7.64.0"
172.17.0.1 - - [16/Mar/2019:15:44:35 +0000] "GET / HTTP/1.1" 200 649 "-" "curl/7.64.0"
172.17.0.1 - - [16/Mar/2019:15:44:35 +0000] "GET / HTTP/1.1" 200 649 "-" "curl/7.64.0"
172.17.0.1 - - [16/Mar/2019:15:44:36 +0000] "GET / HTTP/1.1" 200 649 "-" "curl/7.64.0"
172.17.0.1 - - [16/Mar/2019:15:44:37 +0000] "GET / HTTP/1.1" 200 649 "-" "curl/7.64.0"

Error is thus either in a custom nginx.conf or in docker-compose.

neomantra commented 5 years ago

I was Googling a bit and it seems there's some nuance or issues with docker-compose and buffering. If you think there's something with the image, I can try to help and point at things.

mainflux looks great btw.

drasko commented 5 years ago

I tried to use raw docker (without docker-compose) and custom ngin.conf - works like a charm:

drasko@Marx:~/go/src/github.com/mainflux/mainflux$ docker run --volume `pwd`/docker/nginx.conf:/usr/local/openresty/nginx/conf/nginx.conf --volume `pwd`/docker/ssl/certs/mainflux-server.crt:/etc/ssl/certs/mainflux-server.crt --volume `pwd`/docker/ssl/certs/mainflux-server.key:/etc/ssl/private/mainflux-server.key --volume `pwd`/docker/ssl/certs/ca.crt:/etc/ssl/certs/ca.crt --volume `pwd`/docker/ssl/dhparam.pem:/etc/ssl/certs/dhparam.pem -p 127.0.0.1:443:443 openresty/openresty:alpine
2019/03/16 15:57:27 [error] 8#8: *1 [lua] content_by_lua(nginx.conf:130):2: Hello HTTP, client: 172.17.0.1, server: localhost, request: "POST /users HTTP/2.0", host: "localhost"
2019/03/16 15:57:27 [error] 8#8: *1 [lua] content_by_lua(nginx.conf:130):3: -----BEGIN CERTIFICATE-----
    MIIEPzCCAyegAwIBAgIUWiGAGgp81v+arKsrWTfcC1ftePYwDQYJKoZIhvcNAQEN
    BQAwVzESMBAGA1UEAwwJbG9jYWxob3N0MREwDwYDVQQKDAhNYWluZmx1eDEMMAoG
    A1UECwwDSW9UMSAwHgYJKoZIhvcNAQkBFhFpbmZvQG1haW5mbHV4LmNvbTAeFw0x
    OTAzMTUwMTQ5MTRaFw0zMjAzMTEwMTQ5MTRaMBoxGDAWBgNVBAMMD21haW5mbHV4
    LWNsaWVudDCCASIwDQYJKoZIhvcNAQEBBQADggEPADCCAQoCggEBAKeB9GyR8Gij
    t7otk+cPtvFmhq5o5ZaT08hMRNTk6gpFrIH/9qgSDmZ45upjrdT2+GkV5QvtjI7V
    /ooS/Rdy0JOUHPRTVxOonwo04Sxy2KD4NyofN9mylOTV4LPDvq4+aggW/6OqOZVV
    ZlbIKfuNeMTxpqwJrJhVLwzySX9aoU4RHLm130kXdvJg/9d1qWKikyx7nXt0rDyB
    qLdHd6adsApQpcjAkzoQQdy6EojpJlUmV+5p6QgAMoM0X4Jy2zkulvR0tSb9rFJ/
    Cm1iAX77BfYtx6quCW06xnua4a0tDw08lPzlyioXZEQhDFWyuyOFtRMUTwJAaWB8
    Zf93O9somwcCAwEAAaOCAT4wggE6MAwGA1UdEwEB/wQCMAAwCQYDVR0RBAIwADAR
    BglghkgBhvhCAQEEBAMCBaAwHQYDVR0lBBYwFAYIKwYBBQUHAwIGCCsGAQUFBwME
    MAsGA1UdDwQEAwIDqDAqBglghkgBhvhCAQ0EHRYbTWFpbmZsdXggQ2xpZW50IENl
    cnRpZmljYXRlMB0GA1UdDgQWBBRGHgljTWjgTGkdEcfao1ftbweprjCBlAYDVR0j
    BIGMMIGJgBQL5KQHaahMjqzJ7Qw+Pei5vcUX+qFbpFkwVzESMBAGA1UEAwwJbG9j
    YWxob3N0MREwDwYDVQQKDAhNYWluZmx1eDEMMAoGA1UECwwDSW9UMSAwHgYJKoZI
    hvcNAQkBFhFpbmZvQG1haW5mbHV4LmNvbYIUaWUcPgOJU9qDuLX+ocvK5yb7NVww
    DQYJKoZIhvcNAQENBQADggEBAIkz0So+uY83BwC3dAchOFhpVtc85kG64SYLr+yJ
    r4BACcTCP+v9wrxViYXk+gtZbGTqRhpuxks699Wub6htGlb4D7oazcVjkwBObAjl
    d9r3MZqH9SVgNdiLFKY67/EzTvGWPsuNAmVsppQRslGCfaBMBBG5gMwTxOxWObRA
    rvXRWOTTvsqsMu8tClkutC6iiB5CWpjdXe2RN3ZeOxPh5kjBmHEoRdEkBKgPWJmy
    7+2OwMzM6wLOXQOGMWLsx3VGbSDDlRuedcp3WNSOw8tH+P6cexGeicOEvh86qmX5
    /j/okK5WgFMB1UPQRpW8ZaFKdr7ZHCbCWhzslle7JUOwXk4=
    -----END CERTIFICATE-----, client: 172.17.0.1, server: localhost, request: "POST /users HTTP/2.0", host: "localhost"
172.17.0.1 - - [16/Mar/2019:15:57:27 +0000] "POST /users HTTP/2.0" 200 0 "-" "curl/7.64.0"

Does exactly what I need - logs all access and also logs Lua prints (which in this case print out received client certificate).

I can not obtain these logs and especially this printfs from Lua even after container restart in docker-compose. I.e. after container restart in docker-copose I have access log, that logs accessed HTTP URLs, but I still do not have these nice prits from Lua that I need.

drasko commented 5 years ago

@neomantra thanks - I would like to investigate and solve this, because we really want to use OpenResty in Mainflux and allow mTLS and full X.509 client-side cert support for MQTT and other protocols.

What is strange is that official NginX image which uses the same mechianism of symlinking in the Dockerfile works fine out of the box with the same docker-compose...

drasko commented 5 years ago

Fixed by mounting custom nginx.conf on default OpenResty location, as described in https://github.com/openresty/docker-openresty/issues/90

drasko commented 5 years ago

I have to re-open this issue. It was actually not solved when I added proxy_pass directives in nginx.conf.

I have noticed that when openresty container starts before of other containers in composition, and does not find other containers from nginx.conf, it complains with something like:

mainflux-openresty | 2019/03/17 21:00:00 [emerg] 1#1: host not found in upstream "mqtt-adapter" in /usr/local/openresty/nginx/conf/nginx.conf:302
mainflux-openresty | nginx: [emerg] host not found in upstream "mqtt-adapter" in /usr/local/openresty/nginx/conf/nginx.conf:302

OpenResty is set to restart on failure in docker-compose: https://github.com/drasko/mainflux/blob/resty/docker/docker-compose.yml#L22

Maybe this restart or error in nginx.conf somehow makes problem for logging?

drasko commented 5 years ago

Maybe realted to this one: https://github.com/docker/compose/issues/2700

I do not understand however why mainstream NginX works in the same setup (with restart).

drasko commented 5 years ago

Tried with latest docker-compose v1.24-rc1 - same behavior: no logs on start, then on restart logs appear.

drasko commented 5 years ago

@neomantra I think that this might finally be a OpenResty issue.

Here are the steps to recreate the issue:

In order to see logs again, you need to restart OpenResty once more, manually. Then logs will appear.

I do not know what the issue might be, but the same procedure works fine with original NginX docker, as I mentioned.

Genzer commented 4 years ago

Hi @drasko,

Has there been any update from your case?

I happened to get into the same issue. What I did was to build a Docker image from source following Building (DEB based) with the RESTY_DEB_FLAVOR="-debug".

With nginx.conf using 

error_log logs/error.log debug;

I could see all the logs to /dev/stdout and /dev/stderr, even the ones using ngx.log().

ghost commented 2 years ago

I can confirm @Genzer 's solution works. I also notice something interesting, when reloading openresty within container using /usr/bin/openresty -s reload, I get following output:

openresty    | nginx: [alert] could not open error log file: open() "/usr/local/openresty/nginx/logs/error.log" failed (13: Permission denied)
rulatir commented 1 year ago

Is there a definite known once-and-for-all workaround for this that doesn't require rebuilding openresty from sources?

neomantra commented 1 year ago

It's been hard to tell what the problem actually was.... also the various software (Docker runtimes, docker-compose, OpenResty) have evolved in the last 3 years. If you have something reproducible, I can try to help troubleshoot.