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
