chobits / ngx_http_proxy_connect_module

A forward proxy module for CONNECT request handling
BSD 2-Clause "Simplified" License
1.75k stars 484 forks source link

nginx proxy throws error 400 for https CONNECT request #273

Closed ns-aparnau closed 1 year ago

ns-aparnau commented 1 year ago

Hello, I am stuck on this error - kindly help! curl https://dl.boxcloud.com/d/1/21bytes.txt/download -x a.b.c.d:443 -v

Trying a.b.c.d:443... TCP_NODELAY set Connected to a.b.c.d (a.b.c.d) port 443 (#0) allocate connect buffer! Establish HTTP proxy tunnel to dl.boxcloud.com:443 CONNECT dl.boxcloud.com:443 HTTP/1.1 Host: dl.boxcloud.com:443 User-Agent: curl/7.68.0 Proxy-Connection: Keep-Alive

< HTTP/1.1 400 Bad Request < Server: nginx/1.25.0 < Date: Fri, 16 Jun 2023 12:39:52 GMT < Content-Type: text/html < Content-Length: 255 < Connection: close <

Received HTTP code 400 from proxy after CONNECT CONNECT phase completed! Closing connection 0 curl: (56) Received HTTP code 400 from proxy after CONNECT I am able to make the same request on port 80 (http) but not on 443(https) curl http://dl.boxcloud.com/d/1/21bytes.txt/download -x a.b.c.d:80 -v a.b.c.d - - [16/Jun/2023:12:11:52 +0000] "GET http://dl.boxcloud.com/d/1/21bytes.txt/download HTTP/1.1" 200 20 "-" "curl/7.68.0" 0.002 0.001 .

Here is my nginx conf- upstream box_download {

keepalive 64; server har_box_fs_1:8080; } server {

sendfile on; tcp_nopush off; output_buffers 1 4096k; keepalive_timeout 65; tcp_nodelay on;

listen 443 ssl;

ssl_certificate /etc/nginx/certs/box/box.pem; ssl_certificate_key /etc/nginx/certs/box/box.key; ssl_protocols TLSv1 TLSv1.1 TLSv1.2 TLSv1.3;

server_name dl.boxcloud.com;

allow all;

proxy_connect; proxy_connect_allow 443; proxy_connect_connect_timeout 10s; proxy_connect_data_timeout 10s;

client_max_body_size 2G; client_body_buffer_size 32k;

resolver a.b.c.d;

proxy_read_timeout 1000; proxy_http_version 1.1; proxy_set_header Connection ""; proxy_buffer_size 4096k; proxy_buffers 8 4096k; large_client_header_buffers 4 16k; proxy_busy_buffers_size 4096k;

proxy_buffering off;

location ~ ^/d/1/[0-9a-z]+/download$ {

proxy_pass http://box_download; proxy_next_upstream error timeout invalid_header http_500 http_502 http_503 http_504; proxy_set_header Host $host;

proxy_set_header Host $proxy_host;

proxy_ssl_server_name on; }

location / {

proxy_set_header X-Real-IP $remote_addr; proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;

proxy_set_header Host $proxy_host;

proxy_set_header Host $host; proxy_set_header X-Forwarded-Host $host; proxy_set_header X-NginX-Proxy true; proxy_set_header X-Forwarded-Proto $scheme;

proxy_cache cache;

add_header X-Proxy-Cache $upstream_cache_status; proxy_pass http://box_download; proxy_ssl_server_name on; proxy_next_upstream error timeout invalid_header http_500 http_502 http_503 http_504; proxy_redirect off; } }

Can you please help what is is that is causing this error and what am I missing here!

ns-aparnau commented 1 year ago

Additional details - OS: Ubuntu 20.04 nginx version: nginx/1.25.0 built by gcc 12.2.1 20220924 (Alpine 12.2.1_git20220924-r4) built with OpenSSL 3.0.9 30 May 2023 TLS SNI support enabled configure arguments: --prefix=/etc/nginx --sbin-path=/usr/sbin/nginx --modules-path=/usr/lib/nginx/modules --conf-path=/etc/nginx/nginx.conf --error-log-path=/var/log/nginx/error.log --http-log-path=/var/log/nginx/access.log --pid-path=/var/run/nginx.pid --lock-path=/var/run/nginx.lock --http-client-body-temp-path=/var/cache/nginx/client_temp --http-proxy-temp-path=/var/cache/nginx/proxy_temp --http-fastcgi-temp-path=/var/cache/nginx/fastcgi_temp --http-uwsgi-temp-path=/var/cache/nginx/uwsgi_temp --http-scgi-temp-path=/var/cache/nginx/scgi_temp --with-perl_modules_path=/usr/lib/perl5/vendor_perl --user=nginx --group=nginx --with-compat --with-file-aio --with-threads --with-http_addition_module --with-http_auth_request_module --with-http_dav_module --with-http_flv_module --with-http_gunzip_module --with-http_gzip_static_module --with-http_mp4_module --with-http_random_index_module --with-http_realip_module --with-http_secure_link_module --with-http_slice_module --with-http_ssl_module --with-http_stub_status_module --with-http_sub_module --with-http_v2_module --with-mail --with-mail_ssl_module --with-stream --with-stream_realip_module --with-stream_ssl_module --with-stream_ssl_preread_module --with-compat --add-dynamic-module=/ngx_http_proxy_connect_module

chobits commented 1 year ago

curl https://dl.boxcloud.com/d/1/21bytes.txt/download -x 172.18.29.108:443 -v

This command only sends CONNECT request not over SSL, but ur server listened on SSL, so nginx rejects non-ssl flow with 400.

if you want ur server nginx to listen on SSL, see this doc https://github.com/chobits/ngx_http_proxy_connect_module#example-for-curl-connect-request-in-https. make sure ur configuration and curl command used are right

ns-aparnau commented 1 year ago

Thanks, I updated the curl request to curl -x https://172.18.29.108:443 https://dl.boxcloud.com/d/1/21bytes.txt/download --proxy-insecure -v - now it seems there is a dns resolver error - 2023/06/18 06:14:58 [error] 21#21: *69560166 proxy_connect: no resolver defined to resolve dl.boxcloud.com, client: 172.18.29.108, server: dl.boxcloud.com, request: "CONNECT dl.boxcloud.com:443 HTTP/1.1", host: "dl.boxcloud.com:443" I have already defined server in the upstream block (server har_box_fs_1:8080;) and this server is a docker container that is accessible from nginx - but then why at the time of requesting, nginx is not able to resolve this hostname?

 /usr/src/app # ping har_box_fs_1
PING har_box_fs_1 (192.168.80.11): 56 data bytes
64 bytes from 192.168.80.11: seq=0 ttl=64 time=0.151 ms
64 bytes from 192.168.80.11: seq=1 ttl=64 time=0.110 ms
64 bytes from 192.168.80.11: seq=2 ttl=64 time=0.132 ms
64 bytes from 192.168.80.11: seq=3 ttl=64 time=0.135 ms
^C
--- har_box_fs_1 ping statistics ---
4 packets transmitted, 4 packets received, 0% packet loss
round-trip min/avg/max = 0.110/0.132/0.151 ms
chobits commented 1 year ago

Maybe you forgot to configure directive: https://nginx.org/en/docs/http/ngx_http_core_module.html#resolver

The data flow from your curl command will be handled by the proxy_connect module. This module handles data flow itself, so the ·upstream {}· block does not work with proxy_connect.

ns-aparnau commented 1 year ago

I did define it already - resolver 192.168.80.11; But still somehow it is complaining for the same

chobits commented 1 year ago

This looks weird. Maybe it could be that the reload failed? I can't find it eithe. To accurately pinpoint the problem, you can open and show the full debug log.

ns-aparnau commented 1 year ago

I will enable the debugging and share - so just to summarize - the problem I am trying to solve is to be able to make https calls to the proxied back end-

curl  -x a.b.c.d:80  http://dl.boxcloud.com/d/1/21bytes.txt/download -v // this works now
curl  -x a.b.c.d:443  https://dl.boxcloud.com/d/1/21bytes.txt/download -v  //this is expected to work

nginx with proxy_connect together are also not able to resolve this problem so far -

ns-aparnau commented 1 year ago

2023/06/18 13:40:21 [debug] 25#25: posix_memalign: 00007FF90FC3AAA0:512 @16 2023/06/18 13:40:21 [debug] 25#25: 5 accept: a.b.c.d:43562 fd:27 2023/06/18 13:40:21 [debug] 25#25: 5 event timer add: 27: 60000:8224156758 2023/06/18 13:40:21 [debug] 25#25: 5 reusable connection: 1 2023/06/18 13:40:21 [debug] 25#25: 5 epoll add event: fd:27 op:1 ev:80002001 2023/06/18 13:40:21 [debug] 25#25: epoll del event: fd:7 op:2 ev:00000000 2023/06/18 13:40:21 [debug] 25#25: epoll add event: fd:7 op:1 ev:10000001 2023/06/18 13:40:21 [debug] 25#25: timer delta: 1380915 2023/06/18 13:40:21 [debug] 25#25: worker cycle 2023/06/18 13:40:21 [debug] 25#25: epoll timer: 60000 2023/06/18 13:40:21 [debug] 25#25: epoll: fd:27 ev:0001 d:00007FF90BB5A6D8 2023/06/18 13:40:21 [debug] 25#25: 5 http check ssl handshake 2023/06/18 13:40:21 [debug] 25#25: 5 http recv(): 1 2023/06/18 13:40:21 [debug] 25#25: 5 https ssl handshake: 0x16 2023/06/18 13:40:21 [debug] 25#25: 5 tcp_nodelay 2023/06/18 13:40:21 [debug] 25#25: 5 reusable connection: 0 2023/06/18 13:40:21 [debug] 25#25: 5 SSL server name: null 2023/06/18 13:40:21 [debug] 25#25: 5 SSL ALPN supported by client: http/1.1 2023/06/18 13:40:21 [debug] 25#25: 5 SSL ALPN selected: http/1.1 2023/06/18 13:40:21 [debug] 25#25: 5 SSL_do_handshake: -1 2023/06/18 13:40:21 [debug] 25#25: 5 SSL_get_error: 2 2023/06/18 13:40:21 [debug] 25#25: timer delta: 6 2023/06/18 13:40:21 [debug] 25#25: worker cycle 2023/06/18 13:40:21 [debug] 25#25: epoll timer: 59994 2023/06/18 13:40:21 [debug] 25#25: epoll: fd:27 ev:0001 d:00007FF90BB5A6D8 2023/06/18 13:40:21 [debug] 25#25: 5 SSL handshake handler: 0 2023/06/18 13:40:21 [debug] 25#25: 5 SSL_do_handshake: 1 2023/06/18 13:40:21 [debug] 25#25: 5 SSL: TLSv1.3, cipher: "TLS_AES_256_GCM_SHA384 TLSv1.3 Kx=any Au=any Enc=AESGCM(256) Mac=AEAD" 2023/06/18 13:40:21 [debug] 25#25: 5 reusable connection: 1 2023/06/18 13:40:21 [debug] 25#25: 5 http wait request handler 2023/06/18 13:40:21 [debug] 25#25: 5 malloc: 00007FF90FC31DA0:1024 2023/06/18 13:40:21 [debug] 25#25: 5 SSL_read: 122 2023/06/18 13:40:21 [debug] 25#25: 5 SSL_read: -1 2023/06/18 13:40:21 [debug] 25#25: 5 SSL_get_error: 2 2023/06/18 13:40:21 [debug] 25#25: 5 reusable connection: 0 2023/06/18 13:40:21 [debug] 25#25: 5 posix_memalign: 00007FF90FCB7350:4096 @16 2023/06/18 13:40:21 [debug] 25#25: 5 http process request line 2023/06/18 13:40:21 [info] 25#25: 5 client sent invalid request while reading client request line, client: a.b.c.d, server: dl.boxcloud.com, request: "CONNECT dl.boxcloud.com:443 HTTP/1.1" 2023/06/18 13:40:21 [debug] 25#25: 5 http finalize request: 400, "?" a:1, c:1 2023/06/18 13:40:21 [debug] 25#25: 5 event timer del: 27: 8224156758 2023/06/18 13:40:21 [debug] 25#25: 5 http special response: 400, "?" 2023/06/18 13:40:21 [debug] 25#25: 5 http set discard body 2023/06/18 13:40:21 [debug] 25#25: 5 HTTP/1.1 400 Bad Request Server: nginx/1.25.0 Date: Sun, 18 Jun 2023 13:40:21 GMT Content-Type: text/html Content-Length: 157 Connection: close

2023/06/18 13:40:21 [debug] 25#25: 5 write new buf t:1 f:0 00007FF90FCB81E8, pos 00007FF90FCB81E8, size: 152 file: 0, size: 0 2023/06/18 13:40:21 [debug] 25#25: 5 http write filter: l:0 f:0 s:152 2023/06/18 13:40:21 [debug] 25#25: 5 http output filter "?" 2023/06/18 13:40:21 [debug] 25#25: 5 http copy filter: "?" 2023/06/18 13:40:21 [debug] 25#25: 5 posix_memalign: 00007FF90FCB84D0:4096 @16 2023/06/18 13:40:21 [debug] 25#25: 5 http postpone filter "?" 00007FF90FCB8570 2023/06/18 13:40:21 [debug] 25#25: 5 write old buf t:1 f:0 00007FF90FCB81E8, pos 00007FF90FCB81E8, size: 152 file: 0, size: 0 2023/06/18 13:40:21 [debug] 25#25: 5 write new buf t:0 f:0 0000000000000000, pos 0000558BC2BB2F00, size: 104 file: 0, size: 0 2023/06/18 13:40:21 [debug] 25#25: 5 write new buf t:0 f:0 0000000000000000, pos 0000558BC2BB3460, size: 53 file: 0, size: 0 2023/06/18 13:40:21 [debug] 25#25: 5 http write filter: l:1 f:0 s:309 2023/06/18 13:40:21 [debug] 25#25: 5 http write filter limit 2097152 2023/06/18 13:40:21 [debug] 25#25: 5 posix_memalign: 00007FF90FD474B0:512 @16 2023/06/18 13:40:21 [debug] 25#25: 5 malloc: 00007FF90FBEAE70:16384 2023/06/18 13:40:21 [debug] 25#25: 5 SSL buf copy: 152 2023/06/18 13:40:21 [debug] 25#25: 5 SSL buf copy: 104 2023/06/18 13:40:21 [debug] 25#25: 5 SSL buf copy: 53 2023/06/18 13:40:21 [debug] 25#25: 5 SSL to write: 309 2023/06/18 13:40:21 [debug] 25#25: 5 SSL_write: 309 2023/06/18 13:40:21 [debug] 25#25: 5 http write filter 0000000000000000 2023/06/18 13:40:21 [debug] 25#25: 5 http copy filter: 0 "?" 2023/06/18 13:40:21 [debug] 25#25: 5 http finalize request: 0, "?" a:1, c:1 2023/06/18 13:40:21 [debug] 25#25: 5 SSL_shutdown: 1 2023/06/18 13:40:21 [debug] 25#25: 5 reusable connection: 1 2023/06/18 13:40:21 [debug] 25#25: 5 event timer add: 27: 5000:8224101766 2023/06/18 13:40:21 [debug] 25#25: timer delta: 2 2023/06/18 13:40:21 [debug] 25#25: worker cycle 2023/06/18 13:40:21 [debug] 25#25: epoll timer: 5000 172.18.29.108 - - [18/Jun/2023:13:40:21 +0000] "CONNECT dl.boxcloud.com:443 HTTP/1.1" 400 157 "-" "-" 0.001 - . 2023/06/18 13:40:21 [debug] 25#25: epoll: fd:27 ev:2019 d:00007FF90BB5A6D8 2023/06/18 13:40:21 [debug] 25#25: epoll_wait() error on fd:27 ev:2019 2023/06/18 13:40:21 [debug] 25#25: 5 http lingering close handler 2023/06/18 13:40:21 [debug] 25#25: 5 recv: eof:1, avail:-1 2023/06/18 13:40:21 [debug] 25#25: 5 recv: fd:27 -1 of 4096 2023/06/18 13:40:21 [info] 25#25: 5 recv() failed (104: Connection reset by peer) while reading client request line, client: 172.18.29.108, server: dl.boxcloud.com, request: "CONNECT dl.boxcloud.com:443 HTTP/1.1" 2023/06/18 13:40:21 [debug] 25#25: 5 lingering read: -1 2023/06/18 13:40:21 [debug] 25#25: 5 http request count:1 blk:0 2023/06/18 13:40:21 [debug] 25#25: 5 http close request 2023/06/18 13:40:21 [debug] 25#25: 5 http log handler 2023/06/18 13:40:21 [debug] 25#25: 5 free: 00007FF90FCB7350, unused: 8 2023/06/18 13:40:21 [debug] 25#25: 5 free: 00007FF90FCB84D0, unused: 3707 2023/06/18 13:40:21 [debug] 25#25: 5 close http connection: 27 2023/06/18 13:40:21 [debug] 25#25: 5 SSL_shutdown: 1 2023/06/18 13:40:21 [debug] 25#25: 5 event timer del: 27: 8224101766 2023/06/18 13:40:21 [debug] 25#25: 5 reusable connection: 0 2023/06/18 13:40:21 [debug] 25#25: 5 free: 00007FF90FBEAE70 2023/06/18 13:40:21 [debug] 25#25: 5 free: 00007FF90FC31DA0 2023/06/18 13:40:21 [debug] 25#25: 5 free: 00007FF90FC3AAA0, unused: 16 2023/06/18 13:40:21 [debug] 25#25: 5 free: 00007FF90FD474B0, unused: 400 2023/06/18 13:40:21 [debug] 25#25: timer delta: 1 2023/06/18 13:40:21 [debug] 25#25: worker cycle 2023/06/18 13:40:21 [debug] 25#25: epoll timer: -1 2023/06/18 13:40:21 [debug] 36#36: timer delta: 10010 2023/06/18 13:40:21 [debug] 36#36: event timer del: -1: 8224097203 2023/06/18 13:40:21 [debug] 36#36: http file cache expire 2023/06/18 13:40:21 [debug] 36#36: malloc: 00007FF90FC398B0:55

ns-aparnau commented 1 year ago

Looks like there is an issue in resolving the dns- 2023/06/18 13:53:24 [debug] 30#30: resolver DNS response 4009 fl:8180 1/1/0/0 2023/06/18 13:53:24 [debug] 30#30: resolver DNS response qt:1 cl:1 2023/06/18 13:53:24 [debug] 30#30: malloc: 00007FF90FC46840:16 2023/06/18 13:53:24 [debug] 30#30: resolver qs:dl.boxcloud.com 2023/06/18 13:53:24 [debug] 30#30: resolver naddrs:1 cname:0000000000000000 ttl:60 2023/06/18 13:53:24 [debug] 30#30: 10 http upstream resolve: "/d/1/21bytes.txt/download?" 2023/06/18 13:53:24 [debug] 30#30: 10 name was resolved to 74.112.186.128 2023/06/18 13:53:24 [debug] 30#30: 10 posix_memalign: 00007FF90FCB9740:4096 @16 2023/06/18 13:53:24 [debug] 30#30: resolve name done: 0 2023/06/18 13:53:24 [debug] 30#30: event timer del: -1: 8224909878 2023/06/18 13:53:24 [debug] 30#30: resolver expire 2023/06/18 13:53:24 [debug] 30#30: event timer del: -1: 8224884878 2023/06/18 13:53:24 [debug] 30#30: 10 get rr peer, try: 1 2023/06/18 13:53:24 [debug] 30#30: 10 stream socket 24 2023/06/18 13:53:24 [debug] 30#30: 10 epoll add connection: fd:24 ev:80002005 2023/06/18 13:53:24 [debug] 30#30: 10 connect to 74.112.186.128:80, fd:24 #12 2023/06/18 13:53:24 [debug] 30#30: 10 http upstream connect: -2 2023/06/18 13:53:24 [debug] 30#30: 10 posix_memalign: 00007FF90FC35C70:128 @16 2023/06/18 13:53:24 [debug] 30#30: 10 event timer add: 24: 60000:8224939891 2023/06/18 13:53:24 [debug] 30#30: recv: fd:22 -1 of 4096 2023/06/18 13:53:24 [debug] 30#30: recv() not ready (11: Resource temporarily unavailable)

chobits commented 1 year ago

try my example:

    server {
        listen 8888 ssl; 

        ssl_certificate_key /opt/nginx/server.key;
        ssl_certificate     /opt/nginx/server.crt;
        ssl_session_cache shared:SSL:1m;

        error_log logs/err_8888.log debug;

        resolver 223.5.5.5 ipv6=off;

        proxy_connect;
        proxy_connect_allow all;
        proxy_connect_connect_timeout 10s;
        proxy_connect_data_timeout 120s;

        location / {
            proxy_pass http://$host;
            proxy_set_header Host $host;
        }
    }

access.log:

127.0.0.1 - - [19/Jun/2023:13:28:09 +0800] "CONNECT dl.boxcloud.com:443 HTTP/1.1" 200 4363 "-" "curl/7.68.0" "-"
^C
$ curl -x https://127.0.0.1:8888  https://dl.boxcloud.com/d/1/21bytes.txt/download --proxy-insecure -v
*   Trying 127.0.0.1:8888...
* TCP_NODELAY set
* Connected to 127.0.0.1 (127.0.0.1) port 8888 (#0)
* ALPN, offering http/1.1
* successfully set certificate verify locations:
*   CAfile: /etc/ssl/certs/ca-certificates.crt
  CApath: /etc/ssl/certs
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
* TLSv1.3 (IN), TLS handshake, Server hello (2):
* TLSv1.2 (IN), TLS handshake, Certificate (11):
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
* TLSv1.2 (IN), TLS handshake, Server finished (14):
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
* TLSv1.2 (OUT), TLS change cipher, Change cipher spec (1):
* TLSv1.2 (OUT), TLS handshake, Finished (20):
* TLSv1.2 (IN), TLS handshake, Finished (20):
* SSL connection using TLSv1.2 / ECDHE-RSA-AES256-GCM-SHA384
* ALPN, server accepted to use http/1.1
* Proxy certificate:
*  subject: C=AU; ST=Some-State; O=Internet Widgits Pty Ltd
*  start date: Nov 25 08:36:38 2022 GMT
*  expire date: Nov 25 08:36:38 2023 GMT
*  issuer: C=AU; ST=Some-State; O=Internet Widgits Pty Ltd
*  SSL certificate verify result: self signed certificate (18), continuing anyway.
* allocate connect buffer!
* Establish HTTP proxy tunnel to dl.boxcloud.com:443
> CONNECT dl.boxcloud.com:443 HTTP/1.1
> Host: dl.boxcloud.com:443
> User-Agent: curl/7.68.0
> Proxy-Connection: Keep-Alive
>
< HTTP/1.1 200 Connection Established
< Proxy-agent: nginx
<
* Proxy replied 200 to CONNECT request
* CONNECT phase completed!
* ALPN, offering h2
* ALPN, offering http/1.1
* successfully set certificate verify locations:
*   CAfile: /etc/ssl/certs/ca-certificates.crt
  CApath: /etc/ssl/certs
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
* CONNECT phase completed!
* CONNECT phase completed!
* TLSv1.3 (IN), TLS handshake, Server hello (2):
* TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
* TLSv1.3 (IN), TLS handshake, Certificate (11):
* TLSv1.3 (IN), TLS handshake, CERT verify (15):
* TLSv1.3 (IN), TLS handshake, Finished (20):
* TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
* TLSv1.3 (OUT), TLS handshake, Finished (20):
* SSL connection using TLSv1.3 / TLS_AES_256_GCM_SHA384
* ALPN, server accepted to use h2
* Server certificate:
*  subject: C=US; ST=California; L=Redwood City; O=Box, Inc.; CN=*.boxcloud.com
*  start date: Jan 13 00:00:00 2023 GMT
*  expire date: Jan 12 23:59:59 2024 GMT
*  subjectAltName: host "dl.boxcloud.com" matched cert's "*.boxcloud.com"
*  issuer: C=US; O=DigiCert Inc; CN=DigiCert TLS RSA SHA256 2020 CA1
*  SSL certificate verify ok.
* Using HTTP2, server supports multi-use
* Connection state changed (HTTP/2 confirmed)
* Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0
* Using Stream ID: 1 (easy handle 0x55d4304ede50)
> GET /d/1/21bytes.txt/download HTTP/2
> Host: dl.boxcloud.com
> user-agent: curl/7.68.0
> accept: */*
>
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
* old SSL session ID is stale, removing
* Connection state changed (MAX_CONCURRENT_STREAMS == 100)!
< HTTP/2 400
< server: nginx
< date: Mon, 19 Jun 2023 05:28:45 GMT
< content-type: text/html;charset=utf-8
< content-length: 0
< x-envoy-upstream-service-time: 2
< x-box-original-ingress-adc-host: prod-a-traffic-manager-q1l5
< strict-transport-security: max-age=31536000
< via: 1.1 google
< alt-svc: h3=":443"; ma=2592000,h3-29=":443"; ma=2592000
<
* Connection #0 to host 127.0.0.1 left intact
./configure --prefix=/opt/nginx \
 --with-ld-opt="-lpcre" \
 --with-pcre \
 --with-http_ssl_module \
 --with-http_image_filter_module \
 --with-http_v2_module \
 --with-http_addition_module \
 --with-http_mp4_module \
 --with-http_realip_module \
 --with-http_xslt_module \
 --with-http_geoip_module \
 --with-http_sub_module \
 --with-http_dav_module \
 --with-http_flv_module \
 --with-http_gunzip_module \
 --with-http_gzip_static_module \
 --with-http_auth_request_module \
 --with-http_random_index_module \
 --with-http_secure_link_module \
 --with-http_degradation_module \
 --with-http_slice_module \
 --with-http_stub_status_module \
 --with-mail \
 --with-mail_ssl_module \
 --with-stream \
 --with-stream_ssl_module \
 --with-stream_realip_module \
 --with-stream_geoip_module \
 --with-stream_ssl_preread_module \
 --with-google_perftools_module \
 --with-cpp_test_module \
 --add-module=../ngx_http_proxy_connect_module/ \
  --with-http_perl_module \
 --with-compat \
 --with-debug

2023/06/19 13:48:54 [debug] 302#0: accept on 0.0.0.0:8888, ready: 0
2023/06/19 13:48:54 [debug] 302#0: posix_memalign: 0000564E54631F50:512 @16
2023/06/19 13:48:54 [debug] 302#0: *12 accept: 127.0.0.1:48668 fd:3
2023/06/19 13:48:54 [debug] 302#0: *12 event timer add: 3: 60000:1621547
2023/06/19 13:48:54 [debug] 302#0: *12 reusable connection: 1
2023/06/19 13:48:54 [debug] 302#0: *12 epoll add event: fd:3 op:1 ev:80002001
2023/06/19 13:48:54 [debug] 302#0: *12 http check ssl handshake
2023/06/19 13:48:54 [debug] 302#0: *12 http recv(): 1
2023/06/19 13:48:54 [debug] 302#0: *12 https ssl handshake: 0x16
2023/06/19 13:48:54 [debug] 302#0: *12 tcp_nodelay
2023/06/19 13:48:54 [debug] 302#0: *12 reusable connection: 0
2023/06/19 13:48:54 [debug] 302#0: *12 ssl get session: 0D92886C:32
2023/06/19 13:48:54 [debug] 302#0: *12 SSL server name: null
2023/06/19 13:48:54 [debug] 302#0: *12 SSL ALPN supported by client: http/1.1
2023/06/19 13:48:54 [debug] 302#0: *12 SSL ALPN selected: http/1.1
2023/06/19 13:48:54 [debug] 302#0: *12 SSL_do_handshake: -1
2023/06/19 13:48:54 [debug] 302#0: *12 SSL_get_error: 2
2023/06/19 13:48:54 [debug] 302#0: *12 SSL handshake handler: 0
2023/06/19 13:48:54 [debug] 302#0: *12 ssl new session: 56709369:32:153
2023/06/19 13:48:54 [debug] 302#0: *12 SSL_do_handshake: 1
2023/06/19 13:48:54 [debug] 302#0: *12 SSL: TLSv1.2, cipher: "ECDHE-RSA-AES256-GCM-SHA384 TLSv1.2 Kx=ECDH Au=RSA Enc=AESGCM(256) Mac=AEAD"
2023/06/19 13:48:54 [debug] 302#0: *12 reusable connection: 1
2023/06/19 13:48:54 [debug] 302#0: *12 http wait request handler
2023/06/19 13:48:54 [debug] 302#0: *12 malloc: 0000564E5459BF90:1024
2023/06/19 13:48:54 [debug] 302#0: *12 SSL_read: -1
2023/06/19 13:48:54 [debug] 302#0: *12 SSL_get_error: 2
2023/06/19 13:48:54 [debug] 302#0: *12 free: 0000564E5459BF90
2023/06/19 13:48:54 [debug] 302#0: *12 http wait request handler
2023/06/19 13:48:54 [debug] 302#0: *12 malloc: 0000564E5459BF90:1024
2023/06/19 13:48:54 [debug] 302#0: *12 SSL_read: 122
2023/06/19 13:48:54 [debug] 302#0: *12 SSL_read: -1
2023/06/19 13:48:54 [debug] 302#0: *12 SSL_get_error: 2
2023/06/19 13:48:54 [debug] 302#0: *12 reusable connection: 0
2023/06/19 13:48:54 [debug] 302#0: *12 posix_memalign: 0000564E5462C6B0:4096 @16
2023/06/19 13:48:54 [debug] 302#0: *12 http process request line
2023/06/19 13:48:54 [debug] 302#0: *12 http request line: "CONNECT dl.boxcloud.com:443 HTTP/1.1"
2023/06/19 13:48:54 [debug] 302#0: *12 posix_memalign: 0000564E545B2A50:4096 @16
2023/06/19 13:48:54 [debug] 302#0: *12 http process request header line
2023/06/19 13:48:54 [debug] 302#0: *12 http header: "Host: dl.boxcloud.com:443"
2023/06/19 13:48:54 [debug] 302#0: *12 http header: "User-Agent: curl/7.68.0"
2023/06/19 13:48:54 [debug] 302#0: *12 http header: "Proxy-Connection: Keep-Alive"
2023/06/19 13:48:54 [debug] 302#0: *12 http header done
2023/06/19 13:48:54 [debug] 302#0: *12 event timer del: 3: 1621547
2023/06/19 13:48:54 [debug] 302#0: *12 generic phase: 0
2023/06/19 13:48:54 [debug] 302#0: *12 generic phase: 1
2023/06/19 13:48:54 [debug] 302#0: *12 rewrite phase: 2
2023/06/19 13:48:54 [debug] 302#0: *12 rewrite phase: 4
2023/06/19 13:48:54 [debug] 302#0: *12 post rewrite phase: 5
2023/06/19 13:48:54 [debug] 302#0: *12 generic phase: 6
2023/06/19 13:48:54 [debug] 302#0: *12 generic phase: 7
2023/06/19 13:48:54 [debug] 302#0: *12 generic phase: 8
2023/06/19 13:48:54 [debug] 302#0: *12 generic phase: 9
2023/06/19 13:48:54 [debug] 302#0: *12 access phase: 10
2023/06/19 13:48:54 [debug] 302#0: *12 access phase: 11
2023/06/19 13:48:54 [debug] 302#0: *12 access phase: 12
2023/06/19 13:48:54 [debug] 302#0: *12 post access phase: 13
2023/06/19 13:48:54 [debug] 302#0: *12 generic phase: 14
2023/06/19 13:48:54 [debug] 302#0: *12 generic phase: 15
2023/06/19 13:48:54 [debug] 302#0: *12 proxy_connect: connect handler: parse url: dl.boxcloud.com
2023/06/19 13:48:54 [debug] 302#0: *12 http finalize request: -4, "?" a:1, c:2
2023/06/19 13:48:54 [debug] 302#0: *12 http request count:2 blk:0
2023/06/19 13:48:54 [debug] 302#0: *12 proxy_connect: resolve handler
2023/06/19 13:48:54 [debug] 302#0: *12 proxy_connect: name was resolved to 74.112.186.128
2023/06/19 13:48:54 [debug] 302#0: *12 stream socket 18
2023/06/19 13:48:54 [debug] 302#0: *12 epoll add connection: fd:18 ev:80002005
2023/06/19 13:48:54 [debug] 302#0: *12 connect to 74.112.186.128:443, fd:18 #13
2023/06/19 13:48:54 [debug] 302#0: *12 proxy_connect: ngx_event_connect_peer() returns -2
2023/06/19 13:48:54 [debug] 302#0: *12 posix_memalign: 0000564E54673820:128 @16
2023/06/19 13:48:54 [debug] 302#0: *12 event timer add: 18: 10000:1571569
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: upstream handler: "dl.boxcloud.com:443"
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: upstream write handler (connect)
2023/06/19 13:48:55 [debug] 302#0: *12 event timer del: 18: 1571569
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: send 200 connection established
2023/06/19 13:48:55 [debug] 302#0: *12 SSL to write: 59
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_write: 59
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: sent 200 connection established
2023/06/19 13:48:55 [debug] 302#0: *12 http run request: "?"
2023/06/19 13:48:55 [debug] 302#0: *12 proxy connect read downstream
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: tunnel fu:0 write:0
2023/06/19 13:48:55 [debug] 302#0: *12 malloc: 0000564E545BBC40:16384
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_read: 517
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_read: -1
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_get_error: 2
2023/06/19 13:48:55 [debug] 302#0: *12 send: fd:18 517 of 517
2023/06/19 13:48:55 [debug] 302#0: *12 event timer add: 3: 120000:1681670
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: upstream handler: "dl.boxcloud.com:443"
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: upstream read handler
2023/06/19 13:48:55 [debug] 302#0: *12 malloc: 0000564E546D71E0:16384
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: tunnel fu:1 write:0
2023/06/19 13:48:55 [debug] 302#0: *12 recv: eof:0, avail:-1
2023/06/19 13:48:55 [debug] 302#0: *12 recv: fd:18 2048 of 16384
2023/06/19 13:48:55 [debug] 302#0: *12 SSL to write: 2048
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_write: 2048
2023/06/19 13:48:55 [debug] 302#0: *12 event timer: 3, old: 1681670, new: 1681794
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: upstream handler: "dl.boxcloud.com:443"
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: upstream write handler
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: tunnel fu:0 write:1
2023/06/19 13:48:55 [debug] 302#0: *12 event timer: 3, old: 1681670, new: 1681794
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: upstream handler: "dl.boxcloud.com:443"
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: upstream read handler
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: tunnel fu:1 write:0
2023/06/19 13:48:55 [debug] 302#0: *12 recv: eof:0, avail:-1
2023/06/19 13:48:55 [debug] 302#0: *12 recv: fd:18 1401 of 16384
2023/06/19 13:48:55 [debug] 302#0: *12 SSL to write: 1401
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_write: 1401
2023/06/19 13:48:55 [debug] 302#0: *12 event timer: 3, old: 1681670, new: 1681796
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: upstream handler: "dl.boxcloud.com:443"
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: upstream write handler
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: tunnel fu:0 write:1
2023/06/19 13:48:55 [debug] 302#0: *12 event timer: 3, old: 1681670, new: 1681796
2023/06/19 13:48:55 [debug] 302#0: *12 http run request: "?"
2023/06/19 13:48:55 [debug] 302#0: *12 proxy connect read downstream
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: tunnel fu:0 write:0
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_read: 80
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_read: 46
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_read: -1
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_get_error: 2
2023/06/19 13:48:55 [debug] 302#0: *12 send: fd:18 126 of 126
2023/06/19 13:48:55 [debug] 302#0: *12 event timer: 3, old: 1681670, new: 1681796
2023/06/19 13:48:55 [debug] 302#0: *12 http run request: "?"
2023/06/19 13:48:55 [debug] 302#0: *12 proxy connect read downstream
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: tunnel fu:0 write:0
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_read: 49
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_read: 35
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_read: -1
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_get_error: 2
2023/06/19 13:48:55 [debug] 302#0: *12 send: fd:18 84 of 84
2023/06/19 13:48:55 [debug] 302#0: *12 event timer: 3, old: 1681670, new: 1681796
2023/06/19 13:48:55 [debug] 302#0: *12 http run request: "?"
2023/06/19 13:48:55 [debug] 302#0: *12 proxy connect read downstream
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: tunnel fu:0 write:0
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_read: 81
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_read: -1
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_get_error: 2
2023/06/19 13:48:55 [debug] 302#0: *12 send: fd:18 81 of 81
2023/06/19 13:48:55 [debug] 302#0: *12 event timer: 3, old: 1681670, new: 1681796
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: upstream handler: "dl.boxcloud.com:443"
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: upstream read handler
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: tunnel fu:1 write:0
2023/06/19 13:48:55 [debug] 302#0: *12 recv: eof:0, avail:-1
2023/06/19 13:48:55 [debug] 302#0: *12 recv: fd:18 586 of 16384
2023/06/19 13:48:55 [debug] 302#0: *12 SSL to write: 586
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_write: 586
2023/06/19 13:48:55 [debug] 302#0: *12 event timer: 3, old: 1681670, new: 1681906
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: upstream handler: "dl.boxcloud.com:443"
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: upstream write handler
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: tunnel fu:0 write:1
2023/06/19 13:48:55 [debug] 302#0: *12 event timer: 3, old: 1681670, new: 1681906
2023/06/19 13:48:55 [debug] 302#0: *12 http run request: "?"
2023/06/19 13:48:55 [debug] 302#0: *12 proxy connect read downstream
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: tunnel fu:0 write:0
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_read: 31
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_read: -1
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_get_error: 2
2023/06/19 13:48:55 [debug] 302#0: *12 send: fd:18 31 of 31
2023/06/19 13:48:55 [debug] 302#0: *12 event timer: 3, old: 1681670, new: 1681907
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: upstream handler: "dl.boxcloud.com:443"
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: upstream read handler
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: tunnel fu:1 write:0
2023/06/19 13:48:55 [debug] 302#0: *12 recv: eof:0, avail:-1
2023/06/19 13:48:55 [debug] 302#0: *12 recv: fd:18 31 of 16384
2023/06/19 13:48:55 [debug] 302#0: *12 SSL to write: 31
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_write: 31
2023/06/19 13:48:55 [debug] 302#0: *12 event timer del: 3: 1681670
2023/06/19 13:48:55 [debug] 302#0: *12 event timer add: 3: 120000:1682008
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: upstream handler: "dl.boxcloud.com:443"
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: upstream write handler
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: tunnel fu:0 write:1
2023/06/19 13:48:55 [debug] 302#0: *12 event timer: 3, old: 1682008, new: 1682008
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: upstream handler: "dl.boxcloud.com:443"
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: upstream read handler
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: tunnel fu:1 write:0
2023/06/19 13:48:55 [debug] 302#0: *12 recv: eof:0, avail:-1
2023/06/19 13:48:55 [debug] 302#0: *12 recv: fd:18 239 of 16384
2023/06/19 13:48:55 [debug] 302#0: *12 SSL to write: 239
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_write: 239
2023/06/19 13:48:55 [debug] 302#0: *12 event timer: 3, old: 1682008, new: 1682149
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: upstream handler: "dl.boxcloud.com:443"
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: upstream write handler
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: tunnel fu:0 write:1
2023/06/19 13:48:55 [debug] 302#0: *12 event timer: 3, old: 1682008, new: 1682149
2023/06/19 13:48:55 [debug] 302#0: *12 http run request: "?"
2023/06/19 13:48:55 [debug] 302#0: *12 proxy connect read downstream
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: tunnel fu:0 write:0
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_read: 39
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_read: -1
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_get_error: 2
2023/06/19 13:48:55 [debug] 302#0: *12 send: fd:18 39 of 39
2023/06/19 13:48:55 [debug] 302#0: *12 event timer: 3, old: 1682008, new: 1682149
2023/06/19 13:48:55 [debug] 302#0: *12 http run request: "?"
2023/06/19 13:48:55 [debug] 302#0: *12 proxy connect read downstream
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: tunnel fu:0 write:0
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_read: 24
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_read: 0
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_get_error: 6
2023/06/19 13:48:55 [debug] 302#0: *12 peer shutdown SSL cleanly
2023/06/19 13:48:55 [debug] 302#0: *12 send: fd:18 24 of 24
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: tunnel done
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: finalize upstream request: 0
2023/06/19 13:48:55 [debug] 302#0: *12 proxy_connect: close upstream connection: 18
2023/06/19 13:48:55 [debug] 302#0: *12 free: 0000564E54673820, unused: 48
2023/06/19 13:48:55 [debug] 302#0: *12 reusable connection: 0
2023/06/19 13:48:55 [debug] 302#0: *12 http finalize request: 0, "?" a:1, c:1
2023/06/19 13:48:55 [debug] 302#0: *12 event timer del: 3: 1682008
2023/06/19 13:48:55 [debug] 302#0: *12 http request count:1 blk:0
2023/06/19 13:48:55 [debug] 302#0: *12 http close request
2023/06/19 13:48:55 [debug] 302#0: *12 http log handler
2023/06/19 13:48:55 [debug] 302#0: *12 free: 0000564E546D71E0
2023/06/19 13:48:55 [debug] 302#0: *12 free: 0000564E545BBC40
2023/06/19 13:48:55 [debug] 302#0: *12 free: 0000564E5462C6B0, unused: 128
2023/06/19 13:48:55 [debug] 302#0: *12 free: 0000564E545B2A50, unused: 2438
2023/06/19 13:48:55 [debug] 302#0: *12 close http connection: 3
2023/06/19 13:48:55 [debug] 302#0: *12 SSL_shutdown: 1
2023/06/19 13:48:55 [debug] 302#0: *12 reusable connection: 0
2023/06/19 13:48:55 [debug] 302#0: *12 free: 0000564E5459BF90
2023/06/19 13:48:55 [debug] 302#0: *12 free: 0000564E54631F50, unused: 40
chobits commented 1 year ago

2023/06/18 13:40:21 [debug] 25#25: posix_memalign: 00007FF90FC3AAA0:512 @16 2023/06/18 13:40:21 [debug] 25#25: 5 accept: 172.18.29.108:43562 fd:27 2023/06/18 13:40:21 [debug] 25#25: 5 event timer add: 27: 60000:8224156758 2023/06/18 13:40:21 [debug] 25#25: 5 reusable connection: 1 2023/06/18 13:40:21 [debug] 25#25: 5 epoll add event: fd:27 op:1 ev:80002001 2023/06/18 13:40:21 [debug] 25#25: epoll del event: fd:7 op:2 ev:00000000 2023/06/18 13:40:21 [debug] 25#25: epoll add event: fd:7 op:1 ev:10000001 2023/06/18 13:40:21 [debug] 25#25: timer delta: 1380915 2023/06/18 13:40:21 [debug] 25#25: worker cycle 2023/06/18 13:40:21 [debug] 25#25: epoll timer: 60000 2023/06/18 13:40:21 [debug] 25#25: epoll: fd:27 ev:0001 d:00007FF90BB5A6D8 2023/06/18 13:40:21 [debug] 25#25: 5 http check ssl handshake 2023/06/18 13:40:21 [debug] 25#25: 5 http recv(): 1 2023/06/18 13:40:21 [debug] 25#25: 5 https ssl handshake: 0x16 2023/06/18 13:40:21 [debug] 25#25: 5 tcp_nodelay 2023/06/18 13:40:21 [debug] 25#25: 5 reusable connection: 0 2023/06/18 13:40:21 [debug] 25#25: 5 SSL server name: null 2023/06/18 13:40:21 [debug] 25#25: 5 SSL ALPN supported by client: http/1.1 2023/06/18 13:40:21 [debug] 25#25: 5 SSL ALPN selected: http/1.1 2023/06/18 13:40:21 [debug] 25#25: 5 SSL_do_handshake: -1 2023/06/18 13:40:21 [debug] 25#25: 5 SSL_get_error: 2 2023/06/18 13:40:21 [debug] 25#25: timer delta: 6 2023/06/18 13:40:21 [debug] 25#25: worker cycle 2023/06/18 13:40:21 [debug] 25#25: epoll timer: 59994 2023/06/18 13:40:21 [debug] 25#25: epoll: fd:27 ev:0001 d:00007FF90BB5A6D8 2023/06/18 13:40:21 [debug] 25#25: 5 SSL handshake handler: 0 2023/06/18 13:40:21 [debug] 25#25: 5 SSL_do_handshake: 1 2023/06/18 13:40:21 [debug] 25#25: 5 SSL: TLSv1.3, cipher: "TLS_AES_256_GCM_SHA384 TLSv1.3 Kx=any Au=any Enc=AESGCM(256) Mac=AEAD" 2023/06/18 13:40:21 [debug] 25#25: 5 reusable connection: 1 2023/06/18 13:40:21 [debug] 25#25: 5 http wait request handler 2023/06/18 13:40:21 [debug] 25#25: 5 malloc: 00007FF90FC31DA0:1024 2023/06/18 13:40:21 [debug] 25#25: 5 SSL_read: 122 2023/06/18 13:40:21 [debug] 25#25: 5 SSL_read: -1 2023/06/18 13:40:21 [debug] 25#25: 5 SSL_get_error: 2 2023/06/18 13:40:21 [debug] 25#25: 5 reusable connection: 0 2023/06/18 13:40:21 [debug] 25#25: 5 posix_memalign: 00007FF90FCB7350:4096 @16 2023/06/18 13:40:21 [debug] 25#25: 5 http process request line 2023/06/18 13:40:21 [info] 25#25: 5 client sent invalid request while reading client request line, client: 172.18.29.108, server: dl.boxcloud.com, request: "CONNECT dl.boxcloud.com:443 HTTP/1.1" 2023/06/18 13:40:21 [debug] 25#25: 5 http finalize request: 400, "?" a:1, c:1 2023/06/18 13:40:21 [debug] 25#25: 5 event timer del: 27: 8224156758 2023/06/18 13:40:21 [debug] 25#25: 5 http special response: 400, "?" 2023/06/18 13:40:21 [debug] 25#25: 5 http set discard body 2023/06/18 13:40:21 [debug] 25#25: 5 HTTP/1.1 400 Bad Request Server: nginx/1.25.0 Date: Sun, 18 Jun 2023 13:40:21 GMT Content-Type: text/html Content-Length: 157 Connection: close

2023/06/18 13:40:21 [debug] 25#25: 5 write new buf t:1 f:0 00007FF90FCB81E8, pos 00007FF90FCB81E8, size: 152 file: 0, size: 0 2023/06/18 13:40:21 [debug] 25#25: 5 http write filter: l:0 f:0 s:152 2023/06/18 13:40:21 [debug] 25#25: 5 http output filter "?" 2023/06/18 13:40:21 [debug] 25#25: 5 http copy filter: "?" 2023/06/18 13:40:21 [debug] 25#25: 5 posix_memalign: 00007FF90FCB84D0:4096 @16 2023/06/18 13:40:21 [debug] 25#25: 5 http postpone filter "?" 00007FF90FCB8570 2023/06/18 13:40:21 [debug] 25#25: 5 write old buf t:1 f:0 00007FF90FCB81E8, pos 00007FF90FCB81E8, size: 152 file: 0, size: 0 2023/06/18 13:40:21 [debug] 25#25: 5 write new buf t:0 f:0 0000000000000000, pos 0000558BC2BB2F00, size: 104 file: 0, size: 0 2023/06/18 13:40:21 [debug] 25#25: 5 write new buf t:0 f:0 0000000000000000, pos 0000558BC2BB3460, size: 53 file: 0, size: 0 2023/06/18 13:40:21 [debug] 25#25: 5 http write filter: l:1 f:0 s:309 2023/06/18 13:40:21 [debug] 25#25: 5 http write filter limit 2097152 2023/06/18 13:40:21 [debug] 25#25: 5 posix_memalign: 00007FF90FD474B0:512 @16 2023/06/18 13:40:21 [debug] 25#25: 5 malloc: 00007FF90FBEAE70:16384 2023/06/18 13:40:21 [debug] 25#25: 5 SSL buf copy: 152 2023/06/18 13:40:21 [debug] 25#25: 5 SSL buf copy: 104 2023/06/18 13:40:21 [debug] 25#25: 5 SSL buf copy: 53 2023/06/18 13:40:21 [debug] 25#25: 5 SSL to write: 309 2023/06/18 13:40:21 [debug] 25#25: 5 SSL_write: 309 2023/06/18 13:40:21 [debug] 25#25: 5 http write filter 0000000000000000 2023/06/18 13:40:21 [debug] 25#25: 5 http copy filter: 0 "?" 2023/06/18 13:40:21 [debug] 25#25: 5 http finalize request: 0, "?" a:1, c:1 2023/06/18 13:40:21 [debug] 25#25: 5 SSL_shutdown: 1 2023/06/18 13:40:21 [debug] 25#25: 5 reusable connection: 1 2023/06/18 13:40:21 [debug] 25#25: 5 event timer add: 27: 5000:8224101766 2023/06/18 13:40:21 [debug] 25#25: timer delta: 2 2023/06/18 13:40:21 [debug] 25#25: worker cycle 2023/06/18 13:40:21 [debug] 25#25: epoll timer: 5000 172.18.29.108 - - [18/Jun/2023:13:40:21 +0000] "CONNECT dl.boxcloud.com:443 HTTP/1.1" 400 157 "-" "-" 0.001 - . 2023/06/18 13:40:21 [debug] 25#25: epoll: fd:27 ev:2019 d:00007FF90BB5A6D8 2023/06/18 13:40:21 [debug] 25#25: epoll_wait() error on fd:27 ev:2019 2023/06/18 13:40:21 [debug] 25#25: 5 http lingering close handler 2023/06/18 13:40:21 [debug] 25#25: 5 recv: eof:1, avail:-1 2023/06/18 13:40:21 [debug] 25#25: 5 recv: fd:27 -1 of 4096 2023/06/18 13:40:21 [info] 25#25: 5 recv() failed (104: Connection reset by peer) while reading client request line, client: 172.18.29.108, server: dl.boxcloud.com, request: "CONNECT dl.boxcloud.com:443 HTTP/1.1" 2023/06/18 13:40:21 [debug] 25#25: 5 lingering read: -1 2023/06/18 13:40:21 [debug] 25#25: 5 http request count:1 blk:0 2023/06/18 13:40:21 [debug] 25#25: 5 http close request 2023/06/18 13:40:21 [debug] 25#25: 5 http log handler 2023/06/18 13:40:21 [debug] 25#25: 5 free: 00007FF90FCB7350, unused: 8 2023/06/18 13:40:21 [debug] 25#25: 5 free: 00007FF90FCB84D0, unused: 3707 2023/06/18 13:40:21 [debug] 25#25: 5 close http connection: 27 2023/06/18 13:40:21 [debug] 25#25: 5 SSL_shutdown: 1 2023/06/18 13:40:21 [debug] 25#25: 5 event timer del: 27: 8224101766 2023/06/18 13:40:21 [debug] 25#25: 5 reusable connection: 0 2023/06/18 13:40:21 [debug] 25#25: 5 free: 00007FF90FBEAE70 2023/06/18 13:40:21 [debug] 25#25: 5 free: 00007FF90FC31DA0 2023/06/18 13:40:21 [debug] 25#25: 5 free: 00007FF90FC3AAA0, unused: 16 2023/06/18 13:40:21 [debug] 25#25: 5 free: 00007FF90FD474B0, unused: 400 2023/06/18 13:40:21 [debug] 25#25: timer delta: 1 2023/06/18 13:40:21 [debug] 25#25: worker cycle 2023/06/18 13:40:21 [debug] 25#25: epoll timer: -1 2023/06/18 13:40:21 [debug] 36#36: timer delta: 10010 2023/06/18 13:40:21 [debug] 36#36: event timer del: -1: 8224097203 2023/06/18 13:40:21 [debug] 36#36: http file cache expire 2023/06/18 13:40:21 [debug] 36#36: malloc: 00007FF90FC398B0:55

400 bad request means that proxy_connect is not built into nginx or not enabled.

chobits commented 1 year ago

Looks like there is an issue in resolving the dns 2023/06/18 13:53:24 [debug] 30#30: resolver DNS response 4009 fl:8180 1/1/0/0 2023/06/18 13:53:24 [debug] 30#30: resolver DNS response qt:1 cl:1 2023/06/18 13:53:24 [debug] 30#30: malloc: 00007FF90FC46840:16 2023/06/18 13:53:24 [debug] 30#30: resolver qs:dl.boxcloud.com 2023/06/18 13:53:24 [debug] 30#30: resolver naddrs:1 cname:0000000000000000 ttl:60 2023/06/18 13:53:24 [debug] 30#30: 10 http upstream resolve: "/d/1/21bytes.txt/download?" 2023/06/18 13:53:24 [debug] 30#30: 10 name was resolved to 74.112.186.128 2023/06/18 13:53:24 [debug] 30#30: 10 posix_memalign: 00007FF90FCB9740:4096 @16 2023/06/18 13:53:24 [debug] 30#30: resolve name done: 0 2023/06/18 13:53:24 [debug] 30#30: event timer del: -1: 8224909878 2023/06/18 13:53:24 [debug] 30#30: resolver expire 2023/06/18 13:53:24 [debug] 30#30: event timer del: -1: 8224884878 2023/06/18 13:53:24 [debug] 30#30: 10 get rr peer, try: 1 2023/06/18 13:53:24 [debug] 30#30: 10 stream socket 24 2023/06/18 13:53:24 [debug] 30#30: 10 epoll add connection: fd:24 ev:80002005 2023/06/18 13:53:24 [debug] 30#30: 10 connect to 74.112.186.128:80, fd:24 #12 2023/06/18 13:53:24 [debug] 30#30: 10 http upstream connect: -2 2023/06/18 13:53:24 [debug] 30#30: 10 posix_memalign: 00007FF90FC35C70:128 @16 2023/06/18 13:53:24 [debug] 30#30: 10 event timer add: 24: 60000:8224939891 2023/06/18 13:53:24 [debug] 30#30: recv: fd:22 -1 of 4096 2023/06/18 13:53:24 [debug] 30#30: recv() not ready (11: Resource temporarily unavailable)

dns worked and it had gotten backend record: name was resolved to 74.112.186.128, but this request did not run proxy_connect module, the request worked under normal http upstream module. The log message ... get rr peer, try:... indicates that the request was passed to the normal upstream round robin module. (Requests handled by the proxy_connect module will not execute this logic.)

ns-aparnau commented 1 year ago

Okay, then what am I missing here - i did see some documentation which suggested that resolver would be used with dynamic host - so i updated my config as below -

 location ~ ^/d/1/[0-9a-z]+/download$ {
    resolver 192.168.80.12;
    set $upstream_endpoint http://har_box_fs_1:8080;
    proxy_pass $upstream_endpoint;
    proxy_next_upstream error timeout invalid_header http_500 http_502 http_503 http_504;
  }

location / {
    resolver 192.168.80.12;
    set $upstream_endpoint http://har_box_fs_1:8080;
    proxy_pass $upstream_endpoint;
   .....
}

But this also results in same error -502 

`curl -x https://172.18.29.108:443 https://dl.boxcloud.com/d/1/21bytes.txt/download -v --proxy-insecure -I`

 ``2023/06/19 05:57:36 [error] 20#20: *1 proxy_connect: no resolver defined to resolve dl.boxcloud.com, client: 172.18.29.108, server: dl.boxcloud.com, request: "CONNECT dl.boxcloud.com:443 `HTTP/1.1", host: "dl.boxcloud.com:443"`

looks like proxy_connect is not working as expected -
ns-aparnau commented 1 year ago

dns is resolving incorrectly - 74.112.186.128 is actual box dns and not the mocker i am running as my docker container in my vm... resolver should resolve to 192.168.80.12 - which is the ip of har_box_fs_1 - when i curl the same from inside nginx - it works as expected- but not from proxy

/usr/src/app # curl http://har_box_fs_1:8080/d/1/21bytes.txt/download;
This is a test file
chobits commented 1 year ago

Okay, then what am I missing here - i did see some documentation which suggested that resolver would be used with dynamic host - so i updated my config as below -

 location ~ ^/d/1/[0-9a-z]+/download$ {
    resolver 192.168.80.12;
    set $upstream_endpoint http://har_box_fs_1:8080;
    proxy_pass $upstream_endpoint;
    proxy_next_upstream error timeout invalid_header http_500 http_502 http_503 http_504;
  }

location / {
    resolver 192.168.80.12;
    set $upstream_endpoint http://har_box_fs_1:8080;
    proxy_pass $upstream_endpoint;
   .....
}

But this also results in same error -502 

`curl -x https://172.18.29.108:443 https://dl.boxcloud.com/d/1/21bytes.txt/download -v --proxy-insecure -I`

 ``2023/06/19 05:57:36 [error] 20#20: *1 proxy_connect: no resolver defined to resolve dl.boxcloud.com, client: 172.18.29.108, server: dl.boxcloud.com, request: "CONNECT dl.boxcloud.com:443 `HTTP/1.1", host: "dl.boxcloud.com:443"`

looks like proxy_connect is not working as expected -

Hi, this modification does not work for proxy_connect, so ensure that you fully follow the instance configuration in our documentation!!!

  1. pls configure resolver directive globally in server {}/http {} block
  2. any location {} block , upstream {} block, proxy_pass directive and any other backend/upstream directives do not impact the functionality of the proxy_connect module. This is because the proxy_connect module only executes the logic for requests that use the CONNECT method and that have a data flow under this tunnel.
    • if your requests are not handled outside of the CONNECT tunnel, you can remove any location {} or upstream {} block, as these directives do not affect proxy_connect module.
ns-aparnau commented 1 year ago

Okay - let me try updating the configs again with global reference for resolver

chobits commented 1 year ago

dns is resolving incorrectly - 74.112.186.128 is actual box dns and not the mocker i am running as my docker container in my vm... resolver should resolve to 192.168.80.12 - which is the ip of har_box_fs_1 - when i curl the same from inside nginx - it works as expected- but not from proxy

/usr/src/app # curl http://har_box_fs_1:8080/d/1/21bytes.txt/download;
This is a test file

For normal requests not over CONNECT tunnel as they are not handled by the proxy_connect module (maybe handled by location {} block), you may need to refer to nginx official manual and debug.

For the CONNECT request and the data flow handled by proxy_connect module, the backend server address will be resolved from the DNS server specified by global directive resolver. This resolved address will be used for the entire CONNECT tunnel, until the tunnel is closed.

ns-aparnau commented 1 year ago

After updating few configs - curl -x https://192.168.80.20:443 http://dl.boxcloud.com/d/1/21bytes.txt/download --trace-ascii debugdump.txt --proxy-insecure This is a test file

curl -x https://192.168.80.20:443 https://dl.boxcloud.com/d/1/21bytes.txt/download --trace-ascii debugdump.txt --proxy-insecure curl: (56) Received HTTP code 405 from proxy after CONNECT => Send header, 122 bytes (0x7a)

0000: CONNECT dl.boxcloud.com:443 HTTP/1.1
0026: Host: dl.boxcloud.com:443
0041: User-Agent: curl/7.68.0
005a: Proxy-Connection: Keep-Alive
0078:
<= Recv SSL data, 5 bytes (0x5)
0000: ....R
<= Recv header, 26 bytes (0x1a)
0000: HTTP/1.1 405 Not Allowed
<= Recv header, 22 bytes (0x16)
0000: Server: nginx/1.25.0
<= Recv header, 37 bytes (0x25)
0000: Date: Mon, 19 Jun 2023 10:31:03 GMT
<= Recv header, 25 bytes (0x19)
0000: Content-Type: text/html
<= Recv header, 21 bytes (0x15)
0000: Content-Length: 157
<= Recv header, 24 bytes (0x18)
0000: Connection: keep-alive
<= Recv header, 2 bytes (0x2)
0000:
== Info: Received HTTP code 405 from proxy after CONNECT
== Info: CONNECT phase completed!
== Info: Closing connection 0
=> Send SSL data, 5 bytes (0x5)
0000: .....

using https in curl request with server name gives below error - Received HTTP code 405 from proxy after CONNECT

On further checking , OpenSSL/3.0.9: error:0A00010B:SSL routines::wrong version number

ns-aparnau commented 1 year ago

Followed same configs like you suggested - but it is failing to establish the connect itself ---

  server {
        listen 443 ssl;

        ssl_certificate_key /etc/nginx/certs/box/box.key;
        ssl_certificate     /etc/nginx/certs/box/box.pem;
        ssl_session_cache shared:SSL:1m;

        error_log  /etc/nginx/err_8888.log debug;

        resolver a.b.c.d ipv6=off;

        proxy_connect;
        proxy_connect_allow all;
        proxy_connect_connect_timeout 10s;
        proxy_connect_data_timeout 120s;

        location / {
            proxy_pass http://$host;
            proxy_set_header Host $host;
        }
    }

curl -x https://172.18.29.108:443 https://dl.boxcloud.com/d/1/21bytes.txt/download --proxy-insecure -v

*  ```
 Trying a.b.c.d:443...
* TCP_NODELAY set
* Connected to a.b.c.d (a.b.c.d) port 443 (#0)
* ALPN, offering http/1.1
* successfully set certificate verify locations:
*   CAfile: /etc/ssl/certs/ca-certificates.crt
  CApath: /etc/ssl/certs
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
* TLSv1.3 (IN), TLS handshake, Server hello (2):
* TLSv1.2 (IN), TLS handshake, Certificate (11):
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
* TLSv1.2 (IN), TLS handshake, Server finished (14):
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
* TLSv1.2 (OUT), TLS change cipher, Change cipher spec (1):
* TLSv1.2 (OUT), TLS handshake, Finished (20):
* TLSv1.2 (IN), TLS handshake, Finished (20):
* SSL connection using TLSv1.2 / ECDHE-RSA-AES256-GCM-SHA384
* ALPN, server accepted to use http/1.1
* Proxy certificate:
*  subject: C=US; ST=California; L=Palo Alto; O=nete Inc; CN=box.com; emailAddress=aparna@nete.com
*  start date: May 30 05:00:58 2023 GMT
*  expire date: May 28 05:00:58 2028 GMT
*  issuer: C=US; ST=California; L=Palo Alto; O=nete Inc; CN=box.com; emailAddress=aparna@nete.com
*  SSL certificate verify ok.
* allocate connect buffer!
* Establish HTTP proxy tunnel to dl.boxcloud.com:443
> CONNECT dl.boxcloud.com:443 HTTP/1.1
> Host: dl.boxcloud.com:443
> User-Agent: curl/7.68.0
> Proxy-Connection: Keep-Alive
>
< HTTP/1.1 405 Not Allowed
< Server: nginx/1.25.0
< Date: Mon, 19 Jun 2023 10:55:54 GMT
< Content-Type: text/html
< Content-Length: 157
< Connection: keep-alive
<
* Received HTTP code 405 from proxy after CONNECT
* CONNECT phase completed!
* Closing connection 0
curl: (56) Received HTTP code 405 from proxy after CONNECT
chobits commented 1 year ago

Followed same configs like you suggested - but it is failing to establish the connect itself ---

 server {
       listen 443 ssl;

       ssl_certificate_key /etc/nginx/certs/box/box.key;
       ssl_certificate     /etc/nginx/certs/box/box.pem;
       ssl_session_cache shared:SSL:1m;

       error_log  /etc/nginx/err_8888.log debug;

       resolver 192.168.80.1 ipv6=off;

       proxy_connect;
       proxy_connect_allow all;
       proxy_connect_connect_timeout 10s;
       proxy_connect_data_timeout 120s;

       location / {
           proxy_pass http://$host;
           proxy_set_header Host $host;
       }
   }

curl -x https://172.18.29.108:443 https://dl.boxcloud.com/d/1/21bytes.txt/download --proxy-insecure -v

*  ```
 Trying 172.18.29.108:443...
* TCP_NODELAY set
* Connected to 172.18.29.108 (172.18.29.108) port 443 (#0)
* ALPN, offering http/1.1
* successfully set certificate verify locations:
*   CAfile: /etc/ssl/certs/ca-certificates.crt
  CApath: /etc/ssl/certs
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
* TLSv1.3 (IN), TLS handshake, Server hello (2):
* TLSv1.2 (IN), TLS handshake, Certificate (11):
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
* TLSv1.2 (IN), TLS handshake, Server finished (14):
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
* TLSv1.2 (OUT), TLS change cipher, Change cipher spec (1):
* TLSv1.2 (OUT), TLS handshake, Finished (20):
* TLSv1.2 (IN), TLS handshake, Finished (20):
* SSL connection using TLSv1.2 / ECDHE-RSA-AES256-GCM-SHA384
* ALPN, server accepted to use http/1.1
* Proxy certificate:
*  subject: C=US; ST=California; L=Palo Alto; O=nete Inc; CN=box.com; emailAddress=aparna@nete.com
*  start date: May 30 05:00:58 2023 GMT
*  expire date: May 28 05:00:58 2028 GMT
*  issuer: C=US; ST=California; L=Palo Alto; O=nete Inc; CN=box.com; emailAddress=aparna@nete.com
*  SSL certificate verify ok.
* allocate connect buffer!
* Establish HTTP proxy tunnel to dl.boxcloud.com:443
> CONNECT dl.boxcloud.com:443 HTTP/1.1
> Host: dl.boxcloud.com:443
> User-Agent: curl/7.68.0
> Proxy-Connection: Keep-Alive
>
< HTTP/1.1 405 Not Allowed
< Server: nginx/1.25.0
< Date: Mon, 19 Jun 2023 10:55:54 GMT
< Content-Type: text/html
< Content-Length: 157
< Connection: keep-alive
<
* Received HTTP code 405 from proxy after CONNECT
* CONNECT phase completed!
* Closing connection 0
curl: (56) Received HTTP code 405 from proxy after CONNECT

I still haven't been able to reproduce the issue as I tested this command and configuration in Nginx version 1.25.0, and I received a 400 error response from the backend server at dl.boxcloud.com. The CONNECT tunnel has been established, and the backend server returned a 400 error. Maybe you need to seek help from a nginx specialist who can access to your development environment.

chobits commented 1 year ago

i found you configure /etc/nginx/err_8888.log, you can show the request debug log of your curl command.

Note that the debug log from your above comment is not for proxy_connect request, which cannot help us to debug

ns-aparnau commented 1 year ago

I reloaded the nginx - please find the logs from err_8888.log 2023/06/19 14:10:16 [error] 21#21: *1 proxy_connect: dl.boxcloud.com could not be resolved (110: Operation timed out), client: 172.18.29.108, server: , request: "CONNECT dl.boxcloud.com:443 HTTP/1.1", host: "dl.boxcloud.com:443" And these are docker logs -

2023/06/19 14:09:46 [error] 21#21: recv() failed (111: Connection refused) while resolving, resolver: 192.168.80.1:53
2023/06/19 14:09:51 [error] 21#21: recv() failed (111: Connection refused) while resolving, resolver: 192.168.80.1:53
2023/06/19 14:09:56 [error] 21#21: recv() failed (111: Connection refused) while resolving, resolver: 192.168.80.1:53
2023/06/19 14:10:01 [error] 21#21: recv() failed (111: Connection refused) while resolving, resolver: 192.168.80.1:53
2023/06/19 14:10:06 [error] 21#21: recv() failed (111: Connection refused) while resolving, resolver: 192.168.80.1:53
2023/06/19 14:10:11 [error] 21#21: recv() failed (111: Connection refused) while resolving, resolver: 192.168.80.1:53
172.18.29.108 - - [19/Jun/2023:14:10:16 +0000] "CONNECT dl.boxcloud.com:443 HTTP/1.1" 502 157 "-" "curl/7.68.0" 30.005 - .

I'll try to change it to hostname har_box_fs_1 and retry

ns-aparnau commented 1 year ago

Okay, with changed resolver - the ip is resolving correctly but still there is a connection refused error -

2023/06/19 15:19:25 [error] 21#21: recv() failed (111: Connection refused) while resolving, resolver: 192.168.80.2:8080
2023/06/19 15:19:30 [error] 21#21: recv() failed (111: Connection refused) while resolving, resolver: 192.168.80.2:8080
2023/06/19 15:19:35 [error] 21#21: recv() failed (111: Connection refused) while resolving, resolver: 192.168.80.2:8080
2023/06/19 15:19:40 [error] 21#21: recv() failed (111: Connection refused) while resolving, resolver: 192.168.80.2:8080
172.18.29.108 - - [19/Jun/2023:15:19:45 +0000] "CONNECT dl.boxcloud.com:443 HTTP/1.1" 502 157 "-" "curl/7.68.0" 30.006 - .

2023/06/19 15:19:45 [error] 21#21: *1 proxy_connect: dl.boxcloud.com could not be resolved (110: Operation timed out), client: 172.18.29.108, server: , request: "CONNECT dl.boxcloud.com:443 HTTP/1.1", host: "dl.boxcloud.com:443"

ns-aparnau commented 1 year ago

I tried with docker's dns as per resolv.conf file and the ip of the container of backend server - but in both cases, i am getting proxy_connect: dl.boxcloud.com could not be resolved (110: Operation timed out), client: 172.18.29.108, server: , request: "CONNECT dl.boxcloud.com:443 HTTP/1.1", host: "dl.boxcloud.com:443"

i refereed some existing documentation online and changed the timeout values but no luck.

ns-aparnau commented 1 year ago

If i use resolver as 127.0.0.11 - get 400 because request is incorrectly being routed to real dl.boxcloud.com instead of mocker server (har_box_fas_1)

If i use resolver as har_box_fas_1:8080 , proxy_connect is getting timed out as nginx complains connection refused while resolving resolver.

CONNECT is successful in both the cases now.

Can you please help me unblock this .

chobits commented 1 year ago

If i use resolver as 127.0.0.11 - get 400 because request is incorrectly being routed to real dl.boxcloud.com instead of mocker server (har_box_fas_1)

If i use resolver as har_box_fas_1:8080 , proxy_connect is getting timed out as nginx complains connection refused while resolving resolver.

CONNECT is successful in both the cases now.

Can you please help me unblock this .

Network environment issues are out of my hands .

But there is a method to forcefully specify the backend server address. Check this directive proxy_connect_address , see this configuration in our test cases. You can simply set it as an IP address if you already know the value of backend IP address.

image

ns-aparnau commented 1 year ago

Okay, let me check this..thanks

chobits commented 1 year ago

Okay, let me check this..thanks

try this: currently cannot use if-statement to control

server {
...
proxy_connect_address "xx.xx.xx.xx:443";
}
chobits commented 1 year ago

my fault, you can control the backend address via if-statement like following example:

server {
         .....
        set $proxy_remote_address "";
        proxy_connect_address $proxy_remote_address;
        if ($host = "xx.com") {
            set $proxy_remote_address "xx.xx.xx.xx:443";
        }
}
chobits commented 1 year ago

If i use resolver as 127.0.0.11 - get 400 because request is incorrectly being routed to real dl.boxcloud.com instead of mocker server (har_box_fas_1)

If i use resolver as har_box_fas_1:8080 , proxy_connect is getting timed out as nginx complains connection refused while resolving resolver.

CONNECT is successful in both the cases now.

Can you please help me unblock this .

maybe this file does not exist.

image

ns-aparnau commented 1 year ago

It does exist in the proxy server, but the problem is it is being routed to actual server instead of mocker and hence the 4XX

ns-aparnau commented 1 year ago

So basically here is the reason -

There is an error while resolving host by nginx- resolver is given as har_box_fs_1:8080 --> which is 192.168.80.3:8080 but when nginx is serving the request, it is trying to use 192.168.80.1 instead.

2023/06/20 11:05:10 [error] 23#23: recv() failed (111: Connection refused) while resolving, resolver: 192.168.80.3:8080

2023/06/20 11:05:15 [error] 23#23: *24 [dl.boxcloud.com](http://dl.boxcloud.com/) could not be resolved (110: Operation timed out), client: 192.168.80.1, server: , request: "GET /d/1/21bytes.txt/download HTTP/1.1", host: "[dl.boxcloud.com](http://dl.boxcloud.com/)"
curl http://192.168.80.3:8080/d/1/21bytes.txt/download
This is a test file
curl http://192.168.80.1/d/1/21bytes.txt/download
curl: (7) Failed to connect to 192.168.80.1 port 80 after 0 ms: Couldn't connect to server

Since it is not resolved correctly, there is a 502

ns-aparnau commented 1 year ago

Not sure why but I started getting 400 error again - The proxy_connect module is still there and I am calling the request as expected

curl -x https://172.18.29.108:443 https://dl.boxcloud.com/d/1/21bytes.txt/download --proxy-insecure
curl: (56) Received HTTP code 400 from proxy after CONNECT
chobits commented 1 year ago

Not sure why but I started getting 400 error again - The proxy_connect module is still there and I am calling the request as expected

curl -x https://172.18.29.108:443 https://dl.boxcloud.com/d/1/21bytes.txt/download --proxy-insecure
curl: (56) Received HTTP code 400 from proxy after CONNECT

400 means proxy_connect worked as expected, which is no longer relevant to this module.

So basically here is the reason -

There is an error while resolving host by nginx- resolver is given as har_box_fs_1:8080 --> which is 192.168.80.3:8080 but when nginx is serving the request, it is trying to use 192.168.80.1 instead.

2023/06/20 11:05:10 [error] 23#23: recv() failed (111: Connection refused) while resolving, resolver: 192.168.80.3:8080

2023/06/20 11:05:15 [error] 23#23: *24 [dl.boxcloud.com](http://dl.boxcloud.com/) could not be resolved (110: Operation timed out), client: 192.168.80.1, server: , request: "GET /d/1/21bytes.txt/download HTTP/1.1", host: "[dl.boxcloud.com](http://dl.boxcloud.com/)"
curl http://192.168.80.3:8080/d/1/21bytes.txt/download
This is a test file
curl http://192.168.80.1/d/1/21bytes.txt/download
curl: (7) Failed to connect to 192.168.80.1 port 80 after 0 ms: Couldn't connect to server

Since it is not resolved correctly, there is a 502

this is the problem associated with the resolver server problem or your network environment.

chobits commented 1 year ago

Not sure why but I started getting 400 error again - The proxy_connect module is still there and I am calling the request as expected

curl -x https://172.18.29.108:443 https://dl.boxcloud.com/d/1/21bytes.txt/download --proxy-insecure
curl: (56) Received HTTP code 400 from proxy after CONNECT

The proxy_conect module has worked as expect.

Without proxy_connect, requesting ur give url directly will get a 400 response from my private proxying server around the world.

ns-aparnau commented 1 year ago

Looks like CONNECT itself was not established - why am i getting this again-- i already resolved it by correcting my curl request..

curl -x a.b.c.d:443  https://dl.boxcloud.com/d/1/21bytes.txt/download -v
*   Trying a.b.c.d:443...
* TCP_NODELAY set
* Connected to a.b.c.d (a.b.c.d) port 443 (#0)
* allocate connect buffer!
* Establish HTTP proxy tunnel to dl.boxcloud.com:443
> CONNECT dl.boxcloud.com:443 HTTP/1.1
> Host: dl.boxcloud.com:443
> User-Agent: curl/7.68.0
> Proxy-Connection: Keep-Alive
>
< HTTP/1.1 400 Bad Request
< Server: nginx/1.25.0
< Date: Tue, 20 Jun 2023 12:59:10 GMT
< Content-Type: text/html
< Content-Length: 157
< Connection: close
<
* Received HTTP code 400 from proxy after CONNECT
* CONNECT phase completed!
* Closing connection 0
curl: (56) Received HTTP code 400 from proxy after CONNECT
ns-aparnau commented 1 year ago

So far no luck -I am checking with network team for this

ns-aparnau commented 1 year ago

I was able to resolve this eventually. There were some cert misconfigurations at client side that were fixed. CONNECT working as expected. Thanks for your prompt responses!
Cheers! :))