Skip to content

Instantly share code, notes, and snippets.

@btm

btm/gist:1330454

Created November 1, 2011 13:01
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save btm/1330454 to your computer and use it in GitHub Desktop.
Save btm/1330454 to your computer and use it in GitHub Desktop.
Download ZIP
nginx timeout (http 408) when sending unicode
Raw
gistfile1.txt
# You can see the 60 second timeout start at 12:44:24
#
# Log created with:
# nginx: nginx version: nginx/1.1.6
# nginx: built by gcc 4.4.3 (Ubuntu 4.4.3-4ubuntu5)
# nginx: TLS SNI support enabled
# nginx: configure arguments: --conf-path=/etc/nginx --prefix=/tmp/nginx-1.1.6 --with-http_ssl_module --with-http_stub_status_module --add-module=../nginx-x-rid-header --with-ld-opt=-luuid --with-debug
# Same results with:
# nginx: nginx version: nginx/1.1.6
# nginx: built by gcc 4.4.3 (Ubuntu 4.4.3-4ubuntu5)
# nginx: TLS SNI support enabled
# nginx: configure arguments: --conf-path=/etc/nginx --prefix=/tmp/nginx-1.1.6 --with-http_ssl_module --with-http_stub_status_module --with-debug
# Same results with:
# nginx: nginx version: nginx/1.0.5
# nginx: built by gcc 4.4.3 (Ubuntu 4.4.3-4ubuntu5)
# nginx: TLS SNI support enabled
# nginx: configure arguments: --conf-path=/etc/nginx --prefix=/srv/nginx/1.0.5 --with-http_ssl_module --with-http_stub_status_module --add-module=../nginx-x-rid-header --with-ld-opt=-luuid
2011/11/01 12:44:21 [debug] 13689#0: *129 accept: 66.231.201.193 fd:12
2011/11/01 12:44:21 [debug] 13689#0: *129 event timer add: 12: 60000:1596561647
2011/11/01 12:44:21 [debug] 13689#0: *129 epoll add event: fd:12 op:1 ev:80000001
2011/11/01 12:44:21 [debug] 13689#0: *129 malloc: 087A7568:660
2011/11/01 12:44:21 [debug] 13689#0: *129 malloc: 087071C0:1024
2011/11/01 12:44:21 [debug] 13689#0: *129 posix_memalign: 087A78F0:4096 @16
2011/11/01 12:44:21 [debug] 13689#0: *129 http check ssl handshake
2011/11/01 12:44:21 [debug] 13689#0: *129 https ssl handshake: 0x16
2011/11/01 12:44:21 [debug] 13689#0: *129 SSL_do_handshake: -1
2011/11/01 12:44:21 [debug] 13689#0: *129 SSL_get_error: 2
2011/11/01 12:44:22 [debug] 13689#0: *129 SSL handshake handler: 0
2011/11/01 12:44:22 [debug] 13689#0: *129 SSL_do_handshake: 1
2011/11/01 12:44:22 [debug] 13689#0: *129 SSL: TLSv1, cipher: "AES256-SHA SSLv3 Kx=RSA Au=RSA Enc=AES(256) Mac=SHA1"
2011/11/01 12:44:22 [debug] 13689#0: *129 http process request line
2011/11/01 12:44:22 [debug] 13689#0: *129 SSL_read: -1
2011/11/01 12:44:22 [debug] 13689#0: *129 SSL_get_error: 2
2011/11/01 12:44:23 [debug] 13689#0: *129 http process request line
2011/11/01 12:44:23 [debug] 13689#0: *129 SSL_read: 946
2011/11/01 12:44:23 [debug] 13689#0: *129 SSL_read: -1
2011/11/01 12:44:23 [debug] 13689#0: *129 SSL_get_error: 2
2011/11/01 12:44:23 [debug] 13689#0: *129 http request line: "PUT /organizations/opscode-btm/nodes/broken HTTP/1.1"
2011/11/01 12:44:23 [debug] 13689#0: *129 http uri: "/organizations/opscode-btm/nodes/broken"
2011/11/01 12:44:23 [debug] 13689#0: *129 http args: ""
2011/11/01 12:44:23 [debug] 13689#0: *129 http exten: ""
2011/11/01 12:44:23 [debug] 13689#0: *129 http process request header line
2011/11/01 12:44:23 [debug] 13689#0: *129 http header: "Accept: application/json"
2011/11/01 12:44:23 [debug] 13689#0: *129 http header: "Content-Type: application/json"
2011/11/01 12:44:23 [debug] 13689#0: *129 http header: "Content-Length: 16385"
2011/11/01 12:44:23 [debug] 13689#0: *129 http header: "X-Ops-Sign: version=1.0"
2011/11/01 12:44:23 [debug] 13689#0: *129 http header: "X-Ops-Userid: broken"
2011/11/01 12:44:23 [debug] 13689#0: *129 http header: "X-Ops-Timestamp: 2011-11-01T12:44:19Z"
2011/11/01 12:44:23 [debug] 13689#0: *129 http header: "X-Ops-Content-Hash: aqlM9xv0GoEGSgfZXP89Bc3nZC8="
2011/11/01 12:44:23 [debug] 13689#0: *129 http header: "X-Ops-Authorization-1: hjpcgOjt50E5jg1WHsV0TB1oGEZFkicw75wPDnO5OO5QoWgfVGHNRFyTGY4P"
2011/11/01 12:44:23 [debug] 13689#0: *129 http header: "X-Ops-Authorization-2: Uh0c+8OyWbeI3A5az4xo4NhzbOEs5Ha3sWTQPUt7gVvh00698m+siEVtrQrJ"
2011/11/01 12:44:23 [debug] 13689#0: *129 http header: "X-Ops-Authorization-3: IIJUVpwYLr2zRdYJB38ajJi55F4x8qyMVQWhetpaimYhZBjbeDa84aLB3LtL"
2011/11/01 12:44:23 [debug] 13689#0: *129 http header: "X-Ops-Authorization-4: N/zmRP/c/dZOnCnujVdGtIHF866L9UU3v8qe/FZ2SKwVnvxGjXFcIgOfiDOQ"
2011/11/01 12:44:23 [debug] 13689#0: *129 http header: "X-Ops-Authorization-5: sS1kmW1mzQXyNi47xYyxGxdg7bpIQv/8idQPHtVKbFqVw4jNteJZ+wx0/Mvs"
2011/11/01 12:44:23 [debug] 13689#0: *129 http header: "X-Ops-Authorization-6: NY60rcQDKgG9A10CkmX2sZOB9jcX/IGKuZaFmmCD/Q=="
2011/11/01 12:44:23 [debug] 13689#0: *129 http header: "Host: api-rs-preprod.opscode.com:443"
2011/11/01 12:44:23 [debug] 13689#0: *129 http header: "X-Chef-Version: 0.10.4"
2011/11/01 12:44:23 [debug] 13689#0: *129 http header: "User-Agent: Chef Client/0.10.4 (ruby-1.9.1-p431; ohai-0.6.10; x86_64-linux; +http://opscode.com)"
2011/11/01 12:44:23 [debug] 13689#0: *129 http header: "Connection: close"
2011/11/01 12:44:23 [debug] 13689#0: *129 http header done
2011/11/01 12:44:23 [debug] 13689#0: *129 event timer del: 12: 1596561647
2011/11/01 12:44:23 [debug] 13689#0: *129 rewrite phase: 0
2011/11/01 12:44:23 [debug] 13689#0: *129 http script value: ""
2011/11/01 12:44:23 [debug] 13689#0: *129 http script set $chef_version
2011/11/01 12:44:23 [debug] 13689#0: *129 http script var
2011/11/01 12:44:23 [debug] 13689#0: *129 http script var: "0.10.4"
2011/11/01 12:44:23 [debug] 13689#0: *129 http script regex: "^(\d+\.\d+?)\..+$"
2011/11/01 12:44:23 [notice] 13689#0: *129 "^(\d+\.\d+?)\..+$" matches "0.10.4", client: 66.231.201.193, server: api-rs-preprod.opscode.com, request: "PUT /organizations/opscode-btm/nodes/broken HTTP/1.1", host: "api-rs-preprod.opscode.com:443"
2011/11/01 12:44:23 [debug] 13689#0: *129 http script if
2011/11/01 12:44:23 [debug] 13689#0: *129 http script complex value
2011/11/01 12:44:23 [debug] 13689#0: *129 http script copy: "v"
2011/11/01 12:44:23 [debug] 13689#0: *129 http script capture: "0.10"
2011/11/01 12:44:23 [debug] 13689#0: *129 http script set $chef_version
2011/11/01 12:44:23 [debug] 13689#0: *129 http script value: ""
2011/11/01 12:44:23 [debug] 13689#0: *129 http script set $acct
2011/11/01 12:44:23 [debug] 13689#0: *129 http script value: ""
2011/11/01 12:44:23 [debug] 13689#0: *129 http script set $chef
2011/11/01 12:44:23 [debug] 13689#0: *129 http script value: ""
2011/11/01 12:44:23 [debug] 13689#0: *129 http script set $erchef
2011/11/01 12:44:23 [debug] 13689#0: *129 http script var
2011/11/01 12:44:23 [debug] 13689#0: *129 http script var: "v0.10"
2011/11/01 12:44:23 [debug] 13689#0: *129 http script regex: "^v0.10"
2011/11/01 12:44:23 [notice] 13689#0: *129 "^v0.10" matches "v0.10", client: 66.231.201.193, server: api-rs-preprod.opscode.com, request: "PUT /organizations/opscode-btm/nodes/broken HTTP/1.1", host: "api-rs-preprod.opscode.com:443"
2011/11/01 12:44:23 [debug] 13689#0: *129 http script if
2011/11/01 12:44:23 [debug] 13689#0: *129 http script value: "true"
2011/11/01 12:44:23 [debug] 13689#0: *129 http script set $pass_chef_version_test
2011/11/01 12:44:23 [debug] 13689#0: *129 http script var
2011/11/01 12:44:23 [debug] 13689#0: *129 http script var: "v0.10"
2011/11/01 12:44:23 [debug] 13689#0: *129 http script regex: "^v0.9"
2011/11/01 12:44:23 [notice] 13689#0: *129 "^v0.9" does not match "v0.10", client: 66.231.201.193, server: api-rs-preprod.opscode.com, request: "PUT /organizations/opscode-btm/nodes/broken HTTP/1.1", host: "api-rs-preprod.opscode.com:443"
2011/11/01 12:44:23 [debug] 13689#0: *129 http script if
2011/11/01 12:44:23 [debug] 13689#0: *129 http script if: false
2011/11/01 12:44:23 [debug] 13689#0: *129 http script var
2011/11/01 12:44:23 [debug] 13689#0: *129 http script var: "true"
2011/11/01 12:44:23 [debug] 13689#0: *129 http script value: "true"
2011/11/01 12:44:23 [debug] 13689#0: *129 http script equal
2011/11/01 12:44:23 [debug] 13689#0: *129 http script if
2011/11/01 12:44:23 [debug] 13689#0: *129 http script value: "opscode_account"
2011/11/01 12:44:23 [debug] 13689#0: *129 http script set $acct
2011/11/01 12:44:23 [debug] 13689#0: *129 http script value: "opscode_chef"
2011/11/01 12:44:23 [debug] 13689#0: *129 http script set $chef
2011/11/01 12:44:23 [debug] 13689#0: *129 http script value: "opscode_erchef"
2011/11/01 12:44:23 [debug] 13689#0: *129 http script set $erchef
2011/11/01 12:44:23 [debug] 13689#0: *129 test location: "/"
2011/11/01 12:44:23 [debug] 13689#0: *129 test location: "nginx_status"
2011/11/01 12:44:23 [debug] 13689#0: *129 test location: ~ "^/organizations/[a-z0-9-]+?/.*?/_acl.*$"
2011/11/01 12:44:23 [debug] 13689#0: *129 test location: ~ "^/organizations/[a-z0-9-_]+?/(?:search)/.+$"
2011/11/01 12:44:23 [debug] 13689#0: *129 test location: ~ "^/organizations/[a-z0-9-_]+?/(?:nodes|status|search|cookbooks|data|roles|sandboxes|environments)/{0,1}.*$"
2011/11/01 12:44:23 [debug] 13689#0: *129 using configuration "^/organizations/[a-z0-9-_]+?/(?:nodes|status|search|cookbooks|data|roles|sandboxes|environments)/{0,1}.*$"
2011/11/01 12:44:23 [debug] 13689#0: *129 http cl:16385 max:262144000
2011/11/01 12:44:23 [debug] 13689#0: *129 rewrite phase: 2
2011/11/01 12:44:23 [debug] 13689#0: *129 http script var
2011/11/01 12:44:23 [debug] 13689#0: *129 http script var: "broken"
2011/11/01 12:44:23 [debug] 13689#0: *129 http script regex: "^.+$"
2011/11/01 12:44:23 [notice] 13689#0: *129 "^.+$" matches "broken", client: 66.231.201.193, server: api-rs-preprod.opscode.com, request: "PUT /organizations/opscode-btm/nodes/broken HTTP/1.1", host: "api-rs-preprod.opscode.com:443"
2011/11/01 12:44:23 [debug] 13689#0: *129 http script if
2011/11/01 12:44:23 [debug] 13689#0: *129 http script if: false
2011/11/01 12:44:23 [debug] 13689#0: *129 http script var
2011/11/01 12:44:23 [debug] 13689#0: *129 http script var: "opscode_account"
2011/11/01 12:44:23 [debug] 13689#0: *129 http script value: ""
2011/11/01 12:44:23 [debug] 13689#0: *129 http script equal
2011/11/01 12:44:23 [debug] 13689#0: *129 http script equal: no
2011/11/01 12:44:23 [debug] 13689#0: *129 http script if
2011/11/01 12:44:23 [debug] 13689#0: *129 http script if: false
2011/11/01 12:44:23 [debug] 13689#0: *129 http script var
2011/11/01 12:44:23 [debug] 13689#0: *129 http script var: "v0.10"
2011/11/01 12:44:23 [debug] 13689#0: *129 http script regex: "^v0.8"
2011/11/01 12:44:23 [notice] 13689#0: *129 "^v0.8" does not match "v0.10", client: 66.231.201.193, server: api-rs-preprod.opscode.com, request: "PUT /organizations/opscode-btm/nodes/broken HTTP/1.1", host: "api-rs-preprod.opscode.com:443"
2011/11/01 12:44:23 [debug] 13689#0: *129 http script if
2011/11/01 12:44:23 [debug] 13689#0: *129 http script if: false
2011/11/01 12:44:23 [debug] 13689#0: *129 post rewrite phase: 3
2011/11/01 12:44:23 [debug] 13689#0: *129 generic phase: 4
2011/11/01 12:44:23 [debug] 13689#0: *129 generic phase: 5
2011/11/01 12:44:23 [debug] 13689#0: *129 access phase: 6
2011/11/01 12:44:23 [debug] 13689#0: *129 access: C1C9E742 00FFFFFF 0018BADE
2011/11/01 12:44:23 [debug] 13689#0: *129 access phase: 7
2011/11/01 12:44:23 [debug] 13689#0: *129 post access phase: 8
2011/11/01 12:44:23 [debug] 13689#0: *129 http script copy: "http://"
2011/11/01 12:44:23 [debug] 13689#0: *129 http script var: "opscode_chef"
2011/11/01 12:44:23 [debug] 13689#0: *129 malloc: 0870D8E0:8192
2011/11/01 12:44:23 [debug] 13689#0: *129 http read client request body
2011/11/01 12:44:23 [debug] 13689#0: *129 SSL_read: -1
2011/11/01 12:44:23 [debug] 13689#0: *129 SSL_get_error: 2
2011/11/01 12:44:23 [debug] 13689#0: *129 http client request body recv -2
2011/11/01 12:44:23 [debug] 13689#0: *129 http client request body rest 16385
2011/11/01 12:44:23 [debug] 13689#0: *129 event timer add: 12: 60000:1596563798
2011/11/01 12:44:23 [debug] 13689#0: *129 http finalize request: -4, "/organizations/opscode-btm/nodes/broken?" a:1, c:2
2011/11/01 12:44:23 [debug] 13689#0: *129 http request count:2 blk:0
2011/11/01 12:44:24 [debug] 13689#0: *129 http run request: "/organizations/opscode-btm/nodes/broken?"
2011/11/01 12:44:24 [debug] 13689#0: *129 http read client request body
2011/11/01 12:44:24 [debug] 13689#0: *129 SSL_read: 8192
2011/11/01 12:44:24 [debug] 13689#0: *129 http client request body recv 8192
2011/11/01 12:44:24 [debug] 13689#0: *129 add cleanup: 087A849C
2011/11/01 12:44:24 [debug] 13689#0: *129 hashed path: /tmp/nginx-1.1.6/client_body_temp/0000000012
2011/11/01 12:44:24 [debug] 13689#0: *129 temp fd:13
2011/11/01 12:44:24 [warn] 13689#0: *129 a client request body is buffered to a temporary file /tmp/nginx-1.1.6/client_body_temp/0000000012, client: 66.231.201.193, server: api-rs-preprod.opscode.com, request: "PUT /organizations/opscode-btm/nodes/broken HTTP/1.1", host: "api-rs-preprod.opscode.com:443"
2011/11/01 12:44:24 [debug] 13689#0: *129 write: 13, 0870D8E0, 8192, 0
2011/11/01 12:44:24 [debug] 13689#0: *129 SSL_read: 8192
2011/11/01 12:44:24 [debug] 13689#0: *129 http client request body recv 8192
2011/11/01 12:44:24 [debug] 13689#0: *129 write: 13, 0870D8E0, 8192, 8192
2011/11/01 12:44:24 [debug] 13689#0: *129 SSL_read: -1
2011/11/01 12:44:24 [debug] 13689#0: *129 SSL_get_error: 2
2011/11/01 12:44:24 [debug] 13689#0: *129 http client request body recv -2
2011/11/01 12:44:24 [debug] 13689#0: *129 http client request body rest 1
2011/11/01 12:44:24 [debug] 13689#0: *129 event timer del: 12: 1596563798
2011/11/01 12:44:24 [debug] 13689#0: *129 event timer add: 12: 60000:1596564354
2011/11/01 12:45:24 [debug] 13689#0: *129 event timer del: 12: 1596564354
2011/11/01 12:45:24 [debug] 13689#0: *129 http run request: "/organizations/opscode-btm/nodes/broken?"
2011/11/01 12:45:24 [debug] 13689#0: *129 http finalize request: 408, "/organizations/opscode-btm/nodes/broken?" a:1, c:1
2011/11/01 12:45:24 [debug] 13689#0: *129 http terminate request count:1
2011/11/01 12:45:24 [debug] 13689#0: *129 http terminate cleanup count:1 blk:0
2011/11/01 12:45:24 [debug] 13689#0: *129 http posted request: "/organizations/opscode-btm/nodes/broken?"
2011/11/01 12:45:24 [debug] 13689#0: *129 http terminate handler count:1
2011/11/01 12:45:24 [debug] 13689#0: *129 http request count:1 blk:0
2011/11/01 12:45:24 [debug] 13689#0: *129 http close request
2011/11/01 12:45:24 [debug] 13689#0: *129 http log handler
2011/11/01 12:45:24 [debug] 13689#0: *129 run cleanup: 087A849C
2011/11/01 12:45:24 [debug] 13689#0: *129 file cleanup: fd:13
2011/11/01 12:45:24 [debug] 13689#0: *129 free: 0870D8E0
2011/11/01 12:45:24 [debug] 13689#0: *129 free: 087A78F0, unused: 736
2011/11/01 12:45:24 [debug] 13689#0: *129 close http connection: 12
2011/11/01 12:45:24 [debug] 13689#0: *129 SSL_shutdown: 1
2011/11/01 12:45:24 [debug] 13689#0: *129 reusable connection: 0
2011/11/01 12:45:24 [debug] 13689#0: *129 free: 087071C0
2011/11/01 12:45:24 [debug] 13689#0: *129 free: 087A7568
2011/11/01 12:45:24 [debug] 13689#0: *129 free: 0870FA70, unused: 28
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment