On Thu, Nov 20, 2014 at 6:52 PM, Mark Kirkwood
<mark.kirkwood@xxxxxxxxxxxxxxx> wrote:
> On 21/11/14 14:49, Mark Kirkwood wrote:
>>
>>
>> The only things that look odd in the destination zone logs are 383
>> requests getting 404 rather than 200:
>>
>> $ grep "http_status=404" ceph-client.radosgw.us-west-1.log
>> ...
>> 2014-11-21 13:48:58.435201 7ffc4bf7f700 1 ====== req done
>> req=0x7ffca002df00 http_status=404 ======
>> 2014-11-21 13:49:05.891680 7ffc35752700 1 ====== req done
>> req=0x7ffca00301e0 http_status=404 ======
>> ...
>>
>>
>
> Adding in "debug rgw = 20" and redoing the setup again, I see what looks to
> be an http 500 during the data sync:
>
>
> 2014-11-21 15:13:31.886006 7fb5e3f87700 1 ====== starting new request
> req=0x7fb640032580 =====
> 2014-11-21 15:13:31.886025 7fb5e3f87700 2 req 502:0.000020::PUT
> /bucketbig/_multipart_big.dat.2/fjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta::initializing
> 2014-11-21 15:13:31.886034 7fb5e3f87700 10 host=ceph1 rgw_dns_name=ceph1
> 2014-11-21 15:13:31.886054 7fb5e3f87700 10 meta>> HTTP_X_AMZ_COPY_SOURCE
> 2014-11-21 15:13:31.886080 7fb5e3f87700 10 x>>
> x-amz-copy-source:bucketbig/_multipart_big.dat.2/fjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta
> 2014-11-21 15:13:31.886124 7fb5e3f87700 10
> s->object=_multipart_big.dat.2/fjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta
> s->bucket=bucketbig
> 2014-11-21 15:13:31.886166 7fb5e3f87700 2 req 502:0.000160:s3:PUT
> /bucketbig/_multipart_big.dat.2/fjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta::getting
> op
> 2014-11-21 15:13:31.886188 7fb5e3f87700 2 req 502:0.000182:s3:PUT
> /bucketbig/_multipart_big.dat.2/fjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta:copy_obj:authorizing
> 2014-11-21 15:13:31.886232 7fb5e3f87700 10 get_canon_resource():
> dest=/bucketbig/_multipart_big.dat.2/fjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta
> 2014-11-21 15:13:31.886239 7fb5e3f87700 10 auth_hdr:
> PUT
>
> application/json; charset=UTF-8
> Fri, 21 Nov 2014 02:13:31 GMT
> x-amz-copy-source:bucketbig/_multipart_big.dat.2/fjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta
> /bucketbig/_multipart_big.dat.2/fjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta
> 2014-11-21 15:13:31.886271 7fb5e3f87700 15 calculated
> digest=A0wQIVW7UZ5j2GTDqxbHimNEN1o=
> 2014-11-21 15:13:31.886275 7fb5e3f87700 15
> auth_sign=A0wQIVW7UZ5j2GTDqxbHimNEN1o=
> 2014-11-21 15:13:31.886277 7fb5e3f87700 15 compare=0
> 2014-11-21 15:13:31.886281 7fb5e3f87700 20 system request
> 2014-11-21 15:13:31.886289 7fb5e3f87700 2 req 502:0.000283:s3:PUT
> /bucketbig/_multipart_big.dat.2/fjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta:copy_obj:reading
> permissions
> 2014-11-21 15:13:31.886325 7fb5e3f87700 20 get_obj_state:
> rctx=0x7fb5e3f861d0 obj=.us-west.domain.rgw:bucketbig state=0x7fb63c057008
> s->prefetch_data=0
> 2014-11-21 15:13:31.886339 7fb5e3f87700 10 cache get:
> name=.us-west.domain.rgw+bucketbig : type miss (requested=22, cached=19)
> 2014-11-21 15:13:31.887967 7fb5e3f87700 10 cache put:
> name=.us-west.domain.rgw+bucketbig
> 2014-11-21 15:13:31.887985 7fb5e3f87700 10 moving
> .us-west.domain.rgw+bucketbig to cache LRU end
> 2014-11-21 15:13:31.887998 7fb5e3f87700 20 get_obj_state: s->obj_tag was set
> empty
> 2014-11-21 15:13:31.888008 7fb5e3f87700 10 cache get:
> name=.us-west.domain.rgw+bucketbig : hit
> 2014-11-21 15:13:31.888031 7fb5e3f87700 20 rgw_get_bucket_info: bucket
> instance:
> bucketbig(@{i=.us-east.rgw.buckets.index}.us-east.rgw.buckets[us-east.4697.1])
> 2014-11-21 15:13:31.888043 7fb5e3f87700 20 reading from
> .us-west.domain.rgw:.bucket.meta.bucketbig:us-east.4697.1
> 2014-11-21 15:13:31.888059 7fb5e3f87700 20 get_obj_state:
> rctx=0x7fb5e3f861d0
> obj=.us-west.domain.rgw:.bucket.meta.bucketbig:us-east.4697.1
> state=0x7fb63c057bf8 s->prefetch_data=0
> 2014-11-21 15:13:31.888068 7fb5e3f87700 10 cache get:
> name=.us-west.domain.rgw+.bucket.meta.bucketbig:us-east.4697.1 : hit
> 2014-11-21 15:13:31.888075 7fb5e3f87700 20 get_obj_state: s->obj_tag was set
> empty
> 2014-11-21 15:13:31.888078 7fb5e3f87700 20 Read xattr: user.rgw.acl
> 2014-11-21 15:13:31.888080 7fb5e3f87700 20 Read xattr: user.rgw.idtag
> 2014-11-21 15:13:31.888081 7fb5e3f87700 20 Read xattr: user.rgw.manifest
> 2014-11-21 15:13:31.888084 7fb5e3f87700 10 cache get:
> name=.us-west.domain.rgw+.bucket.meta.bucketbig:us-east.4697.1 : hit
> 2014-11-21 15:13:31.888097 7fb5e3f87700 10 chain_cache_entry:
> cache_locator=.us-west.domain.rgw+bucketbig
> 2014-11-21 15:13:31.888099 7fb5e3f87700 10 chain_cache_entry:
> cache_locator=.us-west.domain.rgw+.bucket.meta.bucketbig:us-east.4697.1
> 2014-11-21 15:13:31.888181 7fb5e3f87700 15 Read
> AccessControlPolicy<AccessControlPolicy
> xmlns="http://s3.amazonaws.com/doc/2006-03-01/";><Owner><ID>markir</ID><DisplayName>Mark</DisplayName></Owner><AccessControlList><Grant><Grantee
> xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance";
> xsi:type="CanonicalUser"><ID>markir</ID><DisplayName>Mark</DisplayName></Grantee><Permission>FULL_CONTROL</Permission></Grant></AccessControlList></AccessControlPolicy>
> 2014-11-21 15:13:31.896569 7fb5e3f87700 2 req 502:0.010563:s3:PUT
> /bucketbig/_multipart_big.dat.2/fjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta:copy_obj:init
> op
> 2014-11-21 15:13:31.896579 7fb5e3f87700 2 req 502:0.010573:s3:PUT
> /bucketbig/_multipart_big.dat.2/fjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta:copy_obj:verifying
> op mask
> 2014-11-21 15:13:31.896581 7fb5e3f87700 20 required_mask= 2 user.op_mask=7
> 2014-11-21 15:13:31.896582 7fb5e3f87700 2 req 502:0.010577:s3:PUT
> /bucketbig/_multipart_big.dat.2/fjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta:copy_obj:verifying
> op permissions
> 2014-11-21 15:13:31.896609 7fb5e3f87700 0 WARNING: couldn't find acl header
> for bucket, generating default
> 2014-11-21 15:13:31.896619 7fb5e3f87700 20 get_obj_state:
> rctx=0x7fb63c028420 obj=.us-west.users.uid:markir state=0x7fb63c0284f8
> s->prefetch_data=0
> 2014-11-21 15:13:31.896637 7fb5e3f87700 10 cache get:
> name=.us-west.users.uid+markir : type miss (requested=6, cached=19)
> 2014-11-21 15:13:31.897736 7fb5e3f87700 10 cache put:
> name=.us-west.users.uid+markir
> 2014-11-21 15:13:31.897753 7fb5e3f87700 10 moving .us-west.users.uid+markir
> to cache LRU end
> 2014-11-21 15:13:31.897760 7fb5e3f87700 20 get_obj_state: s->obj_tag was set
> empty
> 2014-11-21 15:13:31.897766 7fb5e3f87700 10 cache get:
> name=.us-west.users.uid+markir : hit
> 2014-11-21 15:13:31.897808 7fb5e3f87700 2 req 502:0.011802:s3:PUT
> /bucketbig/_multipart_big.dat.2/fjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta:copy_obj:verifying
> op params
> 2014-11-21 15:13:31.897814 7fb5e3f87700 2 req 502:0.011808:s3:PUT
> /bucketbig/_multipart_big.dat.2/fjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta:copy_obj:executing
> 2014-11-21 15:13:31.897843 7fb5e3f87700 10 x>>
> x-amz-copy-source:bucketbig/_multipart_big.dat.2/fjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta
> 2014-11-21 15:13:31.897911 7fb5e3f87700 5 Copy object
> bucketbig(@{i=.us-west.rgw.buckets.index}.us-west.rgw.buckets[us-east.4697.1]):__multipart_big.dat.2/fjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta
> =>
> bucketbig(@{i=.us-west.rgw.buckets.index}.us-west.rgw.buckets[us-east.4697.1]):__multipart_big.dat.2/fjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta
> 2014-11-21 15:13:31.914830 7fb5e3f87700 20 RGWEnv::set(): HTTP_DATE: Fri Nov
> 21 02:13:31 2014
> 2014-11-21 15:13:31.914838 7fb5e3f87700 20 RGWEnv::set():
> HTTP_X_AMZ_COPY_SOURCE:
> bucketbig/_multipart_big.dat.2/fjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta
> 2014-11-21 15:13:31.914845 7fb5e3f87700 10 meta>> HTTP_X_AMZ_COPY_SOURCE
> 2014-11-21 15:13:31.914854 7fb5e3f87700 10 x>>
> x-amz-copy-source:bucketbig/_multipart_big.dat.2/fjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta
> 2014-11-21 15:13:31.914868 7fb5e3f87700 0 > HTTP_DATE -> Fri Nov 21
> 02:13:31 2014
> 2014-11-21 15:13:31.914872 7fb5e3f87700 0 > HTTP_X_AMZ_COPY_SOURCE ->
> bucketbig/_multipart_big.dat.2/fjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta
> 2014-11-21 15:13:31.914888 7fb5e3f87700 10 get_canon_resource():
> dest=/bucketbig/__multipart_big.dat.2%2Ffjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta
> 2014-11-21 15:13:31.914892 7fb5e3f87700 10 generated canonical header: GET
>
>
> Fri Nov 21 02:13:31 2014
> x-amz-copy-source:bucketbig/_multipart_big.dat.2/fjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta
> /bucketbig/__multipart_big.dat.2%2Ffjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta
> 2014-11-21 15:13:31.914925 7fb5e3f87700 15 generated auth header: AWS
> us-west key:tk7RgBQMD92je2Nz1m2D/GV+VNM=
> 2014-11-21 15:13:31.914964 7fb5e3f87700 20 sending request to
> http://ceph2:80/bucketbig/__multipart_big.dat.2%2Ffjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta?rgwx-uid=us-west&rgwx-region=us&rgwx-prepend-metadata=us
> 2014-11-21 15:13:31.920510 7fb5e3f87700 10 receive_http_header
> 2014-11-21 15:13:31.920525 7fb5e3f87700 10 received header:HTTP/1.1 411
> Length Required
It looks like you're running the wrong fastcgi module.
Yehuda
> 2014-11-21 15:13:31.920531 7fb5e3f87700 10 receive_http_header
> 2014-11-21 15:13:31.920534 7fb5e3f87700 10 received header:Date: Fri, 21 Nov
> 2014 02:13:31 GMT
> 2014-11-21 15:13:31.920574 7fb5e3f87700 10 receive_http_header
> 2014-11-21 15:13:31.920578 7fb5e3f87700 10 received header:Server:
> Apache/2.4.7 (Ubuntu)
> 2014-11-21 15:13:31.920586 7fb5e3f87700 10 receive_http_header
> 2014-11-21 15:13:31.920588 7fb5e3f87700 10 received header:Content-Length:
> 238
> 2014-11-21 15:13:31.920593 7fb5e3f87700 10 receive_http_header
> 2014-11-21 15:13:31.920594 7fb5e3f87700 10 received header:Connection: close
> 2014-11-21 15:13:31.920597 7fb5e3f87700 10 receive_http_header
> 2014-11-21 15:13:31.920599 7fb5e3f87700 10 received header:Content-Type:
> text/html; charset=iso-8859-1
> 2014-11-21 15:13:31.920602 7fb5e3f87700 10 receive_http_header
> 2014-11-21 15:13:31.920603 7fb5e3f87700 10 received header:
> 2014-11-21 15:13:31.934664 7fb5e3f87700 0 WARNING: set_req_state_err
> err_no=5 resorting to 500
> 2014-11-21 15:13:31.934725 7fb5e3f87700 2 req 502:0.048719:s3:PUT
> /bucketbig/_multipart_big.dat.2/fjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta:copy_obj:http
> status=500
> 2014-11-21 15:13:31.934753 7fb5e3f87700 1 ====== req done
> req=0x7fb640032580 http_status=500 ======
> 2014-11-21 15:13:31.934776 7fb5e3f87700 20 process_request() returned -5
> 2014-11-21 15:13:31.940742 7fb5f87b0700 20 enqueued request
> req=0x7fb6400390d0
> 2014-11-21 15:13:31.940785 7fb5f87b0700 20 RGWWQ:
> 2014-11-21 15:13:31.940788 7fb5f87b0700 20 req: 0x7fb6400390d0
> 2014-11-21 15:13:31.940812 7fb5f87b0700 10 allocated request
> req=0x7fb64007a8c0
> 2014-11-21 15:13:31.940851 7fb5eaf95700 20 dequeued request
> req=0x7fb6400390d0
> 2014-11-21 15:13:31.940866 7fb5eaf95700 20 RGWWQ: empty
> 2014-11-21 15:13:31.940956 7fb5eaf95700 20 CONTENT_LENGTH=0
> 2014-11-21 15:13:31.940968 7fb5eaf95700 20 CONTEXT_DOCUMENT_ROOT=/var/www
> 2014-11-21 15:13:31.940970 7fb5eaf95700 20 CONTEXT_PREFIX=
> 2014-11-21 15:13:31.940972 7fb5eaf95700 20 DOCUMENT_ROOT=/var/www
> 2014-11-21 15:13:31.940974 7fb5eaf95700 20 FCGI_ROLE=RESPONDER
> 2014-11-21 15:13:31.940976 7fb5eaf95700 20 GATEWAY_INTERFACE=CGI/1.1
> 2014-11-21 15:13:31.940978 7fb5eaf95700 20 HTTP_ACCEPT=*/*
> 2014-11-21 15:13:31.940979 7fb5eaf95700 20 HTTP_ACCEPT_ENCODING=gzip,
> deflate, compress
> 2014-11-21 15:13:31.940981 7fb5eaf95700 20 HTTP_AUTHORIZATION=AWS us-west
> key:5/4h6MISlAVA+2o3FijXQNEq4Vc=
> 2014-11-21 15:13:31.940983 7fb5eaf95700 20 HTTP_DATE=Fri, 21 Nov 2014
> 02:13:31 GMT
> 2014-11-21 15:13:31.940985 7fb5eaf95700 20 HTTP_HOST=ceph1
> 2014-11-21 15:13:31.940987 7fb5eaf95700 20 HTTP_USER_AGENT=Boto/2.20.1
> Python/2.7.6 Linux/3.13.0-39-generic
> 2014-11-21 15:13:31.940988 7fb5eaf95700 20
> PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
> 2014-11-21 15:13:31.940990 7fb5eaf95700 20
> QUERY_STRING=client-id=radosgw-agent&object=bucketbig%2F_multipart_big.dat.2%2Ffjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta&op-id=ceph2%3A26008%3A1
> 2014-11-21 15:13:31.940994 7fb5eaf95700 20 REMOTE_ADDR=192.168.122.22
> 2014-11-21 15:13:31.940996 7fb5eaf95700 20 REMOTE_PORT=60231
> 2014-11-21 15:13:31.940998 7fb5eaf95700 20 REQUEST_METHOD=GET
> 2014-11-21 15:13:31.941000 7fb5eaf95700 20 REQUEST_SCHEME=http
> 2014-11-21 15:13:31.941002 7fb5eaf95700 20
> REQUEST_URI=/admin/opstate?client-id=radosgw-agent&object=bucketbig%2F_multipart_big.dat.2%2Ffjid6CneDQYKisHf0pRFOT5cEWF_EQr.meta&op-id=ceph2%3A26008%3A1
> 2014-11-21 15:13:31.941005 7fb5eaf95700 20
> SCRIPT_FILENAME=/var/www/s3gw.fcgi
> 2014-11-21 15:13:31.941006 7fb5eaf95700 20 SCRIPT_NAME=/admin/opstate
> 2014-11-21 15:13:31.941008 7fb5eaf95700 20
> SCRIPT_URI=http://ceph1/admin/opstate
> 2014-11-21 15:13:31.941011 7fb5eaf95700 20 SCRIPT_URL=/admin/opstate
> 2014-11-21 15:13:31.941013 7fb5eaf95700 20 SERVER_ADDR=192.168.122.21
> 2014-11-21 15:13:31.941014 7fb5eaf95700 20 SERVER_ADMIN=markir@vedavec
> 2014-11-21 15:13:31.941018 7fb5eaf95700 20 SERVER_NAME=ceph1
> 2014-11-21 15:13:31.941020 7fb5eaf95700 20 SERVER_PORT=80
> 2014-11-21 15:13:31.941022 7fb5eaf95700 20 SERVER_PROTOCOL=HTTP/1.1
> 2014-11-21 15:13:31.941024 7fb5eaf95700 20 SERVER_SIGNATURE=
> 2014-11-21 15:13:31.941026 7fb5eaf95700 20 SERVER_SOFTWARE=Apache/2.4.7
> (Ubuntu)
>
>
> _______________________________________________
> ceph-users mailing list
> ceph-users@xxxxxxxxxxxxxx
> http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com
_______________________________________________
ceph-users mailing list
ceph-users@xxxxxxxxxxxxxx
http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com
