skip to Main Content

I use k8s nginx ingress controller before my backend, having two instances. When web-cleint sends quite big request to ingress – nginx for POST/PUT/GET request always returns 400 Bad request. Btw, no another explanation or details for this error, or at least it is logged in some place where I cannot find it or identify that my problem is.

After googling I figured out the recipe to fix this: apply large_client_header_buffers with increased value: that’s exactly what I did – now my buffer size is 4 256k. But no effect , I still get this error.

Pls give me any idea how to procede this problem

2

Answers


  1. Chosen as BEST ANSWER

    So answer is: nginx is not guilty in described behaviour. After thoroughly investigation of log of java-app which stands behind nginx this exception was noticed

    [INFO ] 2021-05-10 16:20:56.354 --- [io-10104-exec-4] org.apache.juli.logging.DirectJDKLog     : Error parsing HTTP request header
    Note: further occurrences of HTTP request parsing errors will be logged at DEBUG level.
     
    java.lang.IllegalArgumentException: Request header is too large 
    

    And because of this detail - Note: further occurrences of HTTP request parsing errors will be logged at DEBUG level. - it was too fleeting to be catch up during fluent observation of log.

    Summing up solution was to increase SpringBoot property server.max-http-header-size to to more proper value. Default value was 8 Kb.


  2. Some additonal infromation about the problem.

    The large_client_header_buffers was changed for http context over ConfigMap, server context was also changed but by simply changing the nginx.conf and reloading nginx – that didn’t help either.

    The problem is that the buffer chain writer buf which can be seen in the debug mode log below reaches 8k and 400 is thrown

    2021/04/29 11:10:18 [debug] 805#805: *292613 http cleanup add: 0000555F4EFFC428
    2021/04/29 11:10:18 [debug] 805#805: *292613 init keepalive peer
    2021/04/29 11:10:18 [debug] 805#805: *292613 get keepalive peer
    2021/04/29 11:10:18 [debug] 805#805: *292613 lua balancer peer, tries: 1
    2021/04/29 11:10:18 [debug] 805#805: *292613 lua reset ctx
    2021/04/29 11:10:18 [debug] 805#805: *292613 looking up Lua code cache with key 'balancer_by_luanhli_0f29762dfd828b8baa4d895affbc4b90'
    2021/04/29 11:10:18 [debug] 805#805: *292613 stream socket 39
    2021/04/29 11:10:18 [debug] 805#805: *292613 epoll add connection: fd:39 ev:80002005
    2021/04/29 11:10:18 [debug] 805#805: *292613 connect to 172.18.112.41:10102, fd:39 #292619
    2021/04/29 11:10:18 [debug] 805#805: *292613 http upstream connect: -2
    2021/04/29 11:10:18 [debug] 805#805: *292613 posix_memalign: 0000555F4EFA1AC0:128 @16
    2021/04/29 11:10:18 [debug] 805#805: *292613 event timer add: 39: 5000:5598957611
    2021/04/29 11:10:18 [debug] 805#805: *292613 http finalize request: -4, "/api/assets/53f75d85-0528-434c-804f-922acb220c88?" a:1, c:2
    2021/04/29 11:10:18 [debug] 805#805: *292613 http request count:2 blk:0
    2021/04/29 11:10:18 [debug] 805#805: *292613 http run request: "/api/assets/53f75d85-0528-434c-804f-922acb220c88?"
    2021/04/29 11:10:18 [debug] 805#805: *292613 http upstream check client, write event:1, "/api/assets/53f75d85-0528-434c-804f-922acb220c88"
    2021/04/29 11:10:18 [debug] 805#805: *292613 http upstream request: "/api/assets/53f75d85-0528-434c-804f-922acb220c88?"
    2021/04/29 11:10:18 [debug] 805#805: *292613 http upstream send request handler
    2021/04/29 11:10:18 [debug] 805#805: *292613 http upstream send request
    2021/04/29 11:10:18 [debug] 805#805: *292613 http upstream send request body
    2021/04/29 11:10:18 [debug] 805#805: *292613 chain writer buf fl:1 s: 8222
    2021/04/29 11:10:18 [debug] 805#805: *292613 chain writer in: 0000555F4EFB81A0
    2021/04/29 11:10:18 [debug] 805#805: *292613 writev: 8222 of 8222
    2021/04/29 11:10:18 [debug] 805#805: *292613 chain writer out: 0000000000000000
    2021/04/29 11:10:18 [debug] 805#805: *292613 event timer del: 39: 5598957611
    2021/04/29 11:10:18 [debug] 805#805: *292613 event timer add: 39: 60000:5599012614
    2021/04/29 11:10:18 [debug] 805#805: *292613 http upstream request: "/api/assets/53f75d85-0528-434c-804f-922acb220c88?"
    2021/04/29 11:10:18 [debug] 805#805: *292613 http upstream process header
    2021/04/29 11:10:18 [debug] 805#805: *292613 malloc: 0000555F4EE529C0:4096
    2021/04/29 11:10:18 [debug] 805#805: *292613 recv: eof:1, avail:-1
    2021/04/29 11:10:18 [debug] 805#805: *292613 recv: fd:39 590 of 4096
    2021/04/29 11:10:18 [debug] 805#805: *292613 http proxy status 400 "400 "
    2021/04/29 11:10:18 [debug] 805#805: *292613 http proxy header: "Content-Type: text/html;charset=utf-8"
    2021/04/29 11:10:18 [debug] 805#805: *292613 http proxy header: "Content-Language: en"
    2021/04/29 11:10:18 [debug] 805#805: *292613 http proxy header: "Content-Length: 435"
    2021/04/29 11:10:18 [debug] 805#805: *292613 http proxy header: "Date: Thu, 29 Apr 2021 11:10:18 GMT"
    2021/04/29 11:10:18 [debug] 805#805: *292613 http proxy header: "Connection: close"
    2021/04/29 11:10:18 [debug] 805#805: *292613 http proxy header done
    
    Login or Signup to reply.
Please signup or login to give your own answer.
Back To Top
Search