fooinha/nginx-json-log

POST body is trimmed after 512 characters

haimari opened this issue · 8 comments

It seems that even though the requests returns OK status (in my case 204)
The event generated to the file (and kafka) trimmed the POST "body" field to 512 characters (after decoding base64)

for example in both Kafka event and the /tmp file generated by nginx locally I see the same base64 value, and if I decode it I can see it is 512 characters (trimmed)

@fooinha Can you please advise on this ?

@fooinha Any update on this ?

I haven't tested the POST a lot, and , sorry, I've missed this issue report.

I guess there will be a limit to write, but 512 seem-s low.

I haven't tested the POST a lot, and , sorry, I've missed this issue report.

I guess there will be a limit to write, but 512 seem-s low.

@fooinha will you be able to check where the limit is coming from and change it ?

I'm always busy, but I'll try to understand it during a cup of coffee.

I'm not sure if I can do it this week or next one.

I'm always busy, but I'll try to understand it during a cup of coffee.

I'm not sure if I can do it this week or next one.

Ok will wait for your update
Thanks

Actually this limit is already configurable via this module config var http_json_log_req_body_limit

Syntax: http_json_log_req_body_limit size;
Default: 512
Context: http local
Limits the body size to log. Argument is a size string. May be 1k or 1M, but avoid this!
src/ngx_http_json_log_filter_module.c

...

#define HTTP_LOG_JSON_REQ_BODY_LIMIT_DEFAULT 512

@fooinha
There is still an issue i'm having as a result of a large payload size.

While increasing http_json_log_req_body_limit to 512k (and 1M) solved the issue for < 512k characters payload,
Now I'm trying to send a payload which is ~700k (690814)

What happens here is different:

I get HTTP Response Code of 204 (expected) or 502 with Postman tests.
But in both cases the event is not sent to kafka (instead of just being trimmed), and I see this in logs:

Ingress log

nginx-ingress-controller-zcvzm nginx-ingress-controller 46.11.31.2 - - [21/Jul/2021:13:43:57 +0000] "POST / HTTP/1.1" 204 0 "-" "PostmanRuntime/7.28.2" 690814 0.627 [prd-nj-geoedge-8080] [] 10.42.2.31:8080 0 0.072 204 aacf863741668e34bc617fa4da21e57f

Nginx log

2021/07/21 13:59:38 [warn] 17#0: *410 a client request body is buffered to a temporary file /usr/local/nginx/client_body_temp/0000000004, client: 10.42.9.0, server: localhost, request: "POST / HTTP/1.1", host: "geoedge.mydomain.com"

nginx debug log atached
geo.log

This is the nginx.conf I use:

user  nobody;
worker_processes  auto;
daemon off;
worker_rlimit_nofile 100000;

events {
    worker_connections  100000;
    use epoll;
    multi_accept on;
}

http {
	aio_write on;
    client_body_in_single_buffer on;
    include       mime.types;
    default_type  application/octet-stream;
    # default_type application/json;
    

    #_id                    $request_id;
    json_log_format full_log '
       _date                  $time_iso8601;
       conn.serial            $connection;
       conn.requests          $connection_requests;
       conn.pipelined         $pipe;
       conn.info.rtt          $tcpinfo_rtt;
       conn.src.ip            $remote_addr;
       conn.src.port          $remote_port;
       conn.dst.ip            $server_addr;
       conn.dst.port          $server_port;
       http.req.protocol      $server_protocol;
       http.req.method        $request_method;
       http.req.path          $uri;
       http.req.args          $args;
       http.req.host          $host;
       http.req.content.type  $content_type;
       http.req.content.type  $content_length;
       http.req.headers       $http_json_log_req_headers;
       http.req.body          $http_json_log_req_body;
       http.req.time.taken.ms $request_time;
       http.req.completion    $request_completion;
       http.resp.headers      $http_json_log_resp_headers;
       http.resp.status       $status;
    ';

    gzip  on;
    proxy_ignore_client_abort on;
    proxy_headers_hash_max_size 4096;
    reset_timedout_connection off;
    client_body_timeout 10;
    send_timeout 60;
    keepalive_timeout 10;
    keepalive_requests 100000;

    open_file_cache max=200000 inactive=20s;
    open_file_cache_valid 30s;
    open_file_cache_min_uses 2;
    open_file_cache_errors on;

    client_max_body_size 100M;
    ignore_invalid_headers on;
    client_header_timeout  3m;
    connection_pool_size  256;
    client_header_buffer_size 4k;
    large_client_header_buffers 4 32k;
    request_pool_size  4k;
    output_buffers   4 32k;
    postpone_output  1460;

    sendfile on;
    tcp_nopush on;
    gzip_min_length 10240;
    gzip_comp_level 9;
    gzip_vary on;
    gzip_disable msie6;
    gzip_proxied expired no-cache no-store private auth;
    gzip_buffers 4 32k;
    gzip_types
        text/css
        text/javascript
        text/xml
        text/plain
        text/x-component
        application/javascript
        application/x-javascript
        application/json
        application/xml
        application/rss+xml
        application/atom+xml
        font/truetype
        font/opentype
        application/vnd.ms-fontobject
        image/svg+xml;


    server {
        aio_write on;
        proxy_headers_hash_max_size 4096;
        client_max_body_size 100M;
        listen 9876;
        access_log /dev/stdout;
        error_log /dev/stdout info;
        location / {
            return 204;
        }
    }


    json_log_kafka_brokers broker1.mydomain.com:9092;
    json_log_kafka_compression none;

    server {
        aio_write on;
        proxy_headers_hash_max_size 4096;
        client_max_body_size 100M;
        listen 8080;
        access_log /dev/null;
        error_log /dev/null;
        server_name localhost;

        # location = /basic_status {
        #     stub_status;
        # }
    
        location = /keepalive {
            access_log off;
            return 200;
        }

        location / {
            aio_write on;
            http_json_log_req_body_limit 1M;
            proxy_headers_hash_max_size 4096;
            client_max_body_size 100M;
            proxy_read_timeout 300s;
            proxy_max_temp_file_size 4096m;
            proxy_connect_timeout 75s;
            proxy_pass http://localhost:9876/;
            error_log  /dev/stdout  debug;

            json_log file:/tmp/full.log full_log;
            json_log kafka:EdgeTest full_log;
        }
    }
}

Can you advise on this please ?