Possible typo in sample Nginx.conf specifying stderr pipe.

hodnett commented 4 years ago

What version of Cloud Foundry and CF CLI are you using? (i.e. What is the output of running cf curl /v2/info && cf version?

api_version: 2.144.0 osbapi_version: 2.15 cf version 6.51.0+2acd15650.2020-04-07

What version of the buildpack you are using?

nginx-buildpack-cflinuxfs3-v1.1.1

If you were attempting to accomplish a task, what was it you were attempting to do?

Output Nginx error logs.

What did you expect to happen?

404, 403, 503 etc errors are displayed in the cf logs <application name> --recent output.

What was the actual behavior?

No errors are displayed in the cf logs output.

Please confirm where necessary:

[ ] I have included a log output
[ ] My log includes an error message
[ ] I have included steps for reproduction

What do you think is the issue?

The sample https://github.com/cloudfoundry/nginx-buildpack/blob/master/fixtures/mainline/nginx.conf file requests that errors be sent to stderr when they should instead be sent to /dev/stderr.

What we cannot determine is whether this is a typo in the sample file, or if there's an adjustment that needs to be made elsewhere in order to allow the Nginx configuration file to redirect to stderr sans directory prefix?

cf-gitbot commented 4 years ago

We have created an issue in Pivotal Tracker to manage this:

https://www.pivotaltracker.com/story/show/172779851

The labels on this github issue will be updated when the story is started.

ryanmoran commented 4 years ago

The nginx documentation of the error_log directive outlines that stderr is a special value that will select the standard error file.

hodnett commented 4 years ago

I am unable to confirm that the stderr special value works as intended but I am willing to accept that some other aspect of my site-specific configuration is preventing that from happening (and that since the /dev/stderr workaround exists, tracking it down is not the most productive use of our time).

If you confirm that stderr works, please feel free to close this ticket.

The test I performed...

Go to a URL that you know exists. The request, with an http status code 200 should be visible in the cf logs output.
Go to a URL that you know does not exist. That request, with an http status code of 404 should be visible in the cf logs output.

ryanmoran commented 4 years ago

I spent some time today and deployed the mainline fixture app against the Nginx buildpack. Here are the logs I am seeing:

2020-08-06T11:06:04.73-0400 [STG/0] OUT Downloading app package...
2020-08-06T11:06:04.76-0400 [STG/0] OUT Downloaded app package (1.8K)
2020-08-06T11:06:06.73-0400 [STG/0] OUT -----> Nginx Buildpack version 1.1.11
2020-08-06T11:06:06.73-0400 [STG/0] OUT -----> Supplying nginx
2020-08-06T11:06:06.74-0400 [STG/0] OUT -----> Requested nginx version: mainline => 1.19.1
2020-08-06T11:06:06.74-0400 [STG/0] OUT -----> Installing nginx 1.19.1
2020-08-06T11:06:06.74-0400 [STG/0] OUT        Download [https://buildpacks.cloudfoundry.org/dependencies/nginx/nginx_1.19.1_linux_x64_cflinuxfs3_b5af01b0.tgz]
2020-08-06T11:06:08.59-0400 [STG/0] OUT Exit status 0
2020-08-06T11:06:08.59-0400 [STG/0] OUT Uploading droplet, build artifacts cache...
2020-08-06T11:06:08.59-0400 [STG/0] OUT Uploading droplet...
2020-08-06T11:06:08.59-0400 [STG/0] OUT Uploading build artifacts cache...
2020-08-06T11:06:08.77-0400 [STG/0] OUT Uploaded build artifacts cache (2.7M)
2020-08-06T11:06:08.81-0400 [API/0] OUT Creating droplet for app with guid 3d004974-e0ab-48ba-aaac-76c0bd35cdd4
2020-08-06T11:06:10.85-0400 [STG/0] OUT Uploaded droplet (6M)
2020-08-06T11:06:10.86-0400 [STG/0] OUT Uploading complete
2020-08-06T11:06:11.00-0400 [STG/0] OUT Cell decdb167-c781-4a8c-95d2-27f35d7eadc3 stopping instance 5968a7c2-b4b1-4516-8fd9-55a4ce249052
2020-08-06T11:06:11.00-0400 [STG/0] OUT Cell decdb167-c781-4a8c-95d2-27f35d7eadc3 destroying container for instance 5968a7c2-b4b1-4516-8fd9-55a4ce249052
2020-08-06T11:06:11.26-0400 [CELL/0] OUT Cell decdb167-c781-4a8c-95d2-27f35d7eadc3 creating container for instance d171547d-07d3-4c16-6996-55bf
2020-08-06T11:06:11.33-0400 [STG/0] OUT Cell decdb167-c781-4a8c-95d2-27f35d7eadc3 successfully destroyed container for instance 5968a7c2-b4b1-4516-8fd9-55a4ce249052
2020-08-06T11:06:11.98-0400 [CELL/0] OUT Cell decdb167-c781-4a8c-95d2-27f35d7eadc3 successfully created container for instance d171547d-07d3-4c16-6996-55bf
2020-08-06T11:06:12.08-0400 [CELL/0] OUT Downloading droplet...
2020-08-06T11:06:12.39-0400 [CELL/0] OUT Downloaded droplet (6M)
2020-08-06T11:06:12.39-0400 [CELL/0] OUT Starting health monitoring of container
2020-08-06T11:06:13.19-0400 [APP/PROC/WEB/0] OUT plain text tempate: worker_processes 1;
2020-08-06T11:06:13.19-0400 [APP/PROC/WEB/0] OUT daemon off;
2020-08-06T11:06:13.19-0400 [APP/PROC/WEB/0] OUT error_log stderr;
2020-08-06T11:06:13.19-0400 [APP/PROC/WEB/0] OUT events { worker_connections 1024; }
2020-08-06T11:06:13.19-0400 [APP/PROC/WEB/0] OUT http {
2020-08-06T11:06:13.19-0400 [APP/PROC/WEB/0] OUT   charset utf-8;
2020-08-06T11:06:13.19-0400 [APP/PROC/WEB/0] OUT   log_format cloudfoundry 'NginxLog "$request" $status $body_bytes_sent';
2020-08-06T11:06:13.19-0400 [APP/PROC/WEB/0] OUT   access_log /dev/stdout cloudfoundry;
2020-08-06T11:06:13.19-0400 [APP/PROC/WEB/0] OUT   default_type application/octet-stream;
2020-08-06T11:06:13.19-0400 [APP/PROC/WEB/0] OUT   include mime.types;
2020-08-06T11:06:13.19-0400 [APP/PROC/WEB/0] OUT   sendfile on;
2020-08-06T11:06:13.19-0400 [APP/PROC/WEB/0] OUT   tcp_nopush on;
2020-08-06T11:06:13.19-0400 [APP/PROC/WEB/0] OUT   keepalive_timeout 30;
2020-08-06T11:06:13.19-0400 [APP/PROC/WEB/0] OUT   port_in_redirect off; # Ensure that redirects don't include the internal container PORT - 8080
2020-08-06T11:06:13.19-0400 [APP/PROC/WEB/0] OUT   server {
2020-08-06T11:06:13.19-0400 [APP/PROC/WEB/0] OUT     listen {{port}};
2020-08-06T11:06:13.19-0400 [APP/PROC/WEB/0] OUT     root public;
2020-08-06T11:06:13.19-0400 [APP/PROC/WEB/0] OUT     index index.html index.htm Default.htm;
2020-08-06T11:06:13.19-0400 [APP/PROC/WEB/0] OUT   }
2020-08-06T11:06:13.19-0400 [APP/PROC/WEB/0] OUT }
2020-08-06T11:06:15.35-0400 [CELL/0] OUT Container became healthy
2020-08-06T11:06:48.68-0400 [APP/PROC/WEB/0] OUT NginxLog "GET / HTTP/1.1" 200 24
2020-08-06T11:06:48.68-0400 [RTR/0] OUT mainline.paleplum.cf-app.com - [2020-08-06T15:06:48.678229116Z] "GET / HTTP/1.1" 200 0 24 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:78.0) Gecko/20100101 Firefox/78.0" "35.191.8.14:58735" "10.0.1.11:61002" x_forwarded_for:"100.37.120.93, 130.211.13.18, 35.191.8.14" x_forwarded_proto:"http" vcap_request_id:"7576edac-d3e1-46b0-4bd5-373c52954f43" response_time:0.010659 gorouter_time:0.000417 app_id:"3d004974-e0ab-48ba-aaac-76c0bd35cdd4" app_index:"0" x_cf_routererror:"-" x_b3_traceid:"740fb305fdd71c60" x_b3_spanid:"740fb305fdd71c60" x_b3_parentspanid:"-" b3:"740fb305fdd71c60-740fb305fdd71c60"
2020-08-06T11:06:48.68-0400 [RTR/0] OUT
2020-08-06T11:06:48.84-0400 [APP/PROC/WEB/0] OUT NginxLog "GET /favicon.ico HTTP/1.1" 404 153
2020-08-06T11:06:48.84-0400 [APP/PROC/WEB/0] ERR 2020/08/06 15:06:48 [error] 69#0: *5 open() "/home/vcap/app/public/favicon.ico" failed (2: No such file or directory), client: 10.255.131.28, server: , request: "GET /favicon.ico HTTP/1.1", host: "mainline.paleplum.cf-app.com"
2020-08-06T11:06:48.84-0400 [RTR/0] OUT mainline.paleplum.cf-app.com - [2020-08-06T15:06:48.848090344Z] "GET /favicon.ico HTTP/1.1" 404 0 153 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:78.0) Gecko/20100101 Firefox/78.0" "35.191.10.82:60279" "10.0.1.11:61002" x_forwarded_for:"100.37.120.93, 130.211.13.18, 35.191.10.82" x_forwarded_proto:"http" vcap_request_id:"28e6564f-2896-435b-4f80-9832d5096b8a" response_time:0.001496 gorouter_time:0.000412 app_id:"3d004974-e0ab-48ba-aaac-76c0bd35cdd4" app_index:"0" x_cf_routererror:"-" x_b3_traceid:"216c94cb5a435b74" x_b3_spanid:"216c94cb5a435b74" x_b3_parentspanid:"-" b3:"216c94cb5a435b74-216c94cb5a435b74"
2020-08-06T11:06:48.84-0400 [RTR/0] OUT
2020-08-06T11:07:08.83-0400 [APP/PROC/WEB/0] ERR 2020/08/06 15:07:08 [error] 69#0: *5 open() "/home/vcap/app/public/no/such/endpoint" failed (2: No such file or directory), client: 10.255.131.28, server: , request: "GET /no/such/endpoint HTTP/1.1", host: "mainline.paleplum.cf-app.com"
2020-08-06T11:07:08.83-0400 [APP/PROC/WEB/0] OUT NginxLog "GET /no/such/endpoint HTTP/1.1" 404 153
2020-08-06T11:07:08.83-0400 [RTR/0] OUT mainline.paleplum.cf-app.com - [2020-08-06T15:07:08.834184205Z] "GET /no/such/endpoint HTTP/1.1" 404 0 153 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:78.0) Gecko/20100101 Firefox/78.0" "35.191.1.239:63638" "10.0.1.11:61002" x_forwarded_for:"100.37.120.93, 130.211.13.18, 35.191.1.239" x_forwarded_proto:"http" vcap_request_id:"19a47bbc-4bd6-4654-48b3-7ca9ed794475" response_time:0.001714 gorouter_time:0.000436 app_id:"3d004974-e0ab-48ba-aaac-76c0bd35cdd4" app_index:"0" x_cf_routererror:"-" x_b3_traceid:"8acb9d5607b9d960" x_b3_spanid:"8acb9d5607b9d960" x_b3_parentspanid:"-" b3:"8acb9d5607b9d960-8acb9d5607b9d960"
2020-08-06T11:07:08.83-0400 [RTR/0] OUT

As you can see in the logs, Nginx is outputting error messages to STDERR:

2020-08-06T11:07:08.83-0400 [APP/PROC/WEB/0] ERR 2020/08/06 15:07:08 [error] 69#0: *5 open() "/home/vcap/app/public/no/such/endpoint" failed (2: No such file or directory), client: 10.255.131.28, server: , request: "GET /no/such/endpoint HTTP/1.1", host: "mainline.paleplum.cf-app.com"

I'm not sure what else you might have in your nginx.conf that might possibly be conflicting with this output.

ForestEckhardt commented 3 years ago

Closing due to inactivity. Please feel free to reopen if you have an update or more to discuss.

cloudfoundry / nginx-buildpack

Possible typo in sample Nginx.conf specifying stderr pipe. #36