openresty / openresty/openresty

got 400 code when reverse proxying docker

Open
#470 1 comment 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

Dominant language
C
Stars
14k
Forks
1.6k
No merged PRs in 30d

Description

i got 400 error code when reverse proxy docker , docker login and pull works fine, but docker push always failed after retrying 3 times,
please help me figure out what's wrong
my config is like this

server {
    listen      80;
    server_name  harbor.example.com;

    error_log /tmp/harbor.debug.log debug;

    location / {
        client_max_body_size 0;
        client_body_buffer_size 0;
        proxy_pass http://10.10.10.9;
    }
}

and tried this ,also failed

server {
    listen      80;
    server_name  harbor.example.com;

    error_log /tmp/harbor.debug.log debug;

    chunked_transfer_encoding on;

    location / {
        client_max_body_size 0;
        client_body_buffer_size 0;
        proxy_buffering off;
        proxy_request_buffering off;
        add_header 'Docker-Distribution-Api-Version' 'registry/2.0' always;
        proxy_set_header  Host              $http_host;   # required for docker client's sake
        proxy_set_header  X-Real-IP         $remote_addr; # pass on real client's IP
        proxy_set_header  X-Forwarded-For   $proxy_add_x_forwarded_for;
        proxy_set_header  X-Forwarded-Proto $scheme;
        proxy_set_header  Cookie            $http_cookie;
        proxy_set_header  Upgrade           $http_upgrade;
        proxy_pass http://10.10.10.9;
    }
}

debug log as follows:

2019/04/01 20:53:03 [debug] 14163#0: *1022 accept: 10.10.10.6:48182 fd:3
2019/04/01 20:53:03 [debug] 14163#0: *1022 event timer add: 3: 60000:1554123243464
2019/04/01 20:53:03 [debug] 14163#0: *1022 reusable connection: 1
2019/04/01 20:53:03 [debug] 14163#0: *1022 epoll add event: fd:3 op:1 ev:80002001
2019/04/01 20:53:03 [debug] 14163#0: *1022 http wait request handler
2019/04/01 20:53:03 [debug] 14163#0: *1022 malloc: 000000000175C570:1048576
2019/04/01 20:53:03 [debug] 14163#0: *1022 recv: eof:0, avail:1
2019/04/01 20:53:03 [debug] 14163#0: *1022 recv: fd:3 34445 of 1048576
2019/04/01 20:53:03 [debug] 14163#0: *1022 reusable connection: 0
2019/04/01 20:53:03 [debug] 14163#0: *1022 posix_memalign: 00000000016A1150:4096 @16
2019/04/01 20:53:03 [debug] 14163#0: *1022 http process request line
2019/04/01 20:53:03 [debug] 14163#0: *1022 http request line: "PATCH /v2/test/a/blobs/uploads/fa5bc114-4fd5-4f47-941e-1e63fca50039?_state=d9HXnK-pVuDprjMAocHG_IK3NwDuYJyH40F9BvmHo8l7Ik5hbWUiOiJ0ZXN0L2EiLCJVVUlEIjoiZmE1YmMxMTQtNGZkNS00ZjQ3LTk0MWUtMWU2M2ZjYTUwMDM5IiwiT2Zmc2V0IjowLCJTdGFydGVkQXQiOiIyMDE5LTA0LTAxVDEyOjUzOjAzLjQ1ODkwNDMwOVoifQ%3D%3D HTTP/1.1"
2019/04/01 20:53:03 [debug] 14163#0: *1022 http uri: "/v2/test/a/blobs/uploads/fa5bc114-4fd5-4f47-941e-1e63fca50039"
2019/04/01 20:53:03 [debug] 14163#0: *1022 http args: "_state=d9HXnK-pVuDprjMAocHG_IK3NwDuYJyH40F9BvmHo8l7Ik5hbWUiOiJ0ZXN0L2EiLCJVVUlEIjoiZmE1YmMxMTQtNGZkNS00ZjQ3LTk0MWUtMWU2M2ZjYTUwMDM5IiwiT2Zmc2V0IjowLCJTdGFydGVkQXQiOiIyMDE5LTA0LTAxVDEyOjUzOjAzLjQ1ODkwNDMwOVoifQ%3D%3D"
2019/04/01 20:53:03 [debug] 14163#0: *1022 http exten: ""
2019/04/01 20:53:03 [debug] 14163#0: *1022 posix_memalign: 000000000169FFC0:4096 @16
2019/04/01 20:53:03 [debug] 14163#0: *1022 http process request header line
2019/04/01 20:53:03 [debug] 14163#0: *1022 http header: "Host: harbor.example.com"
2019/04/01 20:53:03 [debug] 14163#0: *1022 http header: "User-Agent: docker/1.13.1 go/go1.10.3 kernel/3.10.0-862.6.3.el7.x86_64 os/linux arch/amd64 UpstreamClient(Docker-Client/1.13.1 \(linux\))"
2019/04/01 20:53:03 [debug] 14163#0: *1022 http header: "Transfer-Encoding: chunked"
2019/04/01 20:53:03 [debug] 14163#0: *1022 http header: "Authorization: Bearer eyJ0eXAiOiJKV1QiLCJhbGciOiJSUzI1NiIsImtpZCI6IkpKWFE6R1JERTpCVjJEOjdGS1Y6UFVHQTpERFNYOktQSkw6WFY0SDpMQzRSOkZUSVE6UVNMWDpBUENGIn0.eyJpc3MiOiJoYXJib3ItdG9rZW4taXNzdWVyIiwic3ViIjoiZGFubnlfZGVuZyIsImF1ZCI6ImhhcmJvci1yZWdpc3RyeSIsImV4cCI6MTU1NDEyNDk3OCwibmJmIjoxNTU0MTIzMTc4LCJpYXQiOjE1NTQxMjMxNzgsImp0aSI6IjBoQWlLNmJ6YXJLTlVGVkgiLCJhY2Nlc3MiOlt7InR5cGUiOiJyZXBvc2l0b3J5IiwibmFtZSI6InRlc3QvYSIsImFjdGlvbnMiOlsicHVzaCIsIioiLCJwdWxsIl19XX0.iMei_i5e98uZrSnd2iQp1dJAEJz4BZkznDJr47F0n2FdzmjnoLd3Oi6-SJgiEuusMuZGkVL7HmfddiGFMxcD4CgbvF46ka4PQDF_V5jqRkC0i-DqJBzFlzXZStui-S0yRgypCkGAT1iwp80qFgLNyrYf5qDkS9PwCS12FpCbBPa1fAOw4dZd4wHdsMWfH56niT-sbvDyBmGsNnUtEL3TbXg7nqVlfoJQao2louCyaupFh5GzaTDIDOYphtV0wruH_TkKTsGaQlb2LfXN7GuPF-kKKgN1V3oPn5TIIJZWIQYdWME1fSQKUhaQzKxP5kR7hWqUwFA8Wug-Sq0jZiBzWsXpADmJP2btV89_Y5uJuXPHG87Qp-CVH3rNigebhrp6mV63SEuvDaV4wrhGZSgogDnxVSp7IFbrYSHRyE-6JD43S4ZKmpZgNIDa3QK9KByWUFctm4AM8kJoClBiN4weZ1EdK2MlRCU8j-lwHUM7yFTervooN-yDDwkGrJBP_0t_wyhiYSi78ulkgiOPHfxI73O8LBegng-6wzgFdAhQewH3h4CfqRBSmhff6b8_SYzGYna35Nh_Kj9BypI8SWh-rPQHFmC0uTLdvTGS6d2brJTTZ5YHDLC3ve0XOD7-nGnpuulxNDWB80qKgtC24axCp5QUhN-gMgOoY3Xd435HBPs"
2019/04/01 20:53:03 [debug] 14163#0: *1022 http header: "Accept-Encoding: gzip"
2019/04/01 20:53:03 [debug] 14163#0: *1022 http header: "Connection: close"
2019/04/01 20:53:03 [debug] 14163#0: *1022 http header done
2019/04/01 20:53:03 [debug] 14163#0: *1022 event timer del: 3: 1554123243464
2019/04/01 20:53:03 [debug] 14163#0: *1022 rewrite phase: 0
2019/04/01 20:53:03 [debug] 14163#0: *1022 rewrite phase: 1
2019/04/01 20:53:03 [debug] 14163#0: *1022 test location: "/"
2019/04/01 20:53:03 [debug] 14163#0: *1022 using configuration "/"
2019/04/01 20:53:03 [debug] 14163#0: *1022 http cl:-1 max:0
2019/04/01 20:53:03 [debug] 14163#0: *1022 rewrite phase: 3
2019/04/01 20:53:03 [debug] 14163#0: *1022 rewrite phase: 4
2019/04/01 20:53:03 [debug] 14163#0: *1022 post rewrite phase: 5
2019/04/01 20:53:03 [debug] 14163#0: *1022 generic phase: 6
2019/04/01 20:53:03 [debug] 14163#0: *1022 http vts limit handler
2019/04/01 20:53:03 [debug] 14163#0: *1022 generic phase: 7
2019/04/01 20:53:03 [debug] 14163#0: *1022 generic phase: 8
2019/04/01 20:53:03 [debug] 14163#0: *1022 access phase: 9
2019/04/01 20:53:03 [debug] 14163#0: *1022 access phase: 10
2019/04/01 20:53:03 [debug] 14163#0: *1022 access: 4508020A FFFFFFFF A2805F65
2019/04/01 20:53:03 [debug] 14163#0: *1022 access: 4508020A FFFFFFFF B40F8478
2019/04/01 20:53:03 [debug] 14163#0: *1022 access: 4508020A FFFFFFFF 8BCF5334
2019/04/01 20:53:03 [debug] 14163#0: *1022 access: 4508020A 0000FFFF 0000020A
2019/04/01 20:53:03 [debug] 14163#0: *1022 access phase: 11
2019/04/01 20:53:03 [debug] 14163#0: *1022 post access phase: 12
2019/04/01 20:53:03 [debug] 14163#0: *1022 generic phase: 13
2019/04/01 20:53:03 [debug] 14163#0: *1022 generic phase: 14
2019/04/01 20:53:03 [debug] 14163#0: *1022 http client request body preread 32776
2019/04/01 20:53:03 [debug] 14163#0: *1022 http request body chunked filter
2019/04/01 20:53:03 [debug] 14163#0: *1022 http body chunked buf t:1 f:0 000000000175C570, pos 000000000175CBF5, size: 32776 file: 0, size: 0
2019/04/01 20:53:03 [debug] 14163#0: *1022 http chunked byte: 38 s:0
2019/04/01 20:53:03 [debug] 14163#0: *1022 http chunked byte: 30 s:1
2019/04/01 20:53:03 [debug] 14163#0: *1022 http chunked byte: 30 s:1
2019/04/01 20:53:03 [debug] 14163#0: *1022 http chunked byte: 30 s:1
2019/04/01 20:53:03 [debug] 14163#0: *1022 http chunked byte: 0D s:1
2019/04/01 20:53:03 [debug] 14163#0: *1022 http chunked byte: 0A s:3
2019/04/01 20:53:03 [debug] 14163#0: *1022 http chunked byte: 1F s:4
2019/04/01 20:53:03 [debug] 14163#0: *1022 http body chunked buf t:1 f:0 000000000175C570, pos 0000000001764BFB, size: 2 file: 0, size: 0
2019/04/01 20:53:03 [debug] 14163#0: *1022 http chunked byte: 0D s:5
2019/04/01 20:53:03 [debug] 14163#0: *1022 http chunked byte: 0A s:6
2019/04/01 20:53:03 [debug] 14163#0: *1022 http body new buf t:1 f:0 000000000175CBFB, pos 000000000175CBFB, size: 32768 file: 0, size: 0
2019/04/01 20:53:03 [debug] 14163#0: *1022 http read client request body
2019/04/01 20:53:03 [debug] 14163#0: *1022 http write client request body, bufs 00000000016A07C8
2019/04/01 20:53:03 [debug] 14163#0: *1022 add cleanup: 00000000016A0958
2019/04/01 20:53:03 [debug] 14163#0: *1022 hashed path: /usr/local/openresty/nginx/client_body_temp/0000000169
2019/04/01 20:53:03 [debug] 14163#0: *1022 temp fd:8
2019/04/01 20:53:03 [warn] 14163#0: *1022 a client request body is buffered to a temporary file /usr/local/openresty/nginx/client_body_temp/0000000169, client: 10.10.10.6, server: harbor.example.com, request: "PATCH /v2/test/a/blobs/uploads/fa5bc114-4fd5-4f47-941e-1e63fca50039?_state=d9HXnK-pVuDprjMAocHG_IK3NwDuYJyH40F9BvmHo8l7Ik5hbWUiOiJ0ZXN0L2EiLCJVVUlEIjoiZmE1YmMxMTQtNGZkNS00ZjQ3LTk0MWUtMWU2M2ZjYTUwMDM5IiwiT2Zmc2V0IjowLCJTdGFydGVkQXQiOiIyMDE5LTA0LTAxVDEyOjUzOjAzLjQ1ODkwNDMwOVoifQ%3D%3D HTTP/1.1", host: "harbor.example.com"
2019/04/01 20:53:03 [debug] 14163#0: *1022 write: 8, 000000000175CBFB, 32768, 0
2019/04/01 20:53:03 [debug] 14163#0: *1022 recv: eof:0, avail:0
2019/04/01 20:53:03 [debug] 14163#0: *1022 http client request body recv -2
2019/04/01 20:53:03 [debug] 14163#0: *1022 http client request body rest 3
2019/04/01 20:53:03 [debug] 14163#0: *1022 event timer add: 3: 60000:1554123243472
2019/04/01 20:53:03 [debug] 14163#0: *1022 http finalize request: -4, "/v2/test/a/blobs/uploads/fa5bc114-4fd5-4f47-941e-1e63fca50039?_state=d9HXnK-pVuDprjMAocHG_IK3NwDuYJyH40F9BvmHo8l7Ik5hbWUiOiJ0ZXN0L2EiLCJVVUlEIjoiZmE1YmMxMTQtNGZkNS00ZjQ3LTk0MWUtMWU2M2ZjYTUwMDM5IiwiT2Zmc2V0IjowLCJTdGFydGVkQXQiOiIyMDE5LTA0LTAxVDEyOjUzOjAzLjQ1ODkwNDMwOVoifQ%3D%3D" a:1, c:2
2019/04/01 20:53:03 [debug] 14163#0: *1022 http request count:2 blk:0
2019/04/01 20:53:03 [debug] 14163#0: *1022 http run request: "/v2/test/a/blobs/uploads/fa5bc114-4fd5-4f47-941e-1e63fca50039?_state=d9HXnK-pVuDprjMAocHG_IK3NwDuYJyH40F9BvmHo8l7Ik5hbWUiOiJ0ZXN0L2EiLCJVVUlEIjoiZmE1YmMxMTQtNGZkNS00ZjQ3LTk0MWUtMWU2M2ZjYTUwMDM5IiwiT2Zmc2V0IjowLCJTdGFydGVkQXQiOiIyMDE5LTA0LTAxVDEyOjUzOjAzLjQ1ODkwNDMwOVoifQ%3D%3D"
2019/04/01 20:53:03 [debug] 14163#0: *1022 http read client request body
2019/04/01 20:53:03 [debug] 14163#0: *1022 http write client request body, bufs 0000000000000000
2019/04/01 20:53:03 [debug] 14163#0: *1022 recv: eof:0, avail:1
2019/04/01 20:53:03 [debug] 14163#0: *1022 recv: fd:3 0 of 0
2019/04/01 20:53:03 [debug] 14163#0: *1022 http client request body recv 0
2019/04/01 20:53:03 [info] 14163#0: *1022 client prematurely closed connection, client: 10.10.10.6, server: harbor.example.com, request: "PATCH /v2/test/a/blobs/uploads/fa5bc114-4fd5-4f47-941e-1e63fca50039?_state=d9HXnK-pVuDprjMAocHG_IK3NwDuYJyH40F9BvmHo8l7Ik5hbWUiOiJ0ZXN0L2EiLCJVVUlEIjoiZmE1YmMxMTQtNGZkNS00ZjQ3LTk0MWUtMWU2M2ZjYTUwMDM5IiwiT2Zmc2V0IjowLCJTdGFydGVkQXQiOiIyMDE5LTA0LTAxVDEyOjUzOjAzLjQ1ODkwNDMwOVoifQ%3D%3D HTTP/1.1", host: "harbor.example.com"
2019/04/01 20:53:03 [debug] 14163#0: *1022 http finalize request: 400, "/v2/test/a/blobs/uploads/fa5bc114-4fd5-4f47-941e-1e63fca50039?_state=d9HXnK-pVuDprjMAocHG_IK3NwDuYJyH40F9BvmHo8l7Ik5hbWUiOiJ0ZXN0L2EiLCJVVUlEIjoiZmE1YmMxMTQtNGZkNS00ZjQ3LTk0MWUtMWU2M2ZjYTUwMDM5IiwiT2Zmc2V0IjowLCJTdGFydGVkQXQiOiIyMDE5LTA0LTAxVDEyOjUzOjAzLjQ1ODkwNDMwOVoifQ%3D%3D" a:1, c:1
2019/04/01 20:53:03 [debug] 14163#0: *1022 http terminate request count:1
2019/04/01 20:53:03 [debug] 14163#0: *1022 http terminate cleanup count:1 blk:0
2019/04/01 20:53:03 [debug] 14163#0: *1022 http posted request: "/v2/test/a/blobs/uploads/fa5bc114-4fd5-4f47-941e-1e63fca50039?_state=d9HXnK-pVuDprjMAocHG_IK3NwDuYJyH40F9BvmHo8l7Ik5hbWUiOiJ0ZXN0L2EiLCJVVUlEIjoiZmE1YmMxMTQtNGZkNS00ZjQ3LTk0MWUtMWU2M2ZjYTUwMDM5IiwiT2Zmc2V0IjowLCJTdGFydGVkQXQiOiIyMDE5LTA0LTAxVDEyOjUzOjAzLjQ1ODkwNDMwOVoifQ%3D%3D"
2019/04/01 20:53:03 [debug] 14163#0: *1022 http terminate handler count:1
2019/04/01 20:53:03 [debug] 14163#0: *1022 http request count:1 blk:0
2019/04/01 20:53:03 [debug] 14163#0: *1022 http close request
2019/04/01 20:53:03 [debug] 14163#0: *1022 http log handler
2019/04/01 20:53:03 [debug] 14163#0: *1022 http vts handler
2019/04/01 20:53:03 [debug] 14163#0: *1022 run cleanup: 00000000016A0958
2019/04/01 20:53:03 [debug] 14163#0: *1022 file cleanup: fd:8
2019/04/01 20:53:03 [debug] 14163#0: *1022 free: 00000000016A1150, unused: 0
2019/04/01 20:53:03 [debug] 14163#0: *1022 free: 000000000169FFC0, unused: 1043
2019/04/01 20:53:03 [debug] 14163#0: *1022 close http connection: 3
2019/04/01 20:53:03 [debug] 14163#0: *1022 event timer del: 3: 1554123243472
2019/04/01 20:53:03 [debug] 14163#0: *1022 reusable connection: 0
2019/04/01 20:53:03 [debug] 14163#0: *1022 free: 000000000175C570
2019/04/01 20:53:03 [debug] 14163#0: *1022 free: 00000000016862E0, unused: 136

Contributor guide

No contributing guide indexed for this repository

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start with the posted Nginx server blocks and debug log, focusing on the chunked PATCH request and the premature client close. Reproduce a Docker push through the proxy and compare it with a direct registry connection. Done means isolating whether the proxy causes the 400 response and documenting a verified configuration change.

Written by the indexing model from the issue text.

Assessment

Tech stack
docker, nginx
Domain
devops, networking
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
25/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.