Nginx webdav server with auth request

authenticationnginxwebdav

My nginx.conf:

location ~ ^/api/(.*)$ {
  alias /home/username/apidav/$remote_user/$1;

  client_body_temp_path       /var/www/path/;
  client_max_body_size        50m;
  dav_methods                 PUT DELETE MKCOL;# COPY MOVE;
  create_full_put_path        on;
  dav_access                  user:rw  group:rw  all:r;
  dav_ext_methods             PROPFIND OPTIONS;
  auth_request /api_auth;
}

location /api_auth {
  internal;
  proxy_pass http://www.domain.ru/accounts/api_auth/;
  proxy_pass_request_body off;
  proxy_set_header Content-Length "";
  proxy_set_header X-Original-URI $request_uri;
}

curl -T test.txt 'http://gert:passwd@www.domain.ru/api/'
curl: (56) Recv failure: Connection reset by peer?

Why?

tail -f /var/log/nginx/error.log
2012/11/16 17:53:42 [alert] 30060#0: worker process 8374 exited on signal 11

Tail debug log, after auth request:

2012/11/16 07:00:33 [debug] 8241#0: *1892 send 100 Continue
2012/11/16 07:00:33 [debug] 8241#0: *1892 send: fd:458 25 of 25
2012/11/16 07:00:33 [debug] 8241#0: *1892 http read client request body
2012/11/16 07:00:33 [debug] 8241#0: *1892 recv: fd:458 -1 of 91
2012/11/16 07:00:33 [debug] 8241#0: *1892 recv() not ready (11: Resource temporarily
unavailable)
2012/11/16 07:00:33 [debug] 8241#0: *1892 http client request body recv -2
2012/11/16 07:00:33 [debug] 8241#0: *1892 http client request body rest 91
2012/11/16 07:00:33 [debug] 8241#0: *1892 event timer add: 458: 60000:1353027693786
2012/11/16 07:00:33 [debug] 8241#0: *1892 http finalize request: -4, "/api/test.txt?" a:1, c:2
2012/11/16 07:00:33 [debug] 8241#0: *1892 http request count:2 blk:0
2012/11/16 07:00:33 [debug] 8241#0: *1894 post event 0000000001789C58
2012/11/16 07:00:33 [debug] 8241#0: *1894 post event 000000000179D468
2012/11/16 07:00:33 [debug] 8241#0: *1894 delete posted event 000000000179D468
2012/11/16 07:00:33 [debug] 8241#0: *1894 http empty handler
2012/11/16 07:00:33 [debug] 8241#0: *1894 delete posted event 0000000001789C58
2012/11/16 07:00:33 [debug] 8241#0: *1894 http lingering close handler
2012/11/16 07:00:33 [debug] 8241#0: *1894 recv: fd:461 0 of 4096
2012/11/16 07:00:33 [debug] 8241#0: *1894 lingering read: 0
2012/11/16 07:00:33 [debug] 8241#0: *1894 http request count:1 blk:0
2012/11/16 07:00:33 [debug] 8241#0: *1894 http close request
2012/11/16 07:00:33 [debug] 8241#0: *1894 http log handler
2012/11/16 07:00:33 [debug] 8241#0: *1894 free: 0000000000000000
2012/11/16 07:00:33 [debug] 8241#0: *1894 free: 00000000016DE8A0, unused: 1
2012/11/16 07:00:33 [debug] 8241#0: *1894 free: 0000000001605050, unused: 327
2012/11/16 07:00:33 [debug] 8241#0: *1894 close http connection: 461
2012/11/16 07:00:33 [debug] 8241#0: *1894 event timer del: 461: 1353027638785
2012/11/16 07:00:33 [debug] 8241#0: *1894 reusable connection: 0
2012/11/16 07:00:33 [debug] 8241#0: *1894 free: 00000000016610F0
2012/11/16 07:00:33 [debug] 8241#0: *1894 free: 00000000015BFAA0
2012/11/16 07:00:33 [debug] 8241#0: *1894 free: 00000000015F0050, unused: 8
2012/11/16 07:00:33 [debug] 8241#0: *1894 free: 000000000163E980, unused: 112
2012/11/16 07:00:33 [debug] 8241#0: *1892 post event 0000000001789B88
2012/11/16 07:00:33 [debug] 8241#0: *1892 post event 000000000179D398
2012/11/16 07:00:33 [debug] 8241#0: *1892 delete posted event 000000000179D398
2012/11/16 07:00:33 [debug] 8241#0: *1892 http run request: "/api/test.txt?"
2012/11/16 07:00:33 [debug] 8241#0: *1892 content phase: 19
2012/11/16 07:00:33 [debug] 8241#0: *1892 http script copy: "/home/username/apidav/"
2012/11/16 07:00:33 [debug] 8241#0: *1892 http script var: "gert"
2012/11/16 07:00:33 [debug] 8241#0: *1892 http script copy: "/"
2012/11/16 07:00:33 [debug] 8241#0: *1892 http script capture: "test.txt"
2012/11/16 07:00:33 [debug] 8241#0: *1892 http put filename: "/home/username/apidav/gert/test.txt"
2012/11/16 07:00:33 [debug] 8285#0: epoll add event: fd:9 op:1 ev:00000001
2012/11/16 07:36:55 [debug] 8255#0: epoll add event: fd:9 op:1 ev:00000001
2012/11/16 07:36:55 [debug] 8285#0: epoll del event: fd:9 op:2 ev:00000000

core dump

(gdb) bt
0 ngx_ext_rename_file (src=0x8, to=0x7fffcaa10870, ext=0x7fffcaa10840) at src/core/ngx_file.c:545
1 0x0000000000472864 in ngx_http_dav_put_handler (r=0x1581fe0) at src/http/modules/ngx_http_dav_module.c:261
2 0x0000000000450a55 in ngx_http_read_client_request_body (r=0x1581fe0, post_handler=0x472730 ) at src/http/ngx_http_request_body.c:155
3 0x0000000000473873 in ngx_http_dav_handler (r=0x1581fe0) at src/http/modules/ngx_http_dav_module.c:172
4 0x0000000000443676 in ngx_http_core_content_phase (r=0x1581fe0, ph=0x14e7de0) at src/http/ngx_http_core_module.c:1403
5 0x000000000043e215 in ngx_http_core_run_phases (r=0x1581fe0) at src/http/ngx_http_core_module.c:877
6 0x0000000000448b13 in ngx_http_request_handler (ev=0x161e9f8) at src/http/ngx_http_request.c:1846
7 0x000000000042e308 in ngx_event_process_posted (cycle=0x156be60, posted=0x71edc0) at src/event/ngx_event_posted.c:40
8 0x0000000000434f59 in ngx_worker_process_cycle (cycle=0x156be60, data=) at src/os/unix/ngx_process_cycle.c:806
9 0x00000000004338b5 in ngx_spawn_process (cycle=0x156be60, proc=0x434ea0 , data=0x0, name=0x4d4de8 "worker process", respawn=-4) at src/os/unix/ngx_process.c:198
10 0x00000000004352ca in ngx_start_worker_processes (cycle=0x156be60, n=20, type=-4) at src/os/unix/ngx_process_cycle.c:365
11 0x0000000000435fda in ngx_master_process_cycle (cycle=0x156be60) at src/os/unix/ngx_process_cycle.c:250
12 0x0000000000415efe in main (argc=, argv=) at src/core/nginx.c:410

Best Answer

The problem you see is a combination of two actual problems:

  • The problem in nginx core, which results in request body being read incorrectly in some cases. In your case, this problem is triggered by the auth request module. This problem is under investigation.

  • The bug in dav module which causes nginx to dereference null pointer if request body wasn't read under dav module's control. The bug doesn't manifest itself under normal conditions, but due to the above problem you've hit it.

Related Topic