Problem solved. Everything because Nginx, and a request_uri in fcgi params to radosgw. Now request_uri is ok, and problem disappear. Big thanks for help Yehuda. Regards Dnia 12 wrz 2012 o godz. 01:27 Yehuda Sadeh <yehuda@xxxxxxxxxxx> napisał(a): > On Tue, Sep 11, 2012 at 1:41 PM, Sławomir Skowron <szibis@xxxxxxxxx> wrote: >> And more logs: >> >> >> 2012-09-11 21:03:38.357304 7faf0bf4f700 1 ====== req done >> req=0x141a650 http_status=403 ====== >> 2012-09-11 21:23:54.423185 7faf0bf4f700 20 dequeued request req=0x139a3d0 >> 2012-09-11 21:23:54.423192 7faf0bf4f700 20 RGWWQ: empty >> 2012-09-11 21:23:54.423198 7faf0bf4f700 1 ====== starting new request >> req=0x139a3d0 ===== >> 2012-09-11 21:23:54.423237 7faf0bf4f700 2 req 58098:0.000039::::initializing >> 2012-09-11 21:23:54.423258 7faf0bf4f700 10 s->object=<NULL> s->bucket=<NULL> >> 2012-09-11 21:23:54.423265 7faf0bf4f700 20 FCGI_ROLE=RESPONDER >> 2012-09-11 21:23:54.423267 7faf0bf4f700 20 SCRIPT_FILENAME=/var/www/radosgw.fcgi >> 2012-09-11 21:23:54.423269 7faf0bf4f700 20 QUERY_STRING= >> 2012-09-11 21:23:54.423270 7faf0bf4f700 20 REQUEST_METHOD=GET >> 2012-09-11 21:23:54.423272 7faf0bf4f700 20 CONTENT_TYPE= >> 2012-09-11 21:23:54.423273 7faf0bf4f700 20 CONTENT_LENGTH= >> 2012-09-11 21:23:54.423274 7faf0bf4f700 20 HTTP_CONTENT_LENGTH= >> 2012-09-11 21:23:54.423276 7faf0bf4f700 20 SCRIPT_NAME=/ >> 2012-09-11 21:23:54.423277 7faf0bf4f700 20 REQUEST_URI=/ >> 2012-09-11 21:23:54.423279 7faf0bf4f700 20 DOCUMENT_URI=/ >> 2012-09-11 21:23:54.423280 7faf0bf4f700 20 DOCUMENT_ROOT=/var/www >> 2012-09-11 21:23:54.423282 7faf0bf4f700 20 SERVER_PROTOCOL=HTTP/1.0 >> 2012-09-11 21:23:54.423283 7faf0bf4f700 20 GATEWAY_INTERFACE=CGI/1.1 >> 2012-09-11 21:23:54.423284 7faf0bf4f700 20 SERVER_SOFTWARE=nginx/1.2.0 >> 2012-09-11 21:23:54.423286 7faf0bf4f700 20 REMOTE_ADDR=10.177.95.19 >> 2012-09-11 21:23:54.423287 7faf0bf4f700 20 REMOTE_PORT=60477 >> 2012-09-11 21:23:54.423289 7faf0bf4f700 20 SERVER_ADDR=10.177.64.4 >> 2012-09-11 21:23:54.423290 7faf0bf4f700 20 SERVER_PORT=80 >> ...skipping... >> 2012-09-11 22:23:44.530567 7faf0bf4f700 10 >> s->object=images/pulscms/NjQ7MDMsMWUwLDAsMCwx/0a9915212e85062de6134566905cf252.jpg >> s->bucket=ocdn >> 2012-09-11 22:23:44.530586 7faf0bf4f700 20 FCGI_ROLE=RESPONDER >> 2012-09-11 22:23:44.530588 7faf0bf4f700 20 SCRIPT_FILENAME=/var/www/radosgw.fcgi >> 2012-09-11 22:23:44.530589 7faf0bf4f700 20 QUERY_STRING= >> 2012-09-11 22:23:44.530591 7faf0bf4f700 20 REQUEST_METHOD=GET >> 2012-09-11 22:23:44.530592 7faf0bf4f700 20 CONTENT_TYPE= >> 2012-09-11 22:23:44.530593 7faf0bf4f700 20 CONTENT_LENGTH= >> 2012-09-11 22:23:44.530594 7faf0bf4f700 20 HTTP_CONTENT_LENGTH= >> 2012-09-11 22:23:44.530595 7faf0bf4f700 20 >> SCRIPT_NAME=/ocdn/images/pulscms/NjQ7MDMsMWUwLDAsMCwx/0a9915212e85062de6134566905cf252.jpg >> 2012-09-11 22:23:44.530596 7faf0bf4f700 20 >> REQUEST_URI=/ocdn/images/pulscms/NjQ7MDMsMWUwLDAsMCwx/0a9915212e85062de6134566905cf252.jpg >> 2012-09-11 22:23:44.530598 7faf0bf4f700 20 >> DOCUMENT_URI=/ocdn/images/pulscms/NjQ7MDMsMWUwLDAsMCwx/0a9915212e85062de6134566905cf252.jpg >> 2012-09-11 22:23:44.530600 7faf0bf4f700 20 DOCUMENT_ROOT=/var/www >> 2012-09-11 22:23:44.530603 7faf0bf4f700 20 SERVER_PROTOCOL=HTTP/1.1 >> 2012-09-11 22:23:44.530604 7faf0bf4f700 20 GATEWAY_INTERFACE=CGI/1.1 >> 2012-09-11 22:23:44.530605 7faf0bf4f700 20 SERVER_SOFTWARE=nginx/1.2.0 >> 2012-09-11 22:23:44.530606 7faf0bf4f700 20 REMOTE_ADDR=10.167.14.53 >> 2012-09-11 22:23:44.530607 7faf0bf4f700 20 REMOTE_PORT=62145 >> 2012-09-11 22:23:44.530608 7faf0bf4f700 20 SERVER_ADDR=10.177.64.4 >> 2012-09-11 22:23:44.530609 7faf0bf4f700 20 SERVER_PORT=80 >> 2012-09-11 22:23:44.530610 7faf0bf4f700 20 SERVER_NAME= >> 2012-09-11 22:23:44.530610 7faf0bf4f700 20 REDIRECT_STATUS=200 >> 2012-09-11 22:23:44.530611 7faf0bf4f700 20 RGW_SHOULD_LOG=no >> 2012-09-11 22:23:44.530612 7faf0bf4f700 20 HTTP_HOST=10.177.64.4 >> 2012-09-11 22:23:44.530613 7faf0bf4f700 20 HTTP_CONNECTION=keep-alive >> 2012-09-11 22:23:44.530614 7faf0bf4f700 20 HTTP_USER_AGENT=Mozilla/5.0 >> (Macintosh; Intel Mac OS X 10_7_4) AppleWebKit/537.1 (KHTML, like >> Gecko) Chrome/21.0.1180.89 Safari/537.1 >> 2012-09-11 22:23:44.530615 7faf0bf4f700 20 >> HTTP_ACCEPT=text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8 >> 2012-09-11 22:23:44.530616 7faf0bf4f700 20 >> HTTP_ACCEPT_ENCODING=gzip,deflate,sdch >> 2012-09-11 22:23:44.530617 7faf0bf4f700 20 HTTP_ACCEPT_LANGUAGE=en-US,en;q=0.8 >> 2012-09-11 22:23:44.530618 7faf0bf4f700 20 >> HTTP_ACCEPT_CHARSET=ISO-8859-1,utf-8;q=0.7,*;q=0.3 >> 2012-09-11 22:23:44.530620 7faf0bf4f700 2 req 68518:0.000117:s3:GET >> /ocdn/images/pulscms/NjQ7MDMsMWUwLDAsMCwx/0a9915212e85062de6134566905cf252.jpg::getting >> op >> 2012-09-11 22:23:44.530626 7faf0bf4f700 2 req 68518:0.000123:s3:GET >> /ocdn/images/pulscms/NjQ7MDMsMWUwLDAsMCwx/0a9915212e85062de6134566905cf252.jpg:get_obj:authorizing >> 2012-09-11 22:23:44.530630 7faf0bf4f700 2 req 68518:0.000127:s3:GET >> /ocdn/images/pulscms/NjQ7MDMsMWUwLDAsMCwx/0a9915212e85062de6134566905cf252.jpg:get_obj:reading >> permissions >> 2012-09-11 22:23:44.530646 7faf0bf4f700 20 get_obj_state: >> rctx=0x7fb01c0122c0 obj=.rgw:ocdn state=0x7fb01c013248 >> s->prefetch_data=0 >> 2012-09-11 22:23:44.531746 7faf0bf4f700 20 get_obj_state: s->obj_tag >> was set empty >> 2012-09-11 22:23:44.531760 7faf0bf4f700 20 get_obj_state: >> rctx=0x7fb01c0122c0 obj=.rgw:ocdn state=0x7fb01c013248 >> s->prefetch_data=0 >> 2012-09-11 22:23:44.531767 7faf0bf4f700 20 get_obj_state: >> rctx=0x7fb01c0122c0 obj=.rgw:ocdn state=0x7fb01c013248 >> s->prefetch_data=0 >> 2012-09-11 22:23:44.531771 7faf0bf4f700 20 state for obj=.rgw:ocdn is >> not atomic, not appending atomic test >> 2012-09-11 22:23:44.531773 7faf0bf4f700 20 rados->read obj-ofs=0 >> read_ofs=0 read_len=16384 >> 2012-09-11 22:23:44.532701 7faf0bf4f700 20 rados->read r=0 bl.length=65 >> 2012-09-11 22:23:44.532721 7faf0bf4f700 20 rgw_get_bucket_info: >> bucket=ocdn(@.rgw.buckets[4168.2]) owner 0 >> 2012-09-11 22:23:44.532734 7faf0bf4f700 20 get_obj_state: >> rctx=0x7fb01c0122c0 obj=ocdn: state=0x7fb01c013248 s->prefetch_data=0 >> 2012-09-11 22:23:44.532750 7faf0bf4f700 15 Read >> AccessControlPolicy<AccessControlPolicy >> xmlns="http://s3.amazonaws.com/doc/2006-03-01/";><Owner><ID>0</ID><DisplayName>ocdn</DisplayName></Owner><AccessControlList><Grant><Grantee >> xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"; >> xsi:type="Group"><URI>http://acs.amazonaws.com/groups/global/AllUsers</URI></Grantee><Permission>READ</Permission></Grant><Grant><Grantee >> xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"; >> xsi:type="CanonicalUser"><ID>0</ID><DisplayName>ocdn</DisplayName></Grantee><Permission>FULL_CONTROL</Permission></Grant></AccessControlList></AccessControlPolicy> >> 2012-09-11 22:23:44.532770 7faf0bf4f700 20 get_obj_state: >> rctx=0x7fb01c0122c0 >> obj=ocdn:images/pulscms/NjQ7MDMsMWUwLDAsMCwx/0a9915212e85062de6134566905cf252.jpg >> state=0x7fb01c00a608 s->prefetch_data=1 >> 2012-09-11 22:23:44.534298 7faf0bf4f700 20 get_obj_state: s->obj_tag >> was set empty >> 2012-09-11 22:23:44.534315 7faf0bf4f700 15 Read >> AccessControlPolicy<AccessControlPolicy >> xmlns="http://s3.amazonaws.com/doc/2006-03-01/";><Owner><ID>0</ID><DisplayName>ocdn</DisplayName></Owner><AccessControlList><Grant><Grantee >> xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"; >> xsi:type="CanonicalUser"><ID>0</ID><DisplayName>ocdn</DisplayName></Grantee><Permission>FULL_CONTROL</Permission></Grant></AccessControlList></AccessControlPolicy> >> 2012-09-11 22:23:44.534327 7faf0bf4f700 2 req 68518:0.003823:s3:GET >> /ocdn/images/pulscms/NjQ7MDMsMWUwLDAsMCwx/0a9915212e85062de6134566905cf252.jpg:get_obj:verifying >> op permissions >> 2012-09-11 22:23:44.534334 7faf0bf4f700 5 Searching permissions for >> uid=anonymous mask=1 >> 2012-09-11 22:23:44.534336 7faf0bf4f700 5 Permissions for user not found >> 2012-09-11 22:23:44.534337 7faf0bf4f700 5 Searching permissions for >> group=1 mask=1 >> 2012-09-11 22:23:44.534338 7faf0bf4f700 5 Permissions for group not found >> 2012-09-11 22:23:44.534339 7faf0bf4f700 5 Getting permissions >> id=anonymous owner=0 perm=0 >> 2012-09-11 22:23:44.534341 7faf0bf4f700 10 uid=anonymous requested >> perm (type)=1, policy perm=0, user_perm_mask=15, acl perm=0 >> 2012-09-11 22:23:44.534343 7faf0bf4f700 5 Searching permissions for >> uid=anonymous mask=16 >> 2012-09-11 22:23:44.534344 7faf0bf4f700 5 Permissions for user not found >> 2012-09-11 22:23:44.534345 7faf0bf4f700 5 Searching permissions for >> group=1 mask=16 >> 2012-09-11 22:23:44.534347 7faf0bf4f700 5 Found permission: 1 >> 2012-09-11 22:23:44.534348 7faf0bf4f700 5 Getting permissions >> id=anonymous owner=0 perm=0 >> 2012-09-11 22:23:44.534349 7faf0bf4f700 10 uid=anonymous requested >> perm (type)=16, policy perm=0, user_perm_mask=16, acl perm=0 >> 2012-09-11 22:23:44.534357 7faf0bf4f700 10 --> Status: 403 >> 2012-09-11 22:23:44.534367 7faf0bf4f700 10 --> Content-Length: 78 >> 2012-09-11 22:23:44.534370 7faf0bf4f700 10 --> Accept-Ranges: bytes >> 2012-09-11 22:23:44.534373 7faf0bf4f700 10 --> Content-type: application/xml >> 2012-09-11 22:23:44.534480 7faf0bf4f700 2 req 68518:0.003976:s3:GET >> /ocdn/images/pulscms/NjQ7MDMsMWUwLDAsMCwx/0a9915212e85062de6134566905cf252.jpg:get_obj:http >> status=403 >> 2012-09-11 22:23:44.534765 7faf0bf4f700 1 ====== req done >> req=0x13995c0 http_status=403 ====== >> >> Good put, and 403 after: >> >> 2012-09-11 22:37:34.677422 7fafddffb700 1 ====== starting new request >> req=0x139a3d0 ===== >> 2012-09-11 22:37:34.677466 7fafddffb700 2 req 71187:0.000044::::initializing >> 2012-09-11 22:37:34.677492 7fafddffb700 10 >> s->object=files/pulscms/MjU7MDA_/ecebacddde95224b96f46333912049b1 >> s->bucket=ocdn >> 2012-09-11 22:37:34.677501 7fafddffb700 20 FCGI_ROLE=RESPONDER >> 2012-09-11 22:37:34.677502 7fafddffb700 20 SCRIPT_FILENAME=/var/www/radosgw.fcgi >> 2012-09-11 22:37:34.677503 7fafddffb700 20 QUERY_STRING= >> 2012-09-11 22:37:34.677504 7fafddffb700 20 REQUEST_METHOD=PUT >> 2012-09-11 22:37:34.677505 7fafddffb700 20 CONTENT_TYPE=text/plain >> 2012-09-11 22:37:34.677506 7fafddffb700 20 CONTENT_LENGTH=4721 >> 2012-09-11 22:37:34.677507 7fafddffb700 20 HTTP_CONTENT_LENGTH=4721 >> 2012-09-11 22:37:34.677508 7fafddffb700 20 >> SCRIPT_NAME=/ocdn/files/pulscms/MjU7MDA_/ecebacddde95224b96f46333912049b1 >> 2012-09-11 22:37:34.677509 7fafddffb700 20 >> REQUEST_URI=/ocdn/files/pulscms/MjU7MDA_/ecebacddde95224b96f46333912049b1 >> 2012-09-11 22:37:34.677510 7fafddffb700 20 >> DOCUMENT_URI=/ocdn/files/pulscms/MjU7MDA_/ecebacddde95224b96f46333912049b1 >> 2012-09-11 22:37:34.677511 7fafddffb700 20 DOCUMENT_ROOT=/var/www >> 2012-09-11 22:37:34.677512 7fafddffb700 20 SERVER_PROTOCOL=HTTP/1.1 >> 2012-09-11 22:37:34.677512 7fafddffb700 20 GATEWAY_INTERFACE=CGI/1.1 >> 2012-09-11 22:37:34.677513 7fafddffb700 20 SERVER_SOFTWARE=nginx/1.2.0 >> 2012-09-11 22:37:34.677514 7fafddffb700 20 REMOTE_ADDR=10.174.53.77 >> 2012-09-11 22:37:34.677515 7fafddffb700 20 REMOTE_PORT=48588 >> 2012-09-11 22:37:34.677516 7fafddffb700 20 SERVER_ADDR=10.177.0.3 >> 2012-09-11 22:37:34.677516 7fafddffb700 20 SERVER_PORT=80 >> 2012-09-11 22:37:34.677517 7fafddffb700 20 SERVER_NAME= >> 2012-09-11 22:37:34.677518 7fafddffb700 20 REDIRECT_STATUS=200 >> 2012-09-11 22:37:34.677519 7fafddffb700 20 RGW_SHOULD_LOG=no >> 2012-09-11 22:37:34.677520 7fafddffb700 20 HTTP_HOST=10.177.0.3 >> 2012-09-11 22:37:34.677520 7fafddffb700 20 HTTP_ACCEPT_ENCODING=identity >> 2012-09-11 22:37:34.677521 7fafddffb700 20 >> HTTP_CONTENT_MD5=7Ous3d6VIkuW9GMzkSBJsQ== >> 2012-09-11 22:37:34.677522 7fafddffb700 20 HTTP_EXPECT=100-Continue >> 2012-09-11 22:37:34.677523 7fafddffb700 20 HTTP_DATE=Tue, 11 Sep 2012 >> 20:37:46 GMT >> 2012-09-11 22:37:34.677524 7fafddffb700 20 HTTP_USER_AGENT=Boto/2.5.1 (linux2) >> 2012-09-11 22:37:34.677525 7fafddffb700 20 HTTP_CONTENT_TYPE=text/plain >> 2012-09-11 22:37:34.677526 7fafddffb700 20 HTTP_AUTHORIZATION=AWS >> 73VF66Q2JH5PT5K7QJ3A:5ucLfRdtJtAdcIcns2pgMowWAEE= >> 2012-09-11 22:37:34.677529 7fafddffb700 2 req 71187:0.000108:s3:PUT >> /ocdn/files/pulscms/MjU7MDA_/ecebacddde95224b96f46333912049b1::getting >> op >> 2012-09-11 22:37:34.677534 7fafddffb700 2 req 71187:0.000113:s3:PUT >> /ocdn/files/pulscms/MjU7MDA_/ecebacddde95224b96f46333912049b1:put_obj:authorizing >> 2012-09-11 22:37:34.677552 7fafddffb700 20 get_obj_state: >> rctx=0x7fb00c004960 obj=.users:73VF66Q2JH5PT5K7QJ3A >> state=0x7fb00c004a18 s->prefetch_data=0 >> 2012-09-11 22:37:34.679069 7fafddffb700 20 get_obj_state: s->obj_tag >> was set empty >> 2012-09-11 22:37:34.679086 7fafddffb700 20 get_obj_state: >> rctx=0x7fb00c004960 obj=.users:73VF66Q2JH5PT5K7QJ3A >> state=0x7fb00c004a18 s->prefetch_data=0 >> 2012-09-11 22:37:34.680427 7fafddffb700 20 get_obj_state: s->obj_tag >> was set empty >> 2012-09-11 22:37:34.680441 7fafddffb700 20 get_obj_state: >> rctx=0x7fb00c004960 obj=.users:73VF66Q2JH5PT5K7QJ3A >> state=0x7fb00c004a18 s->prefetch_data=0 >> 2012-09-11 22:37:34.680452 7fafddffb700 20 state for >> obj=.users:73VF66Q2JH5PT5K7QJ3A is not atomic, not appending atomic >> test >> 2012-09-11 22:37:34.680457 7fafddffb700 20 rados->read obj-ofs=0 >> read_ofs=0 read_len=16384 >> 2012-09-11 22:37:34.681685 7fafddffb700 20 rados->read r=0 bl.length=231 >> 2012-09-11 22:37:34.681748 7fafddffb700 10 get_canon_resource(): >> dest=/ocdn/files/pulscms/MjU7MDA_/ecebacddde95224b96f46333912049b1 >> 2012-09-11 22:37:34.681766 7fafddffb700 10 auth_hdr: > > missing some lines here, did you grep the output? > >> 2012-09-11 22:37:34.681911 7fafddffb700 15 b64=5ucLfRdtJtAdcIcns2pgMowWAEE= >> 2012-09-11 22:37:34.681921 7fafddffb700 15 >> auth_sign=5ucLfRdtJtAdcIcns2pgMowWAEE= >> 2012-09-11 22:37:34.681922 7fafddffb700 15 compare=0 >> 2012-09-11 22:37:34.681926 7fafddffb700 2 req 71187:0.004504:s3:PUT >> /ocdn/files/pulscms/MjU7MDA_/ecebacddde95224b96f46333912049b1:put_obj:reading >> permissions >> 2012-09-11 22:37:34.681941 7fafddffb700 20 get_obj_state: >> rctx=0x7fb00c007050 obj=.rgw:ocdn state=0x7fb00c006578 >> s->prefetch_data=0 >> 2012-09-11 22:37:34.683575 7fafddffb700 20 get_obj_state: s->obj_tag >> was set empty >> 2012-09-11 22:37:34.683588 7fafddffb700 20 get_obj_state: >> rctx=0x7fb00c007050 obj=.rgw:ocdn state=0x7fb00c006578 >> s->prefetch_data=0 >> 2012-09-11 22:37:34.683596 7fafddffb700 20 get_obj_state: >> rctx=0x7fb00c007050 obj=.rgw:ocdn state=0x7fb00c006578 >> s->prefetch_data=0 >> 2012-09-11 22:37:34.683599 7fafddffb700 20 state for obj=.rgw:ocdn is >> not atomic, not appending atomic test >> 2012-09-11 22:37:34.683601 7fafddffb700 20 rados->read obj-ofs=0 >> read_ofs=0 read_len=16384 >> 2012-09-11 22:37:34.684735 7fafddffb700 20 rados->read r=0 bl.length=65 >> 2012-09-11 22:37:34.684755 7fafddffb700 20 rgw_get_bucket_info: >> bucket=ocdn(@.rgw.buckets[4168.2]) owner 0 >> 2012-09-11 22:37:34.684769 7fafddffb700 20 get_obj_state: >> rctx=0x7fb00c007050 obj=ocdn: state=0x7fb00c006578 s->prefetch_data=0 >> 2012-09-11 22:37:34.684786 7fafddffb700 15 Read >> AccessControlPolicy<AccessControlPolicy >> xmlns="http://s3.amazonaws.com/doc/2006-03-01/";><Owner><ID>0</ID><DisplayName>ocdn</DisplayName></Owner><AccessControlList><Grant><Grantee >> xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"; >> xsi:type="Group"><URI>http://acs.amazonaws.com/groups/global/AllUsers</URI></Grantee><Permission>READ</Permission></Grant><Grant><Grantee >> xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"; >> xsi:type="CanonicalUser"><ID>0</ID><DisplayName>ocdn</DisplayName></Grantee><Permission>FULL_CONTROL</Permission></Grant></AccessControlList></AccessControlPolicy> >> 2012-09-11 22:37:34.684796 7fafddffb700 2 req 71187:0.007375:s3:PUT >> /ocdn/files/pulscms/MjU7MDA_/ecebacddde95224b96f46333912049b1:put_obj:verifying >> op permissions >> 2012-09-11 22:37:34.684801 7fafddffb700 5 Searching permissions for >> uid=0 mask=2 >> 2012-09-11 22:37:34.684803 7fafddffb700 5 Found permission: 15 >> 2012-09-11 22:37:34.684804 7fafddffb700 10 uid=0 requested perm >> (type)=2, policy perm=2, user_perm_mask=2, acl perm=2 >> 2012-09-11 22:37:34.684808 7fafddffb700 2 req 71187:0.007387:s3:PUT >> /ocdn/files/pulscms/MjU7MDA_/ecebacddde95224b96f46333912049b1:put_obj:verifying >> op params >> 2012-09-11 22:37:34.684811 7fafddffb700 2 req 71187:0.007390:s3:PUT >> /ocdn/files/pulscms/MjU7MDA_/ecebacddde95224b96f46333912049b1:put_obj:executing >> 2012-09-11 22:37:34.684831 7fafddffb700 15 >> supplied_md5_b64=7Ous3d6VIkuW9GMzkSBJsQ== >> 2012-09-11 22:37:34.684834 7fafddffb700 15 ceph_armor ret=16 >> 2012-09-11 22:37:34.684841 7fafddffb700 15 >> supplied_md5=ecebacddde95224b96f46333912049b1 >> 2012-09-11 22:37:34.684901 7fafddffb700 20 get_obj_state: >> rctx=0x7fb00c007050 >> obj=ocdn:files/pulscms/MjU7MDA_/ecebacddde95224b96f46333912049b1 >> state=0x7fb00c00bda8 s->prefetch_data=0 >> 2012-09-11 22:37:34.686278 7fafddffb700 20 >> prepare_atomic_for_write_impl: state is not atomic. >> state=0x7fb00c00bda8 >> 2012-09-11 22:37:34.704899 7fafddffb700 10 --> ETag: "ecebacddde95224b96f46333 >> 2012-09-11 22:37:34.704949 7fafddffb700 10 --> Content-Length: 0 >> 2012-09-11 22:37:34.704954 7fafddffb700 10 --> Accept-Ranges: bytes >> 2012-09-11 22:37:34.704958 7fafddffb700 10 --> Status: 200 >> 2012-09-11 22:37:34.704963 7fafddffb700 10 --> Content-type: application/xml >> 2012-09-11 22:37:34.705099 7fafddffb700 2 req 71187:0.027678:s3:PUT >> /ocdn/files/pulscms/MjU7MDA_/ecebacddde95224b96f46333912049b1:put_obj:http >> status=200 >> 2012-09-11 22:37:34.705454 7fafddffb700 1 ====== req done >> req=0x139a3d0 http_status=200 ====== >> >> >> 2012-09-11 22:37:34.708316 7faec76c6700 20 dequeued request req=0x1368860 >> 2012-09-11 22:37:34.708326 7faec76c6700 20 RGWWQ: empty >> 2012-09-11 22:37:34.708333 7faec76c6700 1 ====== starting new request >> req=0x1368860 ===== >> 2012-09-11 22:37:34.708375 7faec76c6700 2 req 71188:0.000042::::initializing >> 2012-09-11 22:37:34.708402 7faec76c6700 10 >> s->object=files/pulscms/MjU7MDA_/ecebacddde95224b96f46333912049b1 >> s->bucket=ocdn >> 2012-09-11 22:37:34.708408 7faec76c6700 10 meta>> HTTP_X_AMZ_ACL=public-read >> 2012-09-11 22:37:34.708425 7faec76c6700 10 x>> x-amz-acl:public-read >> 2012-09-11 22:37:34.708431 7faec76c6700 20 FCGI_ROLE=RESPONDER >> 2012-09-11 22:37:34.708432 7faec76c6700 20 SCRIPT_FILENAME=/var/www/radosgw.fcgi >> 2012-09-11 22:37:34.708434 7faec76c6700 20 QUERY_STRING=acl >> 2012-09-11 22:37:34.708435 7faec76c6700 20 REQUEST_METHOD=PUT >> 2012-09-11 22:37:34.708437 7faec76c6700 20 CONTENT_TYPE= >> 2012-09-11 22:37:34.708438 7faec76c6700 20 CONTENT_LENGTH=0 >> 2012-09-11 22:37:34.708439 7faec76c6700 20 HTTP_CONTENT_LENGTH=0 >> 2012-09-11 22:37:34.708440 7faec76c6700 20 >> SCRIPT_NAME=/ocdn/files/pulscms/MjU7MDA_/ecebacddde95224b96f46333912049b1 >> 2012-09-11 22:37:34.708441 7faec76c6700 20 >> REQUEST_URI=/ocdn/files/pulscms/MjU7MDA_/ecebacddde95224b96f46333912049b1 >> 2012-09-11 22:37:34.708441 7faec76c6700 20 >> DOCUMENT_URI=/ocdn/files/pulscms/MjU7MDA_/ecebacddde95224b96f46333912049b1 >> 2012-09-11 22:37:34.708442 7faec76c6700 20 DOCUMENT_ROOT=/var/www >> 2012-09-11 22:37:34.708443 7faec76c6700 20 SERVER_PROTOCOL=HTTP/1.1 >> 2012-09-11 22:37:34.708444 7faec76c6700 20 GATEWAY_INTERFACE=CGI/1.1 >> 2012-09-11 22:37:34.708446 7faec76c6700 20 SERVER_SOFTWARE=nginx/1.2.0 >> 2012-09-11 22:37:34.708447 7faec76c6700 20 REMOTE_ADDR=10.174.53.77 >> 2012-09-11 22:37:34.708447 7faec76c6700 20 REMOTE_PORT=48588 >> 2012-09-11 22:37:34.708448 7faec76c6700 20 SERVER_ADDR=10.177.0.3 >> 2012-09-11 22:37:34.708450 7faec76c6700 20 SERVER_PORT=80 >> 2012-09-11 22:37:34.708451 7faec76c6700 20 SERVER_NAME= >> 2012-09-11 22:37:34.708452 7faec76c6700 20 REDIRECT_STATUS=200 >> 2012-09-11 22:37:34.708453 7faec76c6700 20 RGW_SHOULD_LOG=no >> 2012-09-11 22:37:34.708454 7faec76c6700 20 HTTP_HOST=10.177.0.3 >> 2012-09-11 22:37:34.708455 7faec76c6700 20 HTTP_ACCEPT_ENCODING=identity >> 2012-09-11 22:37:34.708456 7faec76c6700 20 HTTP_DATE=Tue, 11 Sep 2012 >> 20:37:46 GMT >> 2012-09-11 22:37:34.708457 7faec76c6700 20 HTTP_X_AMZ_ACL=public-read >> 2012-09-11 22:37:34.708458 7faec76c6700 20 HTTP_AUTHORIZATION=AWS >> 73VF66Q2JH5PT5K7QJ3A:xHPA2K5QvuehAvKH9WdOvf+ZKzE= >> 2012-09-11 22:37:34.708458 7faec76c6700 20 HTTP_USER_AGENT=Boto/2.5.1 (linux2) >> 2012-09-11 22:37:34.708462 7faec76c6700 2 req 71188:0.000129:s3:PUT >> /ocdn/files/pulscms/MjU7MDA_/ecebacddde95224b96f46333912049b1::getting >> op >> 2012-09-11 22:37:34.708467 7faec76c6700 2 req 71188:0.000134:s3:PUT >> /ocdn/files/pulscms/MjU7MDA_/ecebacddde95224b96f46333912049b1:put_obj:authorizing >> 2012-09-11 22:37:34.708486 7faec76c6700 20 get_obj_state: >> rctx=0x7fb2a4007e60 obj=.users:73VF66Q2JH5PT5K7QJ3A >> state=0x7fb2a4007f18 s->prefetch_data=0 >> 2012-09-11 22:37:34.709812 7faec76c6700 20 get_obj_state: s->obj_tag >> was set empty >> 2012-09-11 22:37:34.709828 7faec76c6700 20 get_obj_state: >> rctx=0x7fb2a4007e60 obj=.users:73VF66Q2JH5PT5K7QJ3A >> state=0x7fb2a4007f18 s->prefetch_data=0 >> 2012-09-11 22:37:34.711091 7faec76c6700 20 get_obj_state: s->obj_tag >> was set empty >> 2012-09-11 22:37:34.711101 7faec76c6700 20 get_obj_state: >> rctx=0x7fb2a4007e60 obj=.users:73VF66Q2JH5PT5K7QJ3A >> state=0x7fb2a4007f18 s->prefetch_data=0 >> 2012-09-11 22:37:34.711108 7faec76c6700 20 state for >> obj=.users:73VF66Q2JH5PT5K7QJ3A is not atomic, not appending atomic >> test >> 2012-09-11 22:37:34.711111 7faec76c6700 20 rados->read obj-ofs=0 >> read_ofs=0 read_len=16384 >> 2012-09-11 22:37:34.712485 7faec76c6700 20 rados->read r=0 bl.length=231 >> 2012-09-11 22:37:34.712655 7faec76c6700 10 get_canon_resource(): >> dest=/ocdn/files/pulscms/MjU7MDA_/ecebacddde95224b96f46333912049b1 >> 2012-09-11 22:37:34.712659 7faec76c6700 10 auth_hdr: > > and here also > >> 2012-09-11 22:37:34.712735 7faec76c6700 15 b64=7pIUzzJaX/EyTV89LMXwcqvS06w= >> 2012-09-11 22:37:34.712742 7faec76c6700 15 >> auth_sign=xHPA2K5QvuehAvKH9WdOvf+ZKzE= >> 2012-09-11 22:37:34.712744 7faec76c6700 15 compare=65 >> 2012-09-11 22:37:34.712747 7faec76c6700 10 failed to authorize request >> 2012-09-11 22:37:34.712754 7faec76c6700 10 --> Status: 403 >> 2012-09-11 22:37:34.712766 7faec76c6700 10 --> Content-Length: 78 >> 2012-09-11 22:37:34.712769 7faec76c6700 10 --> Accept-Ranges: bytes >> 2012-09-11 22:37:34.712772 7faec76c6700 10 --> Content-type: application/xml >> 2012-09-11 22:37:34.712887 7faec76c6700 2 req 71188:0.004554:s3:PUT >> /ocdn/files/pulscms/MjU7MDA_/ecebacddde95224b96f46333912049b1:put_obj:http >> status=403 >> 2012-09-11 22:37:34.713093 7faec76c6700 1 ====== req done >> req=0x1368860 http_status=403 ====== >> >> On Tue, Sep 11, 2012 at 7:46 PM, Sławomir Skowron <szibis@xxxxxxxxx> wrote: >>> On Tue, Sep 11, 2012 at 6:48 PM, Yehuda Sadeh <yehuda@xxxxxxxxxxx> wrote: >>>> On Tue, Sep 11, 2012 at 9:45 AM, Yehuda Sadeh <yehuda@xxxxxxxxxxx> wrote: >>>>> On Tue, Sep 11, 2012 at 7:28 AM, Sławomir Skowron <szibis@xxxxxxxxx> wrote: >>>>>> Every acl operation ending with 403 in PUT. >>>>>> >>>>>> ~# s3 -u test oc >>>>>> Bucket Status >>>>>> -------------------------------------------------------- -------------------- >>>>>> oc Access Denied >>>>>> >>>>>> Anyone know why, and how to enable this bucket ?? Now i have problems >>>>>> with cluster, because there is no way to upload new file >>>>>> >>>>>> ~# s3 -u getacl oc >>>>>> >>>>>> ERROR: ErrorAccessDenied >>>>>> >>>>> >>>>> User somehow lost bucket ownership (was it actually the owner?). Do >>>>> you know how to reproduce the issue? any remaining logs? >>>>> >>>>> Try getting bucket info: >>>>> >>>>> # radosgw-admin bucket stats --bucket=oc >>>>> >>>>> If that doesn't fail and actually shows relevant info, try checking >>>>> whether the user credentials match the s3 tool credentials. >>>>> >>>> Oh, and thinking about it some more.. 'oc' is a too short name for a >>>> bucket (requires min of 3 chars). How did you create it? The failure >>>> may be related. >>> >>> Yes i made a shortcut of name :)) >>> >>> Right now every bucket in pool, are afected >>> >>> :~#radosgw-admin bucket stats --bucket=lvstest >>> { "bucket": "lvstest", >>> "pool": ".rgw.buckets", >>> "id": "1142048.1", >>> "marker": "1142048.1", >>> "owner": "0", >>> "usage": { "rgw.main": { "size_kb": 1, >>> "size_kb_actual": 4, >>> "num_objects": 1}}} >>> :~# radosgw-admin bucket stats --bucket=ocdn >>> { "bucket": "ocdn", >>> "pool": ".rgw.buckets", >>> "id": "4168.2", >>> "marker": "4168.2", >>> "owner": "0", >>> "usage": { "rgw.main": { "size_kb": 513059717, >>> "size_kb_actual": 516402364, >>> "num_objects": 1606730}}} >>> >>> Credentials from radosgw-admin user info match that from clients requests. >>> >>> Every GET, PUT, HEAD using this credentials works fine, but only one >>> operations does not work (403 from radosgw) - setting acl for object >>> for a public-read. Setting canned acl with PUT for public-read from >>> s3lib work good, but get/set acl failed. >>> >>> list bucket object works good, and list buckets via s3 client. >>> >>> Now i can't reproduce, but i will dig logs from radosgw, for related >>> time, when this happend. >>> >>> Example 403 from radosgw log, before that PUT of object ends with 200: >>> >>> 2012-09-11 19:36:34.346312 7fb25d7fa700 1 ====== req done >>> req=0x1435980 http_status=403 ====== >>> 2012-09-11 19:37:04.342894 7fb25d7fa700 20 dequeued request req=0x13994c0 >>> 2012-09-11 19:37:04.342903 7fb25d7fa700 20 RGWWQ: empty >>> 2012-09-11 19:37:04.342910 7fb25d7fa700 1 ====== starting new request >>> req=0x13994c0 ===== >>> 2012-09-11 19:37:04.342948 7fb25d7fa700 2 req 39665:0.000038::::initializing >>> 2012-09-11 19:37:04.342971 7fb25d7fa700 10 >>> s->object=images/pulscms/ZjM7MDA_/d6d6df3de5afa365d0fb7379fdbd75b8.jpg >>> s->bucket=ocdn >>> 2012-09-11 19:37:04.342983 7fb25d7fa700 10 meta>> HTTP_X_AMZ_ACL=public-read >>> 2012-09-11 19:37:04.342991 7fb25d7fa700 10 x>> x-amz-acl:public-read >>> 2012-09-11 19:37:04.342996 7fb25d7fa700 20 FCGI_ROLE=RESPONDER >>> 2012-09-11 19:37:04.342997 7fb25d7fa700 20 SCRIPT_FILENAME=/var/www/radosgw.fcgi >>> 2012-09-11 19:37:04.342999 7fb25d7fa700 20 QUERY_STRING=acl >>> 2012-09-11 19:37:04.343001 7fb25d7fa700 20 REQUEST_METHOD=PUT >>> 2012-09-11 19:37:04.343002 7fb25d7fa700 20 CONTENT_TYPE= >>> 2012-09-11 19:37:04.343003 7fb25d7fa700 20 CONTENT_LENGTH=0 >>> 2012-09-11 19:37:04.343004 7fb25d7fa700 20 HTTP_CONTENT_LENGTH=0 >>> 2012-09-11 19:37:04.343005 7fb25d7fa700 20 >>> SCRIPT_NAME=/ocdn/images/pulscms/ZjM7MDA_/d6d6df3de5afa365d0fb7379fdbd75b8.jpg >>> 2012-09-11 19:37:04.343006 7fb25d7fa700 20 >>> REQUEST_URI=/ocdn/images/pulscms/ZjM7MDA_/d6d6df3de5afa365d0fb7379fdbd75b8.jpg >>> 2012-09-11 19:37:04.343007 7fb25d7fa700 20 >>> DOCUMENT_URI=/ocdn/images/pulscms/ZjM7MDA_/d6d6df3de5afa365d0fb7379fdbd75b8.jpg >>> 2012-09-11 19:37:04.343008 7fb25d7fa700 20 DOCUMENT_ROOT=/var/www >>> 2012-09-11 19:37:04.343009 7fb25d7fa700 20 SERVER_PROTOCOL=HTTP/1.1 >>> 2012-09-11 19:37:04.343010 7fb25d7fa700 20 GATEWAY_INTERFACE=CGI/1.1 >>> 2012-09-11 19:37:04.343011 7fb25d7fa700 20 SERVER_SOFTWARE=nginx/1.2.0 >>> 2012-09-11 19:37:04.343012 7fb25d7fa700 20 REMOTE_ADDR=10.177.62.9 >>> 2012-09-11 19:37:04.343013 7fb25d7fa700 20 REMOTE_PORT=56378 >>> 2012-09-11 19:37:04.343014 7fb25d7fa700 20 SERVER_ADDR=10.177.0.3 >>> 2012-09-11 19:37:04.343015 7fb25d7fa700 20 SERVER_PORT=80 >>> 2012-09-11 19:37:04.343016 7fb25d7fa700 20 SERVER_NAME= >>> 2012-09-11 19:37:04.343017 7fb25d7fa700 20 REDIRECT_STATUS=200 >>> 2012-09-11 19:37:04.343018 7fb25d7fa700 20 RGW_SHOULD_LOG=no >>> 2012-09-11 19:37:04.343019 7fb25d7fa700 20 HTTP_HOST=10.177.0.3 >>> 2012-09-11 19:37:04.343020 7fb25d7fa700 20 HTTP_ACCEPT_ENCODING=identity >>> 2012-09-11 19:37:04.343021 7fb25d7fa700 20 HTTP_DATE=Tue, 11 Sep 2012 >>> 17:37:02 GMT >>> 2012-09-11 19:37:04.343022 7fb25d7fa700 20 HTTP_X_AMZ_ACL=public-read >>> 2012-09-11 19:37:04.343023 7fb25d7fa700 20 HTTP_AUTHORIZATION=AWS >>> 73VF66Q2JH5PT5K7QJ3A:mh7yBIFGPtdI1MAjW39/1ywV580= >>> 2012-09-11 19:37:04.343024 7fb25d7fa700 20 HTTP_USER_AGENT=Boto/2.5.2 (linux2) >>> 2012-09-11 19:37:04.343026 7fb25d7fa700 2 req 39665:0.000116:s3:PUT >>> /ocdn/images/pulscms/ZjM7MDA_/d6d6df3de5afa365d0fb7379fdbd75b8.jpg::getting >>> op >>> 2012-09-11 19:37:04.343031 7fb25d7fa700 2 req 39665:0.000121:s3:PUT >>> /ocdn/images/pulscms/ZjM7MDA_/d6d6df3de5afa365d0fb7379fdbd75b8.jpg:put_obj:authorizing >>> 2012-09-11 19:37:04.343047 7fb25d7fa700 20 get_obj_state: >>> rctx=0x7fb23c006340 obj=.users:73VF66Q2JH5PT5K7QJ3A >>> state=0x7fb23c00b468 s->prefetch_data=0 >>> 2012-09-11 19:37:04.344527 7fb25d7fa700 20 get_obj_state: s->obj_tag >>> was set empty >>> 2012-09-11 19:37:04.344542 7fb25d7fa700 20 get_obj_state: >>> rctx=0x7fb23c006340 obj=.users:73VF66Q2JH5PT5K7QJ3A >>> state=0x7fb23c00b468 s->prefetch_data=0 >>> 2012-09-11 19:37:04.345847 7fb25d7fa700 20 get_obj_state: s->obj_tag >>> was set empty >>> 2012-09-11 19:37:04.345858 7fb25d7fa700 20 get_obj_state: >>> rctx=0x7fb23c006340 obj=.users:73VF66Q2JH5PT5K7QJ3A >>> state=0x7fb23c00b468 s->prefetch_data=0 >>> 2012-09-11 19:37:04.345863 7fb25d7fa700 20 state for >>> obj=.users:73VF66Q2JH5PT5K7QJ3A is not atomic, not appending atomic >>> test >>> 2012-09-11 19:37:04.345866 7fb25d7fa700 20 rados->read obj-ofs=0 >>> read_ofs=0 read_len=16384 >>> 2012-09-11 19:37:04.347069 7fb25d7fa700 20 rados->read r=0 bl.length=231 >>> 2012-09-11 19:37:04.347121 7fb25d7fa700 10 get_canon_resource(): >>> dest=/ocdn/images/pulscms/ZjM7MDA_/d6d6df3de5afa365d0fb7379fdbd75b8.jpg >>> 2012-09-11 19:37:04.347126 7fb25d7fa700 10 auth_hdr: >>> 2012-09-11 19:37:04.347195 7fb25d7fa700 15 b64=9qJQCGmPbTXcT6a4qD3kED0PPdY= >>> 2012-09-11 19:37:04.347198 7fb25d7fa700 15 >>> auth_sign=mh7yBIFGPtdI1MAjW39/1ywV580= >>> 2012-09-11 19:37:04.347199 7fb25d7fa700 15 compare=52 >>> 2012-09-11 19:37:04.347201 7fb25d7fa700 10 failed to authorize request >>> 2012-09-11 19:37:04.347208 7fb25d7fa700 10 --> Status: 403 >>> 2012-09-11 19:37:04.347218 7fb25d7fa700 10 --> Content-Length: 78 >>> 2012-09-11 19:37:04.347220 7fb25d7fa700 10 --> Accept-Ranges: bytes >>> 2012-09-11 19:37:04.347223 7fb25d7fa700 10 --> Content-type: application/xml >>> 2012-09-11 19:37:04.347346 7fb25d7fa700 2 req 39665:0.004436:s3:PUT >>> /ocdn/images/pulscms/ZjM7MDA_/d6d6df3de5afa365d0fb7379fdbd75b8.jpg:put_obj:http >>> status=403 >>> 2012-09-11 19:37:04.347600 7fb25d7fa700 1 ====== req done >>> req=0x13994c0 http_status=403 ====== >>> 2012-09-11 19:40:04.354709 7fb25d7fa700 20 dequeued request req=0x13994c0 >>> >>> Interesting is that second cluster, which is replicated via s3 client, >>> get the same issue, from that in production one. Is this can be >>> generated by many error on radosgw layer ?? >>> >>> I will try to find beginning of this problems in logs. >>> >>>> >>>> Yehuda >>> >>> >>> >>> -- >>> ----- >>> Pozdrawiam >>> >>> Sławek "sZiBis" Skowron >> >> >> >> -- >> ----- >> Pozdrawiam >> >> Sławek "sZiBis" Skowron -- To unsubscribe from this list: send the line "unsubscribe ceph-devel" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
