Problem

You need to configure access log formats to add embedded variables to your request logs.

Solution

Configure an access log format:

http {
    log_format  geoproxy 
                '[$time_local] $remote_addr '
                '$realip_remote_addr $remote_user '
                '$proxy_protocol_server_addr $proxy_protocol_server_port '
                '$request_method $server_protocol '
                '$scheme $server_name $uri $status '
                '$request_time $body_bytes_sent '
                '$geoip_city_country_code3 $geoip_region '
                '"$geoip_city" $http_x_forwarded_for '
                '$upstream_status $upstream_response_time '
                '"$http_referer" "$http_user_agent"';
    # ...
}

This log format configuration is named geoproxy and uses a number of embedded variables to demonstrate the power of NGINX logging. This configuration shows the local time on the server when the request was made, the IP address that opened the connection, and the IP of the client, as NGINX understands it per geoip_proxy or realip_header instructions.

The variables prefixed with $proxy_protocol_server_ provide information about the server from the PROXY protocol header, when the proxy_protocol parameter is used on the listen directive of the server. $remote_user shows the username of the user, authenticated by basic authentication, followed by the request method and protocol, as well as the scheme, such as HTTP or HTTPS. The server name match is logged as well as the request URI and the return status code.

Statistics logged include the processing time in milliseconds and the size of the body sent to the client. Information about the country, region, and city are logged. The HTTP header X-Forwarded-For is included to show if the request is being forwarded by another proxy. The upstream module enables some embedded variables that we’ve used that show the status returned from the upstream server and how long the upstream request takes to return. Lastly, we’ve logged some information about where the client was referred from and what browser the client is using.

The log_format directive is only valid within the HTTP context. An optional escape parameter can specify what type of escaping is done on the string; default, json, and none, are escape values. The none value disables escaping. For default escaping, characters “"”, “”, and other characters with values less than 32 or above 126 are escaped as “xXX”. If the variable value is not found, a hyphen (“-”) will be logged. For json escaping, all characters not allowed in JSON strings will be escaped: characters “"” and “” are escaped as “"” and “\”, characters with values less than 32 are escaped as “ ”, “ ”, “ ”, “”, “f”, or “u00XX”.

This log configuration renders a log entry that looks like the following:

[25/Nov/2016:16:20:42 +0000] 10.0.1.16 192.168.0.122 Derek 
GET HTTP/1.1 http www.example.com / 200 0.001 370 USA MI
"Ann Arbor" - 200 0.001 "-" "curl/7.47.0"

To use this log format, use the access_log directive, providing a logfile path and the format name geoproxy as parameters:

server {
    access_log  /var/log/nginx/access.log  geoproxy;
    # ...
}

The access_log directive takes a logfile path and the format name as parameters. This directive is valid in many contexts and in each context can have a different log path and/or log format. Named parameters such as buffer, flush, and gzip configure how often logs are written to the logfile and if the file is gzipped or not. A parameter named if exists and takes a condition; if the condition evaluates to 0 or empty string, the access will not be logged.

Discussion

The log module in NGINX allows you to configure log formats for many different scenarios to log to numerous logfiles as you see fit. You may find it useful to configure a different log format for each context, where you use different modules and employ those modules’ embedded variables, or a single, catchall format that provides all the information you could ever want. It’s also possible to log in JSON or XML, provided you construct the format string in that manner. These logs will aid you in understanding your traffic patterns, client usage, who your clients are, and where they’re coming from. Access logs can also aid you in finding lag in responses and issues with upstream servers or particular URIs. Access logs can be used to parse and play back traffic patterns in test environments to mimic real user interaction. There’s limitless possibility for logs when troubleshooting, debugging, or analyzing your application or market.

Problem

You need to configure error logging to better understand issues with your NGINX server.

Solution

Use the error_log directive to define the log path and the log level:

error_log /var/log/nginx/error.log warn;

The error_log directive requires a path; however, the log level is optional, and defaults to error. This directive is valid in every context except for if statements. The log levels available are debug, info, notice, warn, error, crit, alert, or emerg. The order in which these log levels were introduced is also the order of severity from least to most. The debug log level is only available if NGINX is configured with the --with-debug flag.

Discussion

The error log is the first place to look when configuration files are not working correctly. The log is also a great place to find errors produced by application servers like FastCGI. You can use the error log to debug connections down to the worker, memory allocation, client IP, and server. The error log cannot be formatted. However, it follows a specific format of date, followed by the level, then the message.

Problem

You need to forward your logs to a Syslog listener to aggregate logs to a centralized service.

Solution

Use the error_log and access_log directives to send your logs to a Syslog listener:

error_log syslog:server=10.0.1.42 debug;

access_log syslog:server=10.0.1.42,tag=nginx,severity=info geoproxy;

The syslog parameter for the error_log and access_log directives is followed by a colon and a number of options. These options include the required server flag that denotes the IP, DNS name, or Unix socket to connect to, as well as optional flags such as facility, severity, tag, and nohostname. The server option takes a port number, along with IP addresses or DNS names. However, it defaults to UDP 514. The facility option refers to the facility of the log message defined as one of the 23 defined in the RFC standard for Syslog; the default value is local7. The tag option tags the message with a value. This value defaults to nginx. severity defaults to info and denotes the severity of the message being sent. The nohostname flag disables, adding the hostname field into the Syslog message header and does not take a value.

Discussion

Syslog is a standard protocol for sending log messages and collecting those logs on a single server or collection of servers. Sending logs to a centralized location helps in debugging when you’ve got multiple instances of the same service running on multiple hosts. This is called aggregating logs. Aggregating logs allows you to view logs together in one place without having to jump from server to server, and mentally stitch together logfiles by timestamp. A common log aggregation stack is Elasticsearch, Logstash, and Kibana, also known as the ELK Stack. NGINX makes streaming these logs to your Syslog listener easy with the access_log and error_log directives.

Problem

You need to correlate NGINX logs with application logs to have an end-to-end understanding of a request.

Solution

Use the request identifying variable and pass it to your application to log as well:

log_format trace '$remote_addr - $remote_user [$time_local] '
                 '"$request" $status $body_bytes_sent '
                 '"$http_referer" "$http_user_agent" '
                 '"$http_x_forwarded_for" $request_id';
upstream backend {
    server 10.0.0.42;
}
server {
    listen 80;
    # Add the header X-Request-ID to the response to the client
    add_header X-Request-ID $request_id;
    location / {
        proxy_pass http://backend;
        # Send the header X-Request-ID to the application
        proxy_set_header X-Request-ID $request_id;
        access_log /var/log/nginx/access_trace.log trace; 
    }
}

In this example configuration, a log_format named trace is set up, and the variable $request_id is used in the log. This $request_id variable is also passed to the upstream application by use of the proxy_set_header directive to add the request ID to a header when making the upstream request. The request ID is also passed back to the client through use of the add_header directive setting the request ID in a response header.

Discussion

Made available in NGINX Plus R10 and NGINX version 1.11.0, the $request_id provides a randomly generated string of 32 hexadecimal characters that can be used to uniquely identify requests. By passing this identifier to the client as well as to the application, you can correlate your logs with the requests you make. From the frontend client, you will receive this unique string as a response header and can use it to search your logs for the entries that correspond. You will need to instruct your application to capture and log this header in its application logs to create a true end-to-end relationship between the logs. With this advancement, NGINX makes it possible to trace requests through your application stack.

Problem

You have a tracing server that supports OpenTracing and want to integrate NGINX or NGINX Plus.

Solution

Ensure you have an OpenTrace compatible server available, and that the correct client is installed on the NGINX or NGINX Plus node.

A plug-in configuration file for the specific OpenTrace compatible server will be needed. This solution will demonstrate Jaeger and Zipkin.

A Jaeger plug-in configuration example named /etc/jaeger/jaeger-config.json is as follows:

{
  "service_name": "nginx",
  "sampler": {
    "type": "const",
    "param": 1
  },
  "reporter": {
    "localAgentHostPort": "Jaeger-server-IP-address:6831"
  }
}

A Zipkin plug-in configuration example named /etc/zipkin/zipkin-config.json is as follows:

{
  "service_name": "nginx",
  "collector_host": "Zipkin-server-IP-address",
  "collector_port": 9411
}

If NGINX Plus is being used, install the OpenTracing module from the NGINX Plus repository by following the NGINX Plus Admin Guide.

If Open Source NGINX is being used, visit the NGINX OpenTracing Module Releases page to find a prebuilt dynamic module compatible with your system, or compile the module along with NGINX from source. Alternatively, in a docker environment, an image named opentracing/nginx-opentracing is available on Docker Hub, and can be used to jump-start your testing.

When using a dynamically loaded module, which includes the NGINX Plus installation, ensure that you load it within your NGINX configuration by adding the following load_module directive, to tell NGINX where on the filesystem to find the module. As a reminder, the load_module directive is valid only in the main (top-level) context.

load_module modules/ngx_http_opentracing_module.so;

Once an OpenTrace compatible server is listening, a client installed on the NGINX node and plug-in configuration in place, and the NGINX module is loaded, NGINX can be configured to start tracing requests. The following example provides examples of loading a tracer and configuring NGINX to tag requests. The directive to load a tracer plug-in is included; with default location for Jaeger and Zipkin plug-ins, and the configuration files provided above. Uncomment the appropriate vendor example for the use case.

# Load a vendor tracer
#opentracing_load_tracer /usr/local/libjaegertracing_plugin.so 
#                        /etc/jaeger/jaeger-config.json;
#opentracing_load_tracer /usr/local/lib/libzipkin_opentracing_plugin.so
#                        /etc/zipkin/zipkin-config.json;

# Enable tracing for all requests
opentracing on;

# Set additional tags that capture the value of NGINX variables
opentracing_tag bytes_sent $bytes_sent;
opentracing_tag http_user_agent $http_user_agent;
opentracing_tag request_time $request_time;
opentracing_tag upstream_addr $upstream_addr;
opentracing_tag upstream_bytes_received $upstream_bytes_received;
opentracing_tag upstream_cache_status $upstream_cache_status;
opentracing_tag upstream_connect_time $upstream_connect_time;
opentracing_tag upstream_header_time $upstream_header_time;
opentracing_tag upstream_queue_time $upstream_queue_time;
opentracing_tag upstream_response_time $upstream_response_time;

server {
    listen 9001;

    location / {
        # The operation name used for OpenTracing Spans defaults 
        # to the name of the 'location' block,
        # but uncomment this directive to customize it.
        #opentracing_operation_name $uri;

        # Propagate the active Span context upstream, 
        # so that the trace can be continued by the backend.
        opentracing_propagate_context;

        # Example application location service
        proxy_pass http://10.0.0.2:8080; 
    }
}

Discussion

An OpenTracing setup is by no means trivial, but they do provide enormous value in areas of distributed monitoring of performance and transactions. These tools enable teams to effectively provide root cause, and dependency analysis to pinpoint problem areas with data. It’s natural for NGINX to serve as an API gateway, routing and authorizing requests between applications, and therefore has integral information to tracing requests through a complex system.

NGINX can tag a request with any variable available to itself, which enables the tracing system user to have a full view of how a request behaves. This example provided a limited sample of using OpenTracing for a proxied request. One can imagine the amount of data that can be harvested from NGINX as the opentracing_tag directive is valid in the HTTP, server, and location contexts.

Also See

OpenTracing NGINX Module
NGINX Plus OpenTracing Dynamic Module Admin Guide
Datadog OpenTracing NGINX Module Plug-In Guide
NGINX OpenTracing for NGINX and NGINX Plus Blog
NGINX OpenTracing for NGINX Ingress Controller Blog