Trouble getting UploadProgress module to work

george_x · May 21, 2010, 11:03am

My setup:

Debian Lenny
nginx-0.8.36 installed from source
nginx_upload_module-2.0.12 compiled in.
masterzen-nginx-upload-progress-module-v0.8.1-0 compiled in.
spawn-fcgi-1.6.2 installed from source, running on port 9000

Problem:
Uploading works, but the progress keeps showing “Starting” while the
file is uploaded. Only after it’s done, the result is “Done”. No upload
progress is shown meanwhile.

Logs:

From the nginx debug log, while the upload goes on:

2010/05/21 10:24:52 [debug] 17402#0: *465 reportuploads handler found 
id: 2094466ead99626ce9988aeef04cb816
2010/05/21 10:24:52 [debug] 17402#0: *465 upload-progress: find_node 
2094466ead99626ce9988aeef04cb816
2010/05/21 10:24:52 [debug] 17402#0: *465 upload-progress: can't find 
node
2010/05/21 10:24:52 [debug] 17402#0: *465 reportuploads not found: 
2094466ead99626ce9988aeef04cb816
2010/05/21 10:24:52 [debug] 17402#0: *465 http script copy: "new 
Object({ 'state' : 'starting' })

And then, when the upload is done:

2010/05/21 08:51:36 [debug] 17321#0: *9 upload-progress: find_node 
2094466ead99626ce9988aeef04cb816
2010/05/21 08:51:36 [debug] 17321#0: *9 upload-progress: found node
2010/05/21 08:51:36 [debug] 17321#0: *9 reportuploads found node: 
2094466ead99626ce9988aeef04cb816(rest: 0, length: 0, done: 1, 
err_status: 0)
2010/05/21 08:51:36 [debug] 17321#0: *9 http script copy: "new Object({ 
'state' : 'done' })

But no upload progress!

My server config:

server {
  listen  80;
  server_name  myserver;
  root  /home/wwwadmin/www/;
  access_log  /home/wwwadmin/log/access.log;
  error_log  /home/wwwadmin/log/error.log debug_http debug_event;

  location / {
    # If the file exists as a static file serve it directly without
    # running all the other rewite tests on it
    if (-f $request_filename) {
      expires max;
      break;
    }

    if ($request_filename !~ "\.(js|htc|ico|gif|jpg|png|css)$") {
        rewrite ^(.*) /index.php last;
    }

    # upload_progress config
    proxy_pass http://127.0.0.1;
    proxy_redirect default;
    track_uploads proxied 60s;
  }

  location ^~ /progress {
    report_uploads proxied;
  }

  location ~ \.php($|/) {
    set  $script     $uri;
    set  $path_info  "";

    if ($uri ~ "^(.+\.php)(/.+)") {
      set  $script     $1;
      set  $path_info  $2;
    }

    fastcgi_pass   127.0.0.1:9000;

    include /etc/nginx/fastcgi_params;

    fastcgi_param  SCRIPT_FILENAME  /home/wwwadmin/www$script;
    fastcgi_param  PATH_INFO        $path_info;
  }

  #deny access to .htaccess files
  location  ~ /\.ht {
    deny all;
  }
}

And the /etc/nginx/nginx.conf:

user wwwadmin;
worker_processes  1;

error_log  /var/log/nginx/error.log;
pid        /var/run/nginx.pid;

events {
    worker_connections  1024;
}

http {
    upload_progress proxied 1M;
    client_max_body_size 1024M;
    client_body_buffer_size 1024M;

    include       /etc/nginx/mime.types;
    default_type  application/octet-stream;

    access_log  /var/log/nginx/access.log;

    sendfile        on;
    #tcp_nopush     on;

    #keepalive_timeout  0;
    keepalive_timeout  3;
    tcp_nodelay        on;

    gzip  on;
    gzip_comp_level 2;
    gzip_proxied any;

    include /etc/nginx/conf.d/*.conf;
    include /etc/nginx/sites-enabled/*;
}

I suspect that I am missing something big and obvious in the
configuration, since I cannot find any clues online about this.

Hopefully someone recognizes this (probably noob) problem and can help
out!

Thanks in advance

Posted at Nginx Forum:

george_x · May 22, 2010, 11:11pm

On 21/05/10 11:02, george_x wrote:

My setup:

Debian Lenny

nginx-0.8.36 installed from source

nginx_upload_module-2.0.12 compiled in.

masterzen-nginx-upload-progress-module-v0.8.1-0 compiled in.

Apart from the fact I never tested the upload progress module with nginx
0.8.36, I don’t see anything suspect here.

2010/05/21 10:24:52 [debug] 17402#0: *465 upload-progress: can’t find node
2010/05/21 10:24:52 [debug] 17402#0: *465 reportuploads not found: 2094466ead99626ce9988aeef04cb816
2010/05/21 10:24:52 [debug] 17402#0: *465 http script copy: "new Object({ ‘state’ : ‘starting’ })
[/code]

It looks like the upload hasn’t been registered.
Can you find upload progress debug output that is logged when the upload
starts?

You can also sends me privately the full log for analysis.

But no upload progress!
location / {

location ~ .php($|/) {
include /etc/nginx/fastcgi_params;
fastcgi_param  SCRIPT_FILENAME  /home/wwwadmin/www$script;
fastcgi_param  PATH_INFO        $path_info;
}

Are you sure the upload doesn’t use this location and not ‘/’ one?
Because this one has no track_uploads.

george_x · May 23, 2010, 12:17pm

Brice,

Thanks for helping me out. The problem was indeed what you spotted: the
upload was registered at the .php($|/) location, instead of at “/” .

I updated the config, and it works fine now.

Thanks again!

Posted at Nginx Forum:

george_x · December 31, 2010, 10:42am

I’m having the same problem, what’s the fix?

Posted at Nginx Forum:

george_x · September 25, 2011, 3:03pm

I got the uploadprogress module worked yestoday and I have not change
any configuration today,while I find it out of working then.
Who can help me? Here are some debug logs I find:

2011/09/25 21:04:53 [debug] 9445#0: *10 test location: “/progress”
2011/09/25 21:04:53 [debug] 9445#0: *10 using configuration “/progress”
2011/09/25 21:04:53 [debug] 9445#0: *10 http cl:-1 max:2097152000
2011/09/25 21:04:53 [debug] 9445#0: *10 rewrite phase: 2
2011/09/25 21:04:53 [debug] 9445#0: *10 rewrite phase: 3
2011/09/25 21:04:53 [debug] 9445#0: *10 post rewrite phase: 4
2011/09/25 21:04:53 [debug] 9445#0: *10 generic phase: 5
2011/09/25 21:04:53 [debug] 9445#0: *10 generic phase: 6
2011/09/25 21:04:53 [debug] 9445#0: *10 access phase: 7
2011/09/25 21:04:53 [debug] 9445#0: *10 access phase: 8
2011/09/25 21:04:53 [debug] 9445#0: *10 post access phase: 9
2011/09/25 21:04:53 [debug] 9445#0: *10 http set discard body
2011/09/25 21:04:53 [debug] 9445#0: *10 upload-progress:
get_tracking_id
2011/09/25 21:04:53 [debug] 9445#0: *10 malloc: 0000000007D1D2C0:16
2011/09/25 21:04:53 [debug] 9445#0: *10 upload-progress: get_tracking_id
found header: d3182603d117b2a2505d00183485feb5
2011/09/25 21:04:53 [debug] 9445#0: *10 reportuploads handler found id:
d3182603d117b2a2505d00183485feb5
2011/09/25 21:04:53 [debug] 9445#0: shmtx lock
2011/09/25 21:04:53 [debug] 9445#0: *10 upload-progress: find_node
d3182603d117b2a2505d00183485feb5
2011/09/25 21:04:53 [debug] 9445#0: *10 upload-progress: can’t find
node
2011/09/25 21:04:53 [debug] 9445#0: *10 reportuploads not found:
d3182603d117b2a2505d00183485feb5
2011/09/25 21:04:53 [debug] 9445#0: shmtx unlock
2011/09/25 21:04:53 [debug] 9445#0: *10 http script copy: "new Object({
‘state’ : ‘starting’ })

"
2011/09/25 21:04:53 [debug] 9445#0: *10 upload progress: state=0,
err_status=0, remaining=0, length=0
2011/09/25 21:04:53 [debug] 9445#0: *10 uploadprogress error-tracker
error: 0
2011/09/25 21:04:53 [debug] 9445#0: *10 HTTP/1.1 200 OK

Server: nginx/1.1.4

Date: Sun, 25 Sep 2011 13:04:53 GMT

Content-Type: text/javascript

Content-Length: 38

Connection: keep-alive

Expires: Thu, 01 Jan 1970 00:00:01 GMT

Cache-Control: no-cache

2011/09/25 21:04:53 [debug] 9445#0: *10 write new buf t:1 f:0
0000000007D8C178, pos 0000000007D8C178, size: 217 file: 0, size: 0
2011/09/25 21:04:53 [debug] 9445#0: *10 http write filter: l:0 f:0
s:217
2011/09/25 21:04:53 [debug] 9445#0: *10 http output filter “/progress?”
2011/09/25 21:04:53 [debug] 9445#0: *10 http copy filter: “/progress?”
2011/09/25 21:04:53 [debug] 9445#0: *10 http postpone filter
“/progress?” 00007FFFB0EF7DB0
2011/09/25 21:04:53 [debug] 9445#0: *10 write old buf t:1 f:0
0000000007D8C178, pos 0000000007D8C178, size: 217 file: 0, size: 0
2011/09/25 21:04:53 [debug] 9445#0: *10 write new buf t:1 f:0
0000000007D8C0B0, pos 0000000007D8C0B0, size: 38 file: 0, size: 0
2011/09/25 21:04:53 [debug] 9445#0: *10 http write filter: l:1 f:0
s:255
2011/09/25 21:04:53 [debug] 9445#0: *10 http write filter limit 0
2011/09/25 21:04:53 [debug] 9445#0: *10 writev: 255
2011/09/25 21:04:53 [debug] 9445#0: *10 http write filter
0000000000000000
2011/09/25 21:04:53 [debug] 9445#0: *10 http copy filter: 0
“/progress?”
2011/09/25 21:04:53 [debug] 9445#0: *10 http finalize request: 0,
“/progress?” a:1, c:1
2011/09/25 21:04:53 [debug] 9445#0: *10 set http keepalive handler
2011/09/25 21:04:53 [debug] 9445#0: *10 http close request
2011/09/25 21:04:53 [debug] 9445#0: *10 http log handler
2011/09/25 21:04:53 [debug] 9445#0: *10 free: 0000000007D8B400, unused:
42
2011/09/25 21:04:53 [debug] 9445#0: *10 event timer add: 14:
60000:1316955953219
2011/09/25 21:04:53 [debug] 9445#0: *10 free: 0000000007D2A600
2011/09/25 21:04:53 [debug] 9445#0: *10 free: 0000000007D803C0
2011/09/25 21:04:53 [debug] 9445#0: *10 hc free: 0000000000000000 0
2011/09/25 21:04:53 [debug] 9445#0: *10 hc busy: 0000000000000000 0
2011/09/25 21:04:53 [debug] 9445#0: *10 reusable connection: 1
2011/09/25 21:04:53 [debug] 9445#0: *10 post event 00002B2063134148
2011/09/25 21:04:53 [debug] 9445#0: timer delta: 495
2011/09/25 21:04:53 [debug] 9445#0: posted events 00002B2063134148
2011/09/25 21:04:53 [debug] 9445#0: posted event 00002B2063134148
2011/09/25 21:04:53 [debug] 9445#0: *10 delete posted event
00002B2063134148
2011/09/25 21:04:53 [debug] 9445#0: *10 http keepalive handler
2011/09/25 21:04:53 [debug] 9445#0: *10 malloc: 0000000007D803C0:32768
2011/09/25 21:04:53 [debug] 9445#0: *10 recv: fd:14 -1 of 32768
2011/09/25 21:04:53 [debug] 9445#0: *10 recv() not ready (11: Resource
temporarily unavailable)
2011/09/25 21:04:53 [debug] 9445#0: posted event 0000000000000000
2011/09/25 21:04:53 [debug] 9445#0: worker cycle
2011/09/25 21:04:53 [debug] 9445#0: accept mutex lock failed: 0
2011/09/25 21:04:53 [debug] 9445#0: epoll timer: 500
2011/09/25 21:04:53 [debug] 9448#0: timer delta: 500
2011/09/25 21:04:53 [debug] 9448#0: posted events 0000000000000000
2011/09/25 21:04:53 [debug] 9448#0: worker cycle
2011/09/25 21:04:53 [debug] 9448#0: accept mutex lock failed: 0
2011/09/25 21:04:53 [debug] 9448#0: epoll timer: 500
2011/09/25 21:04:53 [debug] 9449#0: timer delta: 500
2011/09/25 21:04:53 [debug] 9449#0: posted events 0000000000000000
2011/09/25 21:04:53 [debug] 9449#0: worker cycle
2011/09/25 21:04:53 [debug] 9449#0: accept mutex lock failed: 0
2011/09/25 21:04:53 [debug] 9449#0: epoll timer: 500
2011/09/25 21:04:53 [debug] 9445#0: timer delta: 510
2011/09/25 21:04:53 [debug] 9445#0: posted events 0000000000000000
2011/09/25 21:04:53 [debug] 9445#0: worker cycle
2011/09/25 21:04:53 [debug] 9445#0: accept mutex lock failed: 0
2011/09/25 21:04:53 [debug] 9445#0: epoll timer: 500
2011/09/25 21:04:53 [debug] 9448#0: timer delta: 500
2011/09/25 21:04:53 [debug] 9448#0: posted events 0000000000000000
2011/09/25 21:04:53 [debug] 9448#0: worker cycle
2011/09/25 21:04:53 [debug] 9448#0: accept mutex lock failed: 0
2011/09/25 21:04:53 [debug] 9448#0: epoll timer: 500
2011/09/25 21:04:54 [debug] 9449#0: timer delta: 500
2011/09/25 21:04:54 [debug] 9449#0: posted events 0000000000000000
2011/09/25 21:04:54 [debug] 9449#0: worker cycle
2011/09/25 21:04:54 [debug] 9449#0: accept mutex lock failed: 0
2011/09/25 21:04:54 [debug] 9449#0: epoll timer: 500
2011/09/25 21:04:54 [debug] 9445#0: epoll: fd:14 ev:0001
d:00002B20627D3250

Posted at Nginx Forum:

Trouble getting UploadProgress module to work

I got the uploadprogress module worked yestoday and I have not change any configuration today,while I find it out of working then. Who can help me? Here are some debug logs I find:

I got the uploadprogress module worked yestoday and I have not change
any configuration today,while I find it out of working then.
Who can help me? Here are some debug logs I find: