anomalizer/ngx_aws_auth

First request after nginx restart is not served

Opened this issue · 1 comments

It seems that the first nginx request after nginx initialization or restart is not served by S3 due to signature mismatch. The problem is probably caused by missing timestamp in string_to_sign even though x-amz-date header is present.
Debug log for the very first request after start or restart

2014/03/28 20:02:20 [debug] 31823#0: *1 start normalize headers
2014/03/28 20:02:20 [debug] 31823#0: *1 normalized: 
2014/03/28 20:02:20 [debug] 31823#0: *1 bucket: mybucket
2014/03/28 20:02:20 [debug] 31823#0: *1 uri:    /backup/amazon/review01.txt
2014/03/28 20:02:20 [debug] 31823#0: *1 normalized resources: /mybucket/backup/amazon/review01.txt
2014/03/28 20:02:20 [debug] 31823#0: *1 String to sign:GET



/mybucket/backup/amazon/review01.txt
2014/03/28 20:02:20 [debug] 31823#0: *1 aws string being signed BEGIN:
GET



/mybucket/backup/amazon/review01.txt
aws string being signed END
2014/03/28 20:02:20 [debug] 31823#0: *1 Signature: AWS AKIAICP2LJG6EZD7V62Q:hZlFkPilKWyG023B0WctzIB1Q38=
2014/03/28 20:02:20 [debug] 31823#0: *1 posix_memalign: 09CB86E0:4096 @16
2014/03/28 20:02:20 [debug] 31823#0: *1 http script copy: "Authorization: "
2014/03/28 20:02:20 [debug] 31823#0: *1 http script var: "AWS AKIAICP2LJG6EZD7V62Q:hZlFkPilKWyG023B0WctzIB1Q38="
2014/03/28 20:02:20 [debug] 31823#0: *1 http script copy: "
"
2014/03/28 20:02:20 [debug] 31823#0: *1 http script copy: "x-amz-date: "
2014/03/28 20:02:20 [debug] 31823#0: *1 http script var: "Fri, 28 Mar 2014 18:02:20 GMT"
2014/03/28 20:02:20 [debug] 31823#0: *1 http script copy: "
"
2014/03/28 20:02:20 [debug] 31823#0: *1 http script copy: "Host: "
2014/03/28 20:02:20 [debug] 31823#0: *1 http script var: "mybucket.s3.amazonaws.com"
2014/03/28 20:02:20 [debug] 31823#0: *1 http script copy: "
"
2014/03/28 20:02:20 [debug] 31823#0: *1 http script copy: "Connection: close
"

Each subsequent request includes the correct timestamp from x-amz-date header

2014/03/28 20:13:59 [debug] 31823#0: *17 start normalize headers
2014/03/28 20:13:59 [debug] 31823#0: *17 normalized: x-amz-date:Fri, 28 Mar 2014 18:13:59 GMT

2014/03/28 20:13:59 [debug] 31823#0: *17 bucket: mybucket
2014/03/28 20:13:59 [debug] 31823#0: *17 uri:    /backup/amazon/review01.txt
2014/03/28 20:13:59 [debug] 31823#0: *17 normalized resources: /mybucket/backup/amazon/review01.txt
2014/03/28 20:13:59 [debug] 31823#0: *17 String to sign:GET



x-amz-date:Fri, 28 Mar 2014 18:13:59 GMT
/mybucket/backup/amazon/review01.txt
2014/03/28 20:13:59 [debug] 31823#0: *17 aws string being signed BEGIN:
GET



x-amz-date:Fri, 28 Mar 2014 18:13:59 GMT
/mybucket/backup/amazon/review01.txt
aws string being signed END
2014/03/28 20:13:59 [debug] 31823#0: *17 Signature: AWS AKIAICP2LJG6EZD7V62Q:d/q/UjFsoSxNHtJhQCFUfGUFOwo=
2014/03/28 20:13:59 [debug] 31823#0: *17 posix_memalign: 09CB7FA0:4096 @16
2014/03/28 20:13:59 [debug] 31823#0: *17 http script copy: "Authorization: "
2014/03/28 20:13:59 [debug] 31823#0: *17 http script var: "AWS AKIAICP2LJG6EZD7V62Q:d/q/UjFsoSxNHtJhQCFUfGUFOwo="
2014/03/28 20:13:59 [debug] 31823#0: *17 http script copy: "
"
2014/03/28 20:13:59 [debug] 31823#0: *17 http script copy: "x-amz-date: "
2014/03/28 20:13:59 [debug] 31823#0: *17 http script var: "Fri, 28 Mar 2014 18:13:59 GMT"
2014/03/28 20:13:59 [debug] 31823#0: *17 http script copy: "
"
2014/03/28 20:13:59 [debug] 31823#0: *17 http script copy: "Host: "
2014/03/28 20:13:59 [debug] 31823#0: *17 http script var: "mybucket.s3.amazonaws.com"
2014/03/28 20:13:59 [debug] 31823#0: *17 http script copy: "
"
2014/03/28 20:13:59 [debug] 31823#0: *17 http script copy: "Connection: close
"

I have exactly the same problem ... Any idea ?