gistfile1.txt

2013-09-18 02:12:13.363556 7fddedfdb700  2 req 5077:0.000334:s3:POST /adsasdasdfsworking/multi:complete_multipart:verifying op params
2013-09-18 02:12:13.363558 7fddedfdb700  2 req 5077:0.000336:s3:POST /adsasdasdfsworking/multi:complete_multipart:executing
2013-09-18 02:12:13.363773 7fddedfdb700 20 get_obj_state: rctx=0x153d3c0 obj=adsasdasdfsworking:_multipart_multi.a_qFC2wNtgQmnrwZ2yySPuZtK-qHCx0.meta state=0x15775f8 s->prefetch_data=0
2013-09-18 02:12:13.365045 7fddedfdb700 20 get_obj_state: s->obj_tag was set empty
2013-09-18 02:12:13.365060 7fddedfdb700 20 Read xattr: user.rgw.acl
2013-09-18 02:12:13.365063 7fddedfdb700 20 Read xattr: user.rgw.content_type
2013-09-18 02:12:13.365064 7fddedfdb700 20 Read xattr: user.rgw.idtag
2013-09-18 02:12:13.365068 7fddedfdb700 20 Read xattr: user.rgw.manifest
2013-09-18 02:12:13.369435 7fddedfdb700 10 calculated etag: 03b0f4c6f422f7ac253ceb7f0de54e3d-50
2013-09-18 02:12:13.369989 7fddedfdb700 20 get_obj_state: rctx=0x153d3c0 obj=adsasdasdfsworking:multi state=0x1667808 s->prefetch_data=0
2013-09-18 02:12:13.371641 7fddedfdb700  0 setting object write_tag=default.31863.5077
2013-09-18 02:12:13.398451 7fddedfdb700  0 WARNING: set_req_state_err err_no=27 resorting to 500
2013-09-18 02:12:13.398482 7fddedfdb700  2 req 5077:0.035259:s3:POST /adsasdasdfsworking/multi:complete_multipart:http status=500
2013-09-18 02:12:13.398536 7fddedfdb700  1 ====== req done req=0x1546c20 http_status=500 ======
2013-09-18 02:12:13.401533 7fde635547c0 20 enqueued request req=0x14f0d50
2013-09-18 02:12:13.401541 7fde635547c0 20 RGWWQ:
2013-09-18 02:12:13.401542 7fde635547c0 20 req: 0x14f0d50
2013-09-18 02:12:13.401545 7fde635547c0 10 allocated request req=0x14f0790
2013-09-18 02:12:13.401598 7fdde4fc9700 20 dequeued request req=0x14f0d50
2013-09-18 02:12:13.401610 7fdde4fc9700 20 RGWWQ: empty
2013-09-18 02:12:13.401616 7fdde4fc9700  1 ====== starting new request req=0x14f0d50 =====
2013-09-18 02:12:13.401680 7fdde4fc9700  2 req 5078:0.000064::DELETE /adsasdasdfsworking/multi::initializing
2013-09-18 02:12:13.401718 7fdde4fc9700 10 s->object=multi s->bucket=adsasdasdfsworking
2013-09-18 02:12:13.401725 7fdde4fc9700 20 FCGI_ROLE=RESPONDER
2013-09-18 02:12:13.401726 7fdde4fc9700 20 SCRIPT_URL=/adsasdasdfsworking/multi
2013-09-18 02:12:13.401727 7fdde4fc9700 20 SCRIPT_URI=http://ap-r310-6.int/adsasdasdfsworking/multi
2013-09-18 02:12:13.401728 7fdde4fc9700 20 HTTP_AUTHORIZATION=AWS Y95JKM91327A4GKTAW1Z:xh/tYLJQzeOOOGGQyoq/uJVE8ks=
2013-09-18 02:12:13.401729 7fdde4fc9700 20 CONTENT_TYPE=
2013-09-18 02:12:13.401730 7fdde4fc9700 20 HTTP_ACCEPT_ENCODING=
2013-09-18 02:12:13.401731 7fdde4fc9700 20 HTTP_USER_AGENT=aws-sdk-ruby/1.18.0 ruby/1.9.3 x86_64-linux
2013-09-18 02:12:13.401732 7fdde4fc9700 20 HTTP_DATE=Wed, 18 Sep 2013 01:12:13 GMT
2013-09-18 02:12:13.401734 7fdde4fc9700 20 HTTP_ACCEPT=*/*
2013-09-18 02:12:13.401735 7fdde4fc9700 20 HTTP_HOST=ap-r310-6.int
2013-09-18 02:12:13.401736 7fdde4fc9700 20 PATH=/usr/local/bin:/usr/bin:/bin
2013-09-18 02:12:13.401737 7fdde4fc9700 20 SERVER_SIGNATURE=
2013-09-18 02:12:13.401738 7fdde4fc9700 20 SERVER_SOFTWARE=Apache/2.2.22 (Ubuntu)
2013-09-18 02:12:13.401739 7fdde4fc9700 20 SERVER_NAME=ap-r310-6.int
2013-09-18 02:12:13.401740 7fdde4fc9700 20 SERVER_ADDR=192.168.100.6
2013-09-18 02:12:13.401741 7fdde4fc9700 20 SERVER_PORT=80
2013-09-18 02:12:13.401742 7fdde4fc9700 20 REMOTE_ADDR=192.168.100.9
2013-09-18 02:12:13.401743 7fdde4fc9700 20 DOCUMENT_ROOT=/var/www
2013-09-18 02:12:13.401743 7fdde4fc9700 20 SERVER_ADMIN=[no address given]
2013-09-18 02:12:13.401744 7fdde4fc9700 20 SCRIPT_FILENAME=/var/www/s3gw.fcgi
2013-09-18 02:12:13.401745 7fdde4fc9700 20 REMOTE_PORT=55611
2013-09-18 02:12:13.401746 7fdde4fc9700 20 GATEWAY_INTERFACE=CGI/1.1
2013-09-18 02:12:13.401747 7fdde4fc9700 20 SERVER_PROTOCOL=HTTP/1.1
2013-09-18 02:12:13.401749 7fdde4fc9700 20 REQUEST_METHOD=DELETE
2013-09-18 02:12:13.401750 7fdde4fc9700 20 QUERY_STRING=page=adsasdasdfsworking&params=/multi&uploadId=a_qFC2wNtgQmnrwZ2yySPuZtK-qHCx0
2013-09-18 02:12:13.401752 7fdde4fc9700 20 REQUEST_URI=/adsasdasdfsworking/multi?uploadId=a_qFC2wNtgQmnrwZ2yySPuZtK-qHCx0
2013-09-18 02:12:13.401753 7fdde4fc9700 20 SCRIPT_NAME=/adsasdasdfsworking/multi
2013-09-18 02:12:13.401755 7fdde4fc9700  2 req 5078:0.000138:s3:DELETE /adsasdasdfsworking/multi::getting op
2013-09-18 02:12:13.401759 7fdde4fc9700  2 req 5078:0.000143:s3:DELETE /adsasdasdfsworking/multi:abort_multipart:authorizing
2013-09-18 02:12:13.401776 7fdde4fc9700 20 get_obj_state: rctx=0x7fdd60006780 obj=.users:Y95JKM91327A4GKTAW1Z state=0x7fdd6000c0c8 s->prefetch_data=0
2013-09-18 02:12:13.401798 7fdde4fc9700 10 moving .users+Y95JKM91327A4GKTAW1Z to cache LRU end
2013-09-18 02:12:13.401801 7fdde4fc9700 10 cache get: name=.users+Y95JKM91327A4GKTAW1Z : hit
2013-09-18 02:12:13.401808 7fdde4fc9700 20 get_obj_state: s->obj_tag was set empty
2013-09-18 02:12:13.401813 7fdde4fc9700 10 moving .users+Y95JKM91327A4GKTAW1Z to cache LRU end
2013-09-18 02:12:13.401814 7fdde4fc9700 10 cache get: name=.users+Y95JKM91327A4GKTAW1Z : hit
2013-09-18 02:12:13.401823 7fdde4fc9700 20 get_obj_state: rctx=0x7fdd60006780 obj=.users.uid:joh state=0x7fdd60011088 s->prefetch_data=0
2013-09-18 02:12:13.401828 7fdde4fc9700 10 moving .users.uid+joh to cache LRU end
2013-09-18 02:12:13.401830 7fdde4fc9700 10 cache get: name=.users.uid+joh : hit
2013-09-18 02:12:13.401832 7fdde4fc9700 20 get_obj_state: s->obj_tag was set empty
2013-09-18 02:12:13.401835 7fdde4fc9700 10 moving .users.uid+joh to cache LRU end
2013-09-18 02:12:13.401836 7fdde4fc9700 10 cache get: name=.users.uid+joh : hit
2013-09-18 02:12:13.401860 7fdde4fc9700 10 get_canon_resource(): dest=
2013-09-18 02:12:13.401861 7fdde4fc9700 10 auth_hdr:
DELETE


Wed, 18 Sep 2013 01:12:13 GMT
/adsasdasdfsworking/multi?uploadId=a_qFC2wNtgQmnrwZ2yySPuZtK-qHCx0
2013-09-18 02:12:13.401891 7fdde4fc9700 15 calculated digest=xh/tYLJQzeOOOGGQyoq/uJVE8ks=
2013-09-18 02:12:13.401892 7fdde4fc9700 15 auth_sign=xh/tYLJQzeOOOGGQyoq/uJVE8ks=
2013-09-18 02:12:13.401893 7fdde4fc9700 15 compare=0
2013-09-18 02:12:13.401895 7fdde4fc9700  2 req 5078:0.000279:s3:DELETE /adsasdasdfsworking/multi:abort_multipart:reading permissions
2013-09-18 02:12:13.401904 7fdde4fc9700 20 get_obj_state: rctx=0x7fdd600064b0 obj=.rgw:adsasdasdfsworking state=0x7fdd6000e4a8 s->prefetch_data=0
2013-09-18 02:12:13.401911 7fdde4fc9700 10 moving .rgw+adsasdasdfsworking to cache LRU end
2013-09-18 02:12:13.401912 7fdde4fc9700 10 cache get: name=.rgw+adsasdasdfsworking : hit
2013-09-18 02:12:13.401914 7fdde4fc9700 20 get_obj_state: s->obj_tag was set empty
2013-09-18 02:12:13.401916 7fdde4fc9700 20 Read xattr: user.rgw.idtag
2013-09-18 02:12:13.401916 7fdde4fc9700 20 Read xattr: user.rgw.manifest
2013-09-18 02:12:13.401919 7fdde4fc9700 10 moving .rgw+adsasdasdfsworking to cache LRU end
2013-09-18 02:12:13.401920 7fdde4fc9700 10 cache get: name=.rgw+adsasdasdfsworking : hit
2013-09-18 02:12:13.401926 7fdde4fc9700 20 rgw_get_bucket_info: bucket instance: adsasdasdfsworking(@{i=.rgw.buckets.index}.rgw.buckets[default.31863.82])
2013-09-18 02:12:13.401930 7fdde4fc9700 20 reading from .rgw:.bucket.meta.adsasdasdfsworking:default.31863.82
2013-09-18 02:12:13.401934 7fdde4fc9700 20 get_obj_state: rctx=0x7fdd600064b0 obj=.rgw:.bucket.meta.adsasdasdfsworking:default.31863.82 state=0x7fdd6000f538 s->prefetch_data=0
2013-09-18 02:12:13.401940 7fdde4fc9700 10 moving .rgw+.bucket.meta.adsasdasdfsworking:default.31863.82 to cache LRU end
2013-09-18 02:12:13.401941 7fdde4fc9700 10 cache get: name=.rgw+.bucket.meta.adsasdasdfsworking:default.31863.82 : hit
2013-09-18 02:12:13.401944 7fdde4fc9700 20 get_obj_state: s->obj_tag was set empty
2013-09-18 02:12:13.401945 7fdde4fc9700 20 Read xattr: user.rgw.acl
2013-09-18 02:12:13.401946 7fdde4fc9700 20 Read xattr: user.rgw.idtag
2013-09-18 02:12:13.401946 7fdde4fc9700 20 Read xattr: user.rgw.manifest
2013-09-18 02:12:13.401949 7fdde4fc9700 10 moving .rgw+.bucket.meta.adsasdasdfsworking:default.31863.82 to cache LRU end
2013-09-18 02:12:13.401950 7fdde4fc9700 10 cache get: name=.rgw+.bucket.meta.adsasdasdfsworking:default.31863.82 : hit
2013-09-18 02:12:13.401961 7fdde4fc9700 15 Read AccessControlPolicy<AccessControlPolicy xmlns="http://s3.amazonaws.com/doc/2006-03-01/"><Owner><ID>joh</ID><DisplayName>Joh</DisplayName></Owner><AccessControlList><Grant><Grantee xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="CanonicalUser"><ID>joh</ID><DisplayName>Joh</DisplayName></Grantee><Permission>FULL_CONTROL</Permission></Grant></AccessControlList></AccessControlPolicy>
2013-09-18 02:12:13.401966 7fdde4fc9700  2 req 5078:0.000350:s3:DELETE /adsasdasdfsworking/multi:abort_multipart:verifying op mask
2013-09-18 02:12:13.401969 7fdde4fc9700 20 required_mask= 4 user.op_mask=7
2013-09-18 02:12:13.401969 7fdde4fc9700  2 req 5078:0.000353:s3:DELETE /adsasdasdfsworking/multi:abort_multipart:verifying op permissions
2013-09-18 02:12:13.401971 7fdde4fc9700  5 Searching permissions for uid=joh mask=50
2013-09-18 02:12:13.401972 7fdde4fc9700  5 Found permission: 15
2013-09-18 02:12:13.401973 7fdde4fc9700  5 Searching permissions for group=1 mask=50
2013-09-18 02:12:13.401974 7fdde4fc9700  5 Permissions for group not found
2013-09-18 02:12:13.401974 7fdde4fc9700  5 Getting permissions id=joh owner=joh perm=2
2013-09-18 02:12:13.401975 7fdde4fc9700 10  uid=joh requested perm (type)=2, policy perm=2, user_perm_mask=2, acl perm=2
2013-09-18 02:12:13.401976 7fdde4fc9700  2 req 5078:0.000360:s3:DELETE /adsasdasdfsworking/multi:abort_multipart:verifying op params
2013-09-18 02:12:13.401978 7fdde4fc9700  2 req 5078:0.000362:s3:DELETE /adsasdasdfsworking/multi:abort_multipart:executing
2013-09-18 02:12:13.401986 7fdde4fc9700 20 get_obj_state: rctx=0x7fdd600064b0 obj=adsasdasdfsworking:_multipart_multi.a_qFC2wNtgQmnrwZ2yySPuZtK-qHCx0.meta state=0x7fdd60007778 s->prefetch_data=0
2013-09-18 02:12:13.402678 7fdde4fc9700 20 get_obj_state: s->obj_tag was set empty
2013-09-18 02:12:13.402683 7fdde4fc9700 20 Read xattr: user.rgw.acl
2013-09-18 02:12:13.402683 7fdde4fc9700 20 Read xattr: user.rgw.content_type
2013-09-18 02:12:13.402684 7fdde4fc9700 20 Read xattr: user.rgw.idtag
2013-09-18 02:12:13.402685 7fdde4fc9700 20 Read xattr: user.rgw.manifest
2013-09-18 02:12:13.406670 7fdde4fc9700 20 get_obj_state: rctx=0x7fdd600064b0 obj=adsasdasdfsworking:_multipart_multi.a_qFC2wNtgQmnrwZ2yySPuZtK-qHCx0.1 state=0x7fdd600c9528 s->prefetch_data=0
2013-09-18 02:12:13.408315 7fdde4fc9700 20 get_obj_state: s->obj_tag was set empty
2013-09-18 02:12:13.408327 7fdde4fc9700 20 prepare_atomic_for_write_impl: state is not atomic. state=0x7fdd600c9528
2013-09-18 02:12:13.449794 7fdde4fc9700 20 get_obj_state: rctx=0x7fdd600064b0 obj=adsasdasdfsworking:_shadow_multi.a_qFC2wNtgQmnrwZ2yySPuZtK-qHCx0.1_1 state=0x7fdd600cade8 s->prefetch_data=0
2013-09-18 02:12:13.451265 7fdde4fc9700 20 get_obj_state: s->obj_tag was set empty
2013-09-18 02:12:13.451281 7fdde4fc9700 20 prepare_atomic_for_write_impl: state is not atomic. state=0x7fdd600cade8
2013-09-18 02:12:13.489969 7fdde4fc9700 20 get_obj_state: rctx=0x7fdd600064b0 obj=adsasdasdfsworking:_shadow_multi.a_qFC2wNtgQmnrwZ2yySPuZtK-qHCx0.1_2 state=0x7fdd600ce908 s->prefetch_data=0
2013-09-18 02:12:13.491162 7fdde4fc9700 20 get_obj_state: s->obj_tag was set empty
2013-09-18 02:12:13.491174 7fdde4fc9700 20 prepare_atomic_for_write_impl: state is not atomic. state=0x7fdd600ce908
2013-09-18 02:12:13.505232 7fdde4fc9700 20 get_obj_state: rctx=0x7fdd600064b0 obj=adsasdasdfsworking:_shadow_multi.a_qFC2wNtgQmnrwZ2yySPuZtK-qHCx0.1_3 state=0x7fdd600c9b88 s->prefetch_data=0
2013-09-18 02:12:13.506137 7fdde4fc9700 20 get_obj_state: s->obj_tag was set empty
2013-09-18 02:12:13.506148 7fdde4fc9700 20 prepare_atomic_for_write_impl: state is not atomic. state=0x7fdd600c9b88
2013-09-18 02:12:13.934224 7fdde4fc9700 20 get_obj_state: rctx=0x7fdd600064b0 obj=adsasdasdfsworking:_shadow_multi.a_qFC2wNtgQmnrwZ2yySPuZtK-qHCx0.1_4 state=0x7fdd600cc728 s->prefetch_data=0
2013-09-18 02:12:13.935448 7fdde4fc9700 20 get_obj_state: s->obj_tag was set empty
2013-09-18 02:12:13.935463 7fdde4fc9700 20 prepare_atomic_for_write_impl: state is not atomic. state=0x7fdd600cc728

==> /var/log/ceph/ceph.log <==
2013-09-18 02:12:11.710022 mon.0 192.168.100.6:6789/0 21557 : [INF] pgmap v22825: 6248 pgs: 6248 active+clean; 5768 GB data, 5781 GB used, 83552 GB / 89333 GB avail; 83248B/s rd, 73675KB/s wr, 161op/s
2013-09-18 02:12:12.877613 mon.0 192.168.100.6:6789/0 21558 : [INF] pgmap v22826: 6248 pgs: 6248 active+clean; 5768 GB data, 5781 GB used, 83552 GB / 89333 GB avail; 136KB/s rd, 83131KB/s wr, 184op/s

==> /var/log/ceph/radosgw.log <==
2013-09-18 02:12:14.120786 7fdde4fc9700 20 get_obj_state: rctx=0x7fdd600064b0 obj=adsasdasdfsworking:_shadow_multi.a_qFC2wNtgQmnrwZ2yySPuZtK-qHCx0.1_5 state=0x7fdd600d2338 s->prefetch_data=0
2013-09-18 02:12:14.121964 7fdde4fc9700 20 get_obj_state: s->obj_tag was set empty
2013-09-18 02:12:14.121971 7fdde4fc9700 20 prepare_atomic_for_write_impl: state is not atomic. state=0x7fdd600d2338
2013-09-18 02:12:14.134385 7fdde4fc9700 20 get_obj_state: rctx=0x7fdd600064b0 obj=adsasdasdfsworking:_shadow_multi.a_qFC2wNtgQmnrwZ2yySPuZtK-qHCx0.1_6 state=0x7fdd600d2d48 s->prefetch_data=0
2013-09-18 02:12:14.135655 7fdde4fc9700 20 get_obj_state: s->obj_tag was set empty
2013-09-18 02:12:14.135663 7fdde4fc9700 20 prepare_atomic_for_write_impl: state is not atomic. state=0x7fdd600d2d48
2013-09-18 02:12:14.175855 7fdde4fc9700 20 get_obj_state: rctx=0x7fdd600064b0 obj=adsasdasdfsworking:_shadow_multi.a_qFC2wNtgQmnrwZ2yySPuZtK-qHCx0.1_7 state=0x7fdd600da108 s->prefetch_data=0
2013-09-18 02:12:14.177164 7fdde4fc9700 20 get_obj_state: s->obj_tag was set empty
2013-09-18 02:12:14.177172 7fdde4fc9700 20 prepare_atomic_for_write_impl: state is not atomic. state=0x7fdd600da108
2013-09-18 02:12:14.190772 7fdde4fc9700 20 get_obj_state: rctx=0x7fdd600064b0 obj=adsasdasdfsworking:_shadow_multi.a_qFC2wNtgQmnrwZ2yySPuZtK-qHCx0.1_8 state=0x7fdd600d6088 s->prefetch_data=0
2013-09-18 02:12:14.191561 7fdde4fc9700 20 get_obj_state: s->obj_tag was set empty
2013-09-18 02:12:14.191567 7fdde4fc9700 20 prepare_atomic_for_write_impl: state is not atomic. state=0x7fdd600d6088
2013-09-18 02:12:14.212709 7fdde4fc9700 20 get_obj_state: rctx=0x7fdd600064b0 obj=adsasdasdfsworking:_shadow_multi.a_qFC2wNtgQmnrwZ2yySPuZtK-qHCx0.1_9 state=0x7fdd600de0c8 s->prefetch_data=0
2013-09-18 02:12:14.214268 7fdde4fc9700 20 get_obj_state: s->obj_tag was set empty
2013-09-18 02:12:14.214281 7fdde4fc9700 20 prepare_atomic_for_write_impl: state is not atomic. state=0x7fdd600de0c8
2013-09-18 02:12:14.232979 7fdde4fc9700 20 get_obj_state: rctx=0x7fdd600064b0 obj=adsasdasdfsworking:_shadow_multi.a_qFC2wNtgQmnrwZ2yySPuZtK-qHCx0.1_10 state=0x7fdd600dc088 s->prefetch_data=0
2013-09-18 02:12:14.234444 7fdde4fc9700 20 get_obj_state: s->obj_tag was set empty
2013-09-18 02:12:14.234458 7fdde4fc9700 20 prepare_atomic_for_write_impl: state is not atomic. state=0x7fdd600dc088