sebres/nginx

[win]+[cache]: diverse cache file creation resp. access errors using multiple workers (intentional md5-collision on cache key)

sebres opened this issue · 3 comments

2015/09/14 19:44:50 [crit] 8444#736: *49 DeleteFile() "./fastcgi_temp/cache_zone_1/k/9/pb10kik4vac5and94m8sqqr9k5.00110056674.DELETE" failed (2: The system cannot find the file specified) while reading upstream, client: 127.0.0.1, server: localhost, request: "GET /test-cache/?ck=%d1%31%dd%02%c5%e6%ee%c4%69%3d%9a%06%98%af%f9%5c%2f%ca%b5%07%12%46%7e%ab%40%04%58%3e%b8%fb%7f%89%55%ad%34%06%09%f4%b3%02%83%e4%88%83%25%f1%41%5a%08%51%25%e8%f7%cd%c9%9f%d9%1d%bd%72%80%37%3c%5b%d8%82%3e%31%56%34%8f%5b%ae%6d%ac%d4%36%c9%19%c6%dd%53%e2%34%87%da%03%fd%02%39%63%06%d2%48%cd%a0%e9%9f%33%42%0f%57%7e%e8%ce%54%b6%70%80%28%0d%1e%c6%98%21%bc%b6%a8%83%93%96%f9%65%ab%6f%f7%2a%70 HTTP/1.1", upstream: ...
2015/09/14 19:44:50 [crit] 8444#736: *49 MoveFile() "./fastcgi_temp/0110056671" to "./fastcgi_temp/cache_zone_1/k/9/pb10kik4vac5and94m8sqqr9k5" failed (183: Cannot create a file when that file already exists) while reading upstream, client: 127.0.0.1, server: localhost, request: "GET /test-cache/?ck=%d1%31%dd%02%c5%e6%ee%c4%69%3d%9a%06%98%af%f9%5c%2f%ca%b5%07%12%46%7e%ab%40%04%58%3e%b8%fb%7f%89%55%ad%34%06%09%f4%b3%02%83%e4%88%83%25%f1%41%5a%08%51%25%e8%f7%cd%c9%9f%d9%1d%bd%72%80%37%3c%5b%d8%82%3e%31%56%34%8f%5b%ae%6d%ac%d4%36%c9%19%c6%dd%53%e2%34%87%da%03%fd%02%39%63%06%d2%48%cd%a0%e9%9f%33%42%0f%57%7e%e8%ce%54%b6%70%80%28%0d%1e%c6%98%21%bc%b6%a8%83%93%96%f9%65%ab%6f%f7%2a%70 HTTP/1.1", upstream: ...
2015/09/14 19:44:50 [crit] 8732#8784: *47 MoveFile() "./fastcgi_temp/0110056672" to "./fastcgi_temp/cache_zone_1/k/9/pb10kik4vac5and94m8sqqr9k5" failed (183: Cannot create a file when that file already exists) while reading upstream, client: 127.0.0.1, server: localhost, request: "GET /test-cache/?ck=%d1%31%dd%02%c5%e6%ee%c4%69%3d%9a%06%98%af%f9%5c%2f%ca%b5%07%12%46%7e%ab%40%04%58%3e%b8%fb%7f%89%55%ad%34%06%09%f4%b3%02%83%e4%88%83%25%f1%41%5a%08%51%25%e8%f7%cd%c9%9f%d9%1d%bd%72%80%37%3c%5b%d8%82%3e%31%56%34%8f%5b%ae%6d%ac%d4%36%c9%19%c6%dd%53%e2%34%87%da%03%fd%02%39%63%06%d2%48%cd%a0%e9%9f%33%42%0f%57%7e%e8%ce%54%b6%70%80%28%0d%1e%c6%98%21%bc%b6%a8%83%93%96%f9%65%ab%6f%f7%2a%70 HTTP/1.1", upstream: ...
2015/09/14 19:50:03 [crit] 3368#9152: *60 MoveFile() "./fastcgi_temp/0110056695" to "./fastcgi_temp/cache_zone_1/k/9/pb10kik4vac5and94m8sqqr9k5" failed (183: Cannot create a file when that file already exists) while reading upstream, client: 127.0.0.1, server: localhost, request: "GET /test-cache/?ck=%d1%31%dd%02%c5%e6%ee%c4%69%3d%9a%06%98%af%f9%5c%2f%ca%b5%87%12%46%7e%ab%40%04%58%3e%b8%fb%7f%89%55%ad%34%06%09%f4%b3%02%83%e4%88%83%25%71%41%5a%08%51%25%e8%f7%cd%c9%9f%d9%1d%bd%f2%80%37%3c%5b%d8%82%3e%31%56%34%8f%5b%ae%6d%ac%d4%36%c9%19%c6%dd%53%e2%b4%87%da%03%fd%02%39%63%06%d2%48%cd%a0%e9%9f%33%42%0f%57%7e%e8%ce%54%b6%70%80%a8%0d%1e%c6%98%21%bc%b6%a8%83%93%96%f9%65%2b%6f%f7%2a%70 HTTP/1.1", upstream: ...
2015/09/14 19:50:05 [crit] 8444#736: *53 DeleteFile() "./fastcgi_temp/cache_zone_1/k/9/pb10kik4vac5and94m8sqqr9k5.00110056724.DELETE" failed (5: Access is denied) while reading upstream, client: 127.0.0.1, server: localhost, request: "GET /test-cache/?ck=%d1%31%dd%02%c5%e6%ee%c4%69%3d%9a%06%98%af%f9%5c%2f%ca%b5%07%12%46%7e%ab%40%04%58%3e%b8%fb%7f%89%55%ad%34%06%09%f4%b3%02%83%e4%88%83%25%f1%41%5a%08%51%25%e8%f7%cd%c9%9f%d9%1d%bd%72%80%37%3c%5b%d8%82%3e%31%56%34%8f%5b%ae%6d%ac%d4%36%c9%19%c6%dd%53%e2%34%87%da%03%fd%02%39%63%06%d2%48%cd%a0%e9%9f%33%42%0f%57%7e%e8%ce%54%b6%70%80%28%0d%1e%c6%98%21%bc%b6%a8%83%93%96%f9%65%ab%6f%f7%2a%70 HTTP/1.1", upstream: ...
2015/09/14 19:50:05 [crit] 3368#9152: *60 MoveFile() "./fastcgi_temp/cache_zone_1/k/9/pb10kik4vac5and94m8sqqr9k5" to "./fastcgi_temp/cache_zone_1/k/9/pb10kik4vac5and94m8sqqr9k5.00110056728.DELETE" failed (2: The system cannot find the file specified) while reading upstream, client: 127.0.0.1, server: localhost, request: "GET /test-cache/?ck=%d1%31%dd%02%c5%e6%ee%c4%69%3d%9a%06%98%af%f9%5c%2f%ca%b5%87%12%46%7e%ab%40%04%58%3e%b8%fb%7f%89%55%ad%34%06%09%f4%b3%02%83%e4%88%83%25%71%41%5a%08%51%25%e8%f7%cd%c9%9f%d9%1d%bd%f2%80%37%3c%5b%d8%82%3e%31%56%34%8f%5b%ae%6d%ac%d4%36%c9%19%c6%dd%53%e2%b4%87%da%03%fd%02%39%63%06%d2%48%cd%a0%e9%9f%33%42%0f%57%7e%e8%ce%54%b6%70%80%a8%0d%1e%c6%98%21%bc%b6%a8%83%93%96%f9%65%2b%6f%f7%2a%70 HTTP/1.1", upstream: ...
2015/09/14 19:50:05 [crit] 3368#9152: *60 MoveFile() "./fastcgi_temp/cache_zone_1/k/9/pb10kik4vac5and94m8sqqr9k5" to "./fastcgi_temp/cache_zone_1/k/9/pb10kik4vac5and94m8sqqr9k5.00150037056.DELETE" failed (2: The system cannot find the file specified) while reading upstream, client: 127.0.0.1, server: localhost, request: "GET /test-cache/?ck=%d1%31%dd%02%c5%e6%ee%c4%69%3d%9a%06%98%af%f9%5c%2f%ca%b5%87%12%46%7e%ab%40%04%58%3e%b8%fb%7f%89%55%ad%34%06%09%f4%b3%02%83%e4%88%83%25%71%41%5a%08%51%25%e8%f7%cd%c9%9f%d9%1d%bd%f2%80%37%3c%5b%d8%82%3e%31%56%34%8f%5b%ae%6d%ac%d4%36%c9%19%c6%dd%53%e2%b4%87%da%03%fd%02%39%63%06%d2%48%cd%a0%e9%9f%33%42%0f%57%7e%e8%ce%54%b6%70%80%a8%0d%1e%c6%98%21%bc%b6%a8%83%93%96%f9%65%2b%6f%f7%2a%70 HTTP/1.1", upstream: ...
2015/09/14 19:50:05 [crit] 3368#9152: *60 MoveFile() "./fastcgi_temp/cache_zone_1/k/9/pb10kik4vac5and94m8sqqr9k5" to "./fastcgi_temp/cache_zone_1/k/9/pb10kik4vac5and94m8sqqr9k5.00190017384.DELETE" failed (2: The system cannot find the file specified) while reading upstream, client: 127.0.0.1, server: localhost, request: "GET /test-cache/?ck=%d1%31%dd%02%c5%e6%ee%c4%69%3d%9a%06%98%af%f9%5c%2f%ca%b5%87%12%46%7e%ab%40%04%58%3e%b8%fb%7f%89%55%ad%34%06%09%f4%b3%02%83%e4%88%83%25%71%41%5a%08%51%25%e8%f7%cd%c9%9f%d9%1d%bd%f2%80%37%3c%5b%d8%82%3e%31%56%34%8f%5b%ae%6d%ac%d4%36%c9%19%c6%dd%53%e2%b4%87%da%03%fd%02%39%63%06%d2%48%cd%a0%e9%9f%33%42%0f%57%7e%e8%ce%54%b6%70%80%a8%0d%1e%c6%98%21%bc%b6%a8%83%93%96%f9%65%2b%6f%f7%2a%70 HTTP/1.1", upstream: ...
2015/09/14 19:50:05 [crit] 3368#9152: *60 MoveFile() "./fastcgi_temp/cache_zone_1/k/9/pb10kik4vac5and94m8sqqr9k5" to "./fastcgi_temp/cache_zone_1/k/9/pb10kik4vac5and94m8sqqr9k5.00229997712.DELETE" failed (2: The system cannot find the file specified) while reading upstream, client: 127.0.0.1, server: localhost, request: "GET /test-cache/?ck=%d1%31%dd%02%c5%e6%ee%c4%69%3d%9a%06%98%af%f9%5c%2f%ca%b5%87%12%46%7e%ab%40%04%58%3e%b8%fb%7f%89%55%ad%34%06%09%f4%b3%02%83%e4%88%83%25%71%41%5a%08%51%25%e8%f7%cd%c9%9f%d9%1d%bd%f2%80%37%3c%5b%d8%82%3e%31%56%34%8f%5b%ae%6d%ac%d4%36%c9%19%c6%dd%53%e2%b4%87%da%03%fd%02%39%63%06%d2%48%cd%a0%e9%9f%33%42%0f%57%7e%e8%ce%54%b6%70%80%a8%0d%1e%c6%98%21%bc%b6%a8%83%93%96%f9%65%2b%6f%f7%2a%70 HTTP/1.1", upstream: ...

Configuration:

        location ^~ /test-cache/ {

          set_unescape_uri $urikey $arg_ck;
          fastcgi_cache          cache_zone_1;
          fastcgi_cache_key      $urikey;
          fastcgi_ignore_headers Expires Cache-Control Set-Cookie Vary;
          fastcgi_cache_valid    200 5m;


          fastcgi_buffering on;
          fastcgi_keep_conn on;
          #fastcgi_ignore_client_abort on;
          fastcgi_read_timeout 400s;
          fastcgi_send_timeout 120s;

          fastcgi_split_path_info "^(?:/[^/]+/?)([^;]*)(?:;([^/]*))?$";
          include fastcgi_params;
          fastcgi_param SCRIPT_NAME "echo";
          fastcgi_param X_QUERY_ATTRS $fastcgi_path_info if_not_empty;          
          fastcgi_param REMOTE_USER test;

          expires off;

          fastcgi_pass http_cgi_backend;
        }

Test page:

<pre>
GET &quot;/test-cache/%d1%31%dd%02%c5%e6%ee%c4%69%3d%9a%06%98%af%f9%5c%2f%ca%b5%87%12%46%7e%ab%40%04%58%3e%b8%fb%7f%89%55%ad%34%06%09%f4%b3%02%83%e4%88%83%25%71%41%5a%08%51%25%e8%f7%cd%c9%9f%d9%1d%bd%f2%80%37%3c%5b%d8%82%3e%31%56%34%8f%5b%ae%6d%ac%d4%36%c9%19%c6%dd%53%e2%b4%87%da%03%fd%02%39%63%06%d2%48%cd%a0%e9%9f%33%42%0f%57%7e%e8%ce%54%b6%70%80%a8%0d%1e%c6%98%21%bc%b6%a8%83%93%96%f9%65%2b%6f%f7%2a%70
<iframe style="width:100%; height:10%" src="http://localhost/test-cache/?ck=%d1%31%dd%02%c5%e6%ee%c4%69%3d%9a%06%98%af%f9%5c%2f%ca%b5%87%12%46%7e%ab%40%04%58%3e%b8%fb%7f%89%55%ad%34%06%09%f4%b3%02%83%e4%88%83%25%71%41%5a%08%51%25%e8%f7%cd%c9%9f%d9%1d%bd%f2%80%37%3c%5b%d8%82%3e%31%56%34%8f%5b%ae%6d%ac%d4%36%c9%19%c6%dd%53%e2%b4%87%da%03%fd%02%39%63%06%d2%48%cd%a0%e9%9f%33%42%0f%57%7e%e8%ce%54%b6%70%80%a8%0d%1e%c6%98%21%bc%b6%a8%83%93%96%f9%65%2b%6f%f7%2a%70"></iframe>
GET &quot;/test-cache/%d1%31%dd%02%c5%e6%ee%c4%69%3d%9a%06%98%af%f9%5c%2f%ca%b5%07%12%46%7e%ab%40%04%58%3e%b8%fb%7f%89%55%ad%34%06%09%f4%b3%02%83%e4%88%83%25%f1%41%5a%08%51%25%e8%f7%cd%c9%9f%d9%1d%bd%72%80%37%3c%5b%d8%82%3e%31%56%34%8f%5b%ae%6d%ac%d4%36%c9%19%c6%dd%53%e2%34%87%da%03%fd%02%39%63%06%d2%48%cd%a0%e9%9f%33%42%0f%57%7e%e8%ce%54%b6%70%80%28%0d%1e%c6%98%21%bc%b6%a8%83%93%96%f9%65%ab%6f%f7%2a%70
<iframe style="width:100%; height:10%" src="http://localhost/test-cache/?ck=%d1%31%dd%02%c5%e6%ee%c4%69%3d%9a%06%98%af%f9%5c%2f%ca%b5%07%12%46%7e%ab%40%04%58%3e%b8%fb%7f%89%55%ad%34%06%09%f4%b3%02%83%e4%88%83%25%f1%41%5a%08%51%25%e8%f7%cd%c9%9f%d9%1d%bd%72%80%37%3c%5b%d8%82%3e%31%56%34%8f%5b%ae%6d%ac%d4%36%c9%19%c6%dd%53%e2%34%87%da%03%fd%02%39%63%06%d2%48%cd%a0%e9%9f%33%42%0f%57%7e%e8%ce%54%b6%70%80%28%0d%1e%c6%98%21%bc%b6%a8%83%93%96%f9%65%ab%6f%f7%2a%70"></iframe>
GET &quot;/test-cache/%d1%31%dd%02%c5%e6%ee%c4%69%3d%9a%06%98%af%f9%5c%2f%ca%b5%87%12%46%7e%ab%40%04%58%3e%b8%fb%7f%89%55%ad%34%06%09%f4%b3%02%83%e4%88%83%25%71%41%5a%08%51%25%e8%f7%cd%c9%9f%d9%1d%bd%f2%80%37%3c%5b%d8%82%3e%31%56%34%8f%5b%ae%6d%ac%d4%36%c9%19%c6%dd%53%e2%b4%87%da%03%fd%02%39%63%06%d2%48%cd%a0%e9%9f%33%42%0f%57%7e%e8%ce%54%b6%70%80%a8%0d%1e%c6%98%21%bc%b6%a8%83%93%96%f9%65%2b%6f%f7%2a%70
<iframe style="width:100%; height:10%" src="http://localhost/test-cache/?ck=%d1%31%dd%02%c5%e6%ee%c4%69%3d%9a%06%98%af%f9%5c%2f%ca%b5%87%12%46%7e%ab%40%04%58%3e%b8%fb%7f%89%55%ad%34%06%09%f4%b3%02%83%e4%88%83%25%71%41%5a%08%51%25%e8%f7%cd%c9%9f%d9%1d%bd%f2%80%37%3c%5b%d8%82%3e%31%56%34%8f%5b%ae%6d%ac%d4%36%c9%19%c6%dd%53%e2%b4%87%da%03%fd%02%39%63%06%d2%48%cd%a0%e9%9f%33%42%0f%57%7e%e8%ce%54%b6%70%80%a8%0d%1e%c6%98%21%bc%b6%a8%83%93%96%f9%65%2b%6f%f7%2a%70"></iframe>
GET &quot;/test-cache/%d1%31%dd%02%c5%e6%ee%c4%69%3d%9a%06%98%af%f9%5c%2f%ca%b5%07%12%46%7e%ab%40%04%58%3e%b8%fb%7f%89%55%ad%34%06%09%f4%b3%02%83%e4%88%83%25%f1%41%5a%08%51%25%e8%f7%cd%c9%9f%d9%1d%bd%72%80%37%3c%5b%d8%82%3e%31%56%34%8f%5b%ae%6d%ac%d4%36%c9%19%c6%dd%53%e2%34%87%da%03%fd%02%39%63%06%d2%48%cd%a0%e9%9f%33%42%0f%57%7e%e8%ce%54%b6%70%80%28%0d%1e%c6%98%21%bc%b6%a8%83%93%96%f9%65%ab%6f%f7%2a%70
<iframe style="width:100%; height:10%" src="http://localhost/test-cache/?ck=%d1%31%dd%02%c5%e6%ee%c4%69%3d%9a%06%98%af%f9%5c%2f%ca%b5%07%12%46%7e%ab%40%04%58%3e%b8%fb%7f%89%55%ad%34%06%09%f4%b3%02%83%e4%88%83%25%f1%41%5a%08%51%25%e8%f7%cd%c9%9f%d9%1d%bd%72%80%37%3c%5b%d8%82%3e%31%56%34%8f%5b%ae%6d%ac%d4%36%c9%19%c6%dd%53%e2%34%87%da%03%fd%02%39%63%06%d2%48%cd%a0%e9%9f%33%42%0f%57%7e%e8%ce%54%b6%70%80%28%0d%1e%c6%98%21%bc%b6%a8%83%93%96%f9%65%ab%6f%f7%2a%70"></iframe>
....
</pre>

Tcl-code to produce a HTML above, for multiple collisions in cache using browser:

time {
foreach k {
  {
   d131dd02c5e6eec4693d9a0698aff95c   2fcab5[8]712467eab4004583eb8fb7f89
   55ad340609f4b30283e4888325[7]1415a 085125e8f7cdc99fd91dbd[f]280373c5b
   d8823e3156348f5bae6dacd436c919c6   dd53e2[b]487da03fd02396306d248cda0
   e99f33420f577ee8ce54b67080[a]80d1e c69821bcb6a8839396f965[2]b6ff72a70

  } 
  {
   d131dd02c5e6eec4693d9a0698aff95c   2fcab5[0]712467eab4004583eb8fb7f89
   55ad340609f4b30283e4888325[f]1415a 085125e8f7cdc99fd91dbd[7]280373c5b
   d8823e3156348f5bae6dacd436c919c6   dd53e2[3]487da03fd02396306d248cda0
   e99f33420f577ee8ce54b67080[2]80d1e c69821bcb6a8839396f965[a]b6ff72a70
  }
} {
  regsub -all {[\s\[\]]+} $k "" k
  regsub -all {(..)} $k {%\1} k2
  puts "GET \"/test-cache/$k2"
  puts [subst {<iframe style="width:100%; height:10%" src="/test-cache/?ck=$k2"></iframe>}]

  #break
}
} 20

Errors occur only if fastcgi_cache_lock is off (default) and if we have a collision (file will be always invalidated).
May be additionaly impaired from rude antivirus (but rare occurred also without it).

no pull request to mainline-hg (original mercurial repository) as long as #1 was not accepted from nginx developers (does no matter as long as single-worker, see http://forum.nginx.org/read.php?29,259516).

much better solution as amend commit 0f329b8