search

s3gw-tech / s3gw

Container able to run on a Kubernetes cluster, providing S3-compatible endpoints to applications.
https://s3gw.tech
Apache License 2.0
130 stars 20 forks source link

[BUG] rgw/sfs: SegFault when running a copyObject command #539

Closed votdev closed 1 year ago

votdev commented 1 year ago

When copying an object a seg fault occurs.

$ aws s3api copy-object --bucket test09 --key file3.txt --copy-source "test09/file3.txt" --endpoint-url https://<ENDPOINT> --no-verify-ssl --debug

[1/2]

2023-05-23T16:30:38.328+0000 7fda620ba700  1 ====== starting new request req=0x7fd96a6ca740 =====
2023-05-23T16:30:38.328+0000 7fda620ba700 10 zone_unique_id: TODO
2023-05-23T16:30:38.328+0000 7fda620ba700 10 zone_unique_trans_id: TODO
2023-05-23T16:30:38.328+0000 7fda620ba700 10 get_host_id: TODO
2023-05-23T16:30:38.328+0000 7fda620ba700  2 req 0 0.000000000s initializing for trans_id = 
2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s rgw api priority: s3=8 s3website=7
2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s host=s3gw.xxxx.sslip.io
2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s meta>> HTTP_X_AMZ_CONTENT_SHA256
2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s meta>> HTTP_X_AMZ_COPY_SOURCE
2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s meta>> HTTP_X_AMZ_DATE
2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s x>> x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s x>> x-amz-copy-source:test09/file3.txt
2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s x>> x-amz-date:20230523T163037Z
2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s handler=22RGWHandler_REST_Obj_S3
2023-05-23T16:30:38.328+0000 7fda620ba700  2 req 0 0.000000000s getting op 1
2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s s3:copy_obj scheduling with throttler client=2 cost=1
2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s s3:copy_obj op=22RGWCopyObj_ObjStore_S3
2023-05-23T16:30:38.328+0000 7fda620ba700  2 req 0 0.000000000s s3:copy_obj verifying requester
2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s v4 signature format = c92ce6ac7bb8e919924220ad3fd72340ff3c4ada64b42283331351f40f08021f
2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s v4 credential format = test/20230523/us-east-1/s3/aws4_request
2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s access key id = test
2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s credential scope = 20230523/us-east-1/s3/aws4_request
2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s canonical headers format = host:s3gw.xxx.sslip.io
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-copy-source:test09/file3.txt
x-amz-date:20230523T163037Z

2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s payload request hash = e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s canonical request = PUT
/test09/file3.txt

host:s3gw.xxx.sslip.io
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-copy-source:test09/file3.txt
x-amz-date:20230523T163037Z

host;x-amz-content-sha256;x-amz-copy-source;x-amz-date
e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s canonical request hash = 8ad97132192e2f51dab0b82937033fc51be6601d298cea8c87c721792379ab60
2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s string to sign = AWS4-HMAC-SHA256
20230523T163037Z
20230523/us-east-1/s3/aws4_request
8ad97132192e2f51dab0b82937033fc51be6601d298cea8c87c721792379ab60
2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s date_k    = c38a65e317e028738dc307ca47c0118ae7509e74f69cad40910270fae8bcddcd
2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s region_k  = 1e47545cb6663f578f67e3f9a90dfde06c0d693d30ba077f10ad1bc69c8d78a9
2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s service_k = c2dfb24f9bdda6a34fada665ea7c984b9fd8e80439c72079791ed30040c35276
2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s signing_k = 66f03664efad9a65cda606dcd0797a493620cd1e4c5438c2a4f5229c1ffc2b6c
2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s generated signature = c92ce6ac7bb8e919924220ad3fd72340ff3c4ada64b42283331351f40f08021f
2023-05-23T16:30:38.332+0000 7fda620ba700 15 req 0 0.004000050s s3:copy_obj string_to_sign=AWS4-HMAC-SHA256
20230523T163037Z
20230523/us-east-1/s3/aws4_request
8ad97132192e2f51dab0b82937033fc51be6601d298cea8c87c721792379ab60
2023-05-23T16:30:38.332+0000 7fda620ba700 15 req 0 0.004000050s s3:copy_obj server signature=c92ce6ac7bb8e919924220ad3fd72340ff3c4ada64b42283331351f40f08021f
2023-05-23T16:30:38.332+0000 7fda620ba700 15 req 0 0.004000050s s3:copy_obj client signature=c92ce6ac7bb8e919924220ad3fd72340ff3c4ada64b42283331351f40f08021f
2023-05-23T16:30:38.332+0000 7fda620ba700 15 req 0 0.004000050s s3:copy_obj compare=0
2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj normalizing buckets and tenants
2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s s->object=file3.txt s->bucket=test09
2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj init permissions
2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s s3:copy_obj get_bucket: bucket: test09
2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s s3:copy_obj get_bucket: bucket: test09
2023-05-23T16:30:38.332+0000 7fda620ba700 15 req 0 0.004000050s s3:copy_obj decode_policy Read AccessControlPolicy<AccessControlPolicy xmlns="http://s3.amazonaws.com/doc/2006-03-01/"><Owner><ID>testid</ID><DisplayName>M. Tester</DisplayName></Owner><AccessControlList><Grant><Grantee xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="CanonicalUser"><ID>testid</ID><DisplayName>M. Tester</DisplayName></Grantee><Permission>FULL_CONTROL</Permission></Grant></AccessControlList></AccessControlPolicy>
2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj recalculating target
2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj reading permissions
2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj init op
2023-05-23T16:30:38.332+0000 7fda620ba700 10 get_quota: TODO
2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj verifying op mask
2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj verifying op permissions
2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s s3:copy_obj get_bucket: bucket: test09
*** Caught signal (Segmentation fault) **
 in thread 7fda620ba700 thread_name:radosgw
2023-05-23T16:30:38.332+0000 7fda620ba700 15 req 0 0.004000050s s3:copy_obj decode_policy Read AccessControlPolicy<AccessControlPolicy xmlns="http://s3.amazonaws.com/doc/2006-03-01/"><Owner><ID>testid</ID><DisplayName>M. Tester</DisplayName></Owner><AccessControlList><Grant><Grantee xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="CanonicalUser"><ID>testid</ID><DisplayName>M. Tester</DisplayName></Grantee><Permission>FULL_CONTROL</Permission></Grant></AccessControlList></AccessControlPolicy>
2023-05-23T16:30:38.332+0000 7fda620ba700  0 req 0 0.004000050s s3:copy_obj This copy request is illegal because it is trying to copy an object to itself without changing the object's metadata, storage class, website redirect location or encryption attributes.
2023-05-23T16:30:38.332+0000 7fda620ba700  2 overriding permissions due to admin operation
2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj verifying op params
2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj pre-executing
2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj check rate limiting
2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj executing
2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s s3:copy_obj x>> x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s s3:copy_obj x>> x-amz-copy-source:test09/file3.txt
2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s s3:copy_obj x>> x-amz-date:20230523T163037Z
2023-05-23T16:30:38.332+0000 7fda620ba700 10 get_notification: return stub notification
 ceph version Development (no_version) reef (dev)
 1: /lib64/libpthread.so.0(+0x168c0) [0x7fda7c4368c0]
 2: (RGWCopyObj::execute(optional_yield)+0x727) [0x556bf8d07ee7]
 3: (rgw_process_authenticated(RGWHandler_REST*, RGWOp*&, RGWRequest*, req_state*, optional_yield, rgw::sal::Driver*, bool)+0xca4) [0x556bf8ab1f24]
 4: (process_request(RGWProcessEnv const&, RGWRequest*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, RGWRestfulIO*, optional_yield, rgw::dmclock::Scheduler*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >*, std::chrono::duration<unsigned long, std::ratio<1l, 1000000000l> >*, int*)+0x25b6) [0x556bf8ab5206]
 5: radosgw(+0xb70a53) [0x556bf89e0a53]
 6: radosgw(+0xb718e6) [0x556bf89e18e6]
 7: make_fcontext()
2023-05-23T16:30:38.336+0000 7fda620ba700 -1 *** Caught signal (Segmentation fault) **
 in thread 7fda620ba700 thread_name:radosgw

 ceph version Development (no_version) reef (dev)
 1: /lib64/libpthread.so.0(+0x168c0) [0x7fda7c4368c0]
 2: (RGWCopyObj::execute(optional_yield)+0x727) [0x556bf8d07ee7]
 3: (rgw_process_authenticated(RGWHandler_REST*, RGWOp*&, RGWRequest*, req_state*, optional_yield, rgw::sal::Driver*, bool)+0xca4) [0x556bf8ab1f24]
 4: (process_request(RGWProcessEnv const&, RGWRequest*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, RGWRestfulIO*, optional_yield, rgw::dmclock::Scheduler*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >*, std::chrono::duration<unsigned long, std::ratio<1l, 1000000000l> >*, int*)+0x25b6) [0x556bf8ab5206]
 5: radosgw(+0xb70a53) [0x556bf89e0a53]
 6: radosgw(+0xb718e6) [0x556bf89e18e6]
 7: make_fcontext()
 NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- begin dump of recent events ---
  -203> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command assert hook 0x556bfa7c4c80
  -202> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command abort hook 0x556bfa7c4c80
  -201> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command leak_some_memory hook 0x556bfa7c4c80
  -200> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command perfcounters_dump hook 0x556bfa7c4c80
  -199> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command 1 hook 0x556bfa7c4c80
  -198> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command perf dump hook 0x556bfa7c4c80
  -197> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command perfcounters_schema hook 0x556bfa7c4c80
  -196> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command perf histogram dump hook 0x556bfa7c4c80
  -195> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command 2 hook 0x556bfa7c4c80
  -194> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command perf schema hook 0x556bfa7c4c80
  -193> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command counter dump hook 0x556bfa7c4c80
  -192> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command counter schema hook 0x556bfa7c4c80
  -191> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command perf histogram schema hook 0x556bfa7c4c80
  -190> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command perf reset hook 0x556bfa7c4c80
  -189> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command config show hook 0x556bfa7c4c80
  -188> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command config help hook 0x556bfa7c4c80
  -187> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command config set hook 0x556bfa7c4c80
  -186> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command config unset hook 0x556bfa7c4c80
  -185> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command config get hook 0x556bfa7c4c80
  -184> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command config diff hook 0x556bfa7c4c80
  -183> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command config diff get hook 0x556bfa7c4c80
  -182> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command injectargs hook 0x556bfa7c4c80
  -181> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command log flush hook 0x556bfa7c4c80
  -180> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command log dump hook 0x556bfa7c4c80
  -179> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command log reopen hook 0x556bfa7c4c80
  -178> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command dump_mempools hook 0x556bfb538068
  -177> 2023-05-23T16:26:53.885+0000 7fda77922f80 -1 Errors while parsing config file!
  -176> 2023-05-23T16:26:53.885+0000 7fda77922f80 -1 can't open ceph.conf: (2) No such file or directory
  -175> 2023-05-23T16:26:53.885+0000 7fda77922f80 -1 Errors while parsing config file!
  -174> 2023-05-23T16:26:53.885+0000 7fda77922f80 -1 can't open ceph.conf: (2) No such file or directory
  -173> 2023-05-23T16:26:53.885+0000 7fda77922f80  0 ceph version Development (no_version) reef (dev), process radosgw, pid 1
  -172> 2023-05-23T16:26:53.885+0000 7fda77922f80  0 framework: beast
  -171> 2023-05-23T16:26:53.885+0000 7fda77922f80  0 framework conf key: port, val: 7480
  -170> 2023-05-23T16:26:53.885+0000 7fda77922f80  0 framework conf key: ssl_port, val: 7481
  -169> 2023-05-23T16:26:53.885+0000 7fda77922f80  0 framework conf key: ssl_certificate, val: /s3gw-cluster-ip-tls/tls.crt
  -168> 2023-05-23T16:26:53.885+0000 7fda77922f80  0 framework conf key: ssl_private_key, val: /s3gw-cluster-ip-tls/tls.key
  -167> 2023-05-23T16:26:53.885+0000 7fda77922f80  1 init_numa not setting numa affinity
  -166> 2023-05-23T16:26:53.885+0000 7fda77922f80  5 asok(0x556bfaa78000) init /run//ceph-client.${ID}.1.93922255157408.asok
  -165> 2023-05-23T16:26:53.885+0000 7fda77922f80  5 asok(0x556bfaa78000) bind_and_listen /run//ceph-client.${ID}.1.93922255157408.asok
  -164> 2023-05-23T16:26:53.885+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command 0 hook 0x556bfa81e490
  -163> 2023-05-23T16:26:53.885+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command version hook 0x556bfa81e490
  -162> 2023-05-23T16:26:53.885+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command git_version hook 0x556bfa81e490
  -161> 2023-05-23T16:26:53.885+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command help hook 0x556bfa7c4c70
  -160> 2023-05-23T16:26:53.885+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command get_command_descriptions hook 0x556bfa7c4c60
  -159> 2023-05-23T16:26:53.885+0000 7fda76109700  5 asok(0x556bfaa78000) entry start
  -158> 2023-05-23T16:26:53.889+0000 7fda77922f80  0 rgw main: sfs init!
  -157> 2023-05-23T16:26:53.889+0000 7fda74105700 10 entry start
  -156> 2023-05-23T16:26:53.905+0000 7fda77922f80  0 sfs serving data from "/data"
  -155> 2023-05-23T16:26:53.909+0000 7fda77922f80  0 rgw main: Found default user "testid" in database.
  -154> 2023-05-23T16:26:53.909+0000 7fda77922f80 10 rgw main: initialize
  -153> 2023-05-23T16:26:53.909+0000 7fda728fa700  2 garbage collection: > GCWorker::entry start
  -152> 2023-05-23T16:26:53.909+0000 7fda728fa700 10 garbage collection: > SFSGC::process garbage collection: processing with max_objects = 32
  -151> 2023-05-23T16:26:53.909+0000 7fda708f6700  5 lifecycle: schedule life cycle next start time: Wed May 24 00:00:00 2023
  -150> 2023-05-23T16:26:53.909+0000 7fda6e8f2700  5 lifecycle: schedule life cycle next start time: Wed May 24 00:00:00 2023
  -149> 2023-05-23T16:26:53.909+0000 7fda6c8ee700  5 lifecycle: schedule life cycle next start time: Wed May 24 00:00:00 2023
  -148> 2023-05-23T16:26:53.909+0000 7fda77922f80 10 get_sync_module: TODO
  -147> 2023-05-23T16:26:53.909+0000 7fda77922f80 10 get_sync_module: TODO
  -146> 2023-05-23T16:26:53.909+0000 7fda728fa700 10 garbage collection: > SFSGC::process_deleted_buckets deleted buckets found = 0
  -145> 2023-05-23T16:26:53.909+0000 7fda728fa700  2 garbage collection: > GCWorker::entry stop
  -144> 2023-05-23T16:26:53.909+0000 7fda77922f80 10 get_lua_manager: TODO
  -143> 2023-05-23T16:26:53.909+0000 7fda77922f80  0 framework: beast
  -142> 2023-05-23T16:26:53.909+0000 7fda77922f80  0 framework conf key: ssl_certificate, val: config://rgw/cert/$realm/$zone.crt
  -141> 2023-05-23T16:26:53.909+0000 7fda77922f80  0 framework conf key: ssl_private_key, val: config://rgw/cert/$realm/$zone.key
  -140> 2023-05-23T16:26:53.941+0000 7fda77922f80  0 starting handler: beast
  -139> 2023-05-23T16:26:53.941+0000 7fda77922f80  4 frontend listening on 0.0.0.0:7481
  -138> 2023-05-23T16:26:53.941+0000 7fda77922f80  4 frontend listening on [::]:7481
  -137> 2023-05-23T16:26:53.941+0000 7fda77922f80  4 frontend listening on 0.0.0.0:7480
  -136> 2023-05-23T16:26:53.941+0000 7fda77922f80  4 frontend listening on [::]:7480
  -135> 2023-05-23T16:26:53.941+0000 7fda77922f80  4 frontend spawning 512 threads
  -134> 2023-05-23T16:26:53.961+0000 7fda77922f80 10 rgw main: register_to_service_map: TODO
  -133> 2023-05-23T16:27:23.909+0000 7fda7710b700 10 rgw UsageLogger: log_usage: TODO
  -132> 2023-05-23T16:27:41.382+0000 7fda6a0ca700  1 ====== starting new request req=0x7fd96a6ca740 =====
  -131> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 zone_unique_id: TODO
  -130> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 zone_unique_trans_id: TODO
  -129> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 get_host_id: TODO
  -128> 2023-05-23T16:27:41.382+0000 7fda6a0ca700  2 req 0 0.000000000s initializing for trans_id = 
  -127> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s rgw api priority: s3=8 s3website=7
  -126> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s host=s3gw.xxx.sslip.io
  -125> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s meta>> HTTP_X_AMZ_CONTENT_SHA256
  -124> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s meta>> HTTP_X_AMZ_DATE
  -123> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s x>> x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
  -122> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s x>> x-amz-date:20230523T162740Z
  -121> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s handler=22RGWHandler_REST_Obj_S3
  -120> 2023-05-23T16:27:41.382+0000 7fda6a0ca700  2 req 0 0.000000000s getting op 3
  -119> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s s3:get_obj scheduling with throttler client=2 cost=1
  -118> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s s3:get_obj op=21RGWGetObj_ObjStore_S3
  -117> 2023-05-23T16:27:41.382+0000 7fda6a0ca700  2 req 0 0.000000000s s3:get_obj verifying requester
  -116> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s v4 signature format = abbc16b45b35518f9e0a06fafeeaa43e5be01e3935cae536e1ce930bc8efebda
  -115> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s v4 credential format = test/20230523/us-east-1/s3/aws4_request
  -114> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s access key id = test
  -113> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s credential scope = 20230523/us-east-1/s3/aws4_request
  -112> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s canonical headers format = host:s3gw.xxx.sslip.io
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-date:20230523T162740Z

  -111> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s payload request hash = e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
  -110> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s canonical request = HEAD
/test09/file3.txt

host:s3gw.xxx.sslip.io
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-date:20230523T162740Z

host;x-amz-content-sha256;x-amz-date
e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
  -109> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s canonical request hash = 0cdad2b724c409f65cae9b994fca8713cfc95c0613a9a345361da46a080e1d71
  -108> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s string to sign = AWS4-HMAC-SHA256
20230523T162740Z
20230523/us-east-1/s3/aws4_request
0cdad2b724c409f65cae9b994fca8713cfc95c0613a9a345361da46a080e1d71
  -107> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s date_k    = c38a65e317e028738dc307ca47c0118ae7509e74f69cad40910270fae8bcddcd
  -106> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s region_k  = 1e47545cb6663f578f67e3f9a90dfde06c0d693d30ba077f10ad1bc69c8d78a9
  -105> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s service_k = c2dfb24f9bdda6a34fada665ea7c984b9fd8e80439c72079791ed30040c35276
  -104> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s signing_k = 66f03664efad9a65cda606dcd0797a493620cd1e4c5438c2a4f5229c1ffc2b6c
  -103> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s generated signature = abbc16b45b35518f9e0a06fafeeaa43e5be01e3935cae536e1ce930bc8efebda
  -102> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 15 req 0 0.000000000s s3:get_obj string_to_sign=AWS4-HMAC-SHA256
20230523T162740Z
20230523/us-east-1/s3/aws4_request
0cdad2b724c409f65cae9b994fca8713cfc95c0613a9a345361da46a080e1d71
  -101> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 15 req 0 0.000000000s s3:get_obj server signature=abbc16b45b35518f9e0a06fafeeaa43e5be01e3935cae536e1ce930bc8efebda
  -100> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 15 req 0 0.000000000s s3:get_obj client signature=abbc16b45b35518f9e0a06fafeeaa43e5be01e3935cae536e1ce930bc8efebda
   -99> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 15 req 0 0.000000000s s3:get_obj compare=0
   -98> 2023-05-23T16:27:41.382+0000 7fda6a0ca700  2 req 0 0.000000000s s3:get_obj normalizing buckets and tenants
   -97> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s s->object=file3.txt s->bucket=test09
   -96> 2023-05-23T16:27:41.382+0000 7fda6a0ca700  2 req 0 0.000000000s s3:get_obj init permissions
   -95> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s s3:get_obj get_bucket: bucket: test09
   -94> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 15 req 0 0.000000000s s3:get_obj decode_policy Read AccessControlPolicy<AccessControlPolicy xmlns="http://s3.amazonaws.com/doc/2006-03-01/"><Owner><ID>testid</ID><DisplayName>M. Tester</DisplayName></Owner><AccessControlList><Grant><Grantee xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="CanonicalUser"><ID>testid</ID><DisplayName>M. Tester</DisplayName></Grantee><Permission>FULL_CONTROL</Permission></Grant></AccessControlList></AccessControlPolicy>
   -93> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  2 req 0 0.004000050s s3:get_obj recalculating target
   -92> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  2 req 0 0.004000050s s3:get_obj reading permissions
   -91> 2023-05-23T16:27:41.386+0000 7fda6a0ca700 15 req 0 0.004000050s s3:get_obj decode_policy Read AccessControlPolicy<AccessControlPolicy xmlns="http://s3.amazonaws.com/doc/2006-03-01/"><Owner><ID>testid</ID><DisplayName>M. Tester</DisplayName></Owner><AccessControlList><Grant><Grantee xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="CanonicalUser"><ID>testid</ID><DisplayName>M. Tester</DisplayName></Grantee><Permission>FULL_CONTROL</Permission></Grant></AccessControlList></AccessControlPolicy>
   -90> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  2 req 0 0.004000050s s3:get_obj init op
   -89> 2023-05-23T16:27:41.386+0000 7fda6a0ca700 10 get_quota: TODO
   -88> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  2 req 0 0.004000050s s3:get_obj verifying op mask
   -87> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  2 req 0 0.004000050s s3:get_obj verifying op permissions
   -86> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  5 req 0 0.004000050s s3:get_obj Searching permissions for identity=rgw::auth::SysReqApplier -> rgw::auth::LocalApplier(acct_user=testid, acct_name=M. Tester, subuser=, perm_mask=15, is_admin=1) mask=49
   -85> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  5 req 0 0.004000050s s3:get_obj Searching permissions for uid=testid
   -84> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  5 req 0 0.004000050s s3:get_obj Found permission: 15
   -83> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  5 req 0 0.004000050s s3:get_obj Searching permissions for group=1 mask=49
   -82> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  5 req 0 0.004000050s s3:get_obj Permissions for group not found
   -81> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  5 req 0 0.004000050s s3:get_obj Searching permissions for group=2 mask=49
   -80> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  5 req 0 0.004000050s s3:get_obj Permissions for group not found
   -79> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  5 req 0 0.004000050s s3:get_obj -- Getting permissions done for identity=rgw::auth::SysReqApplier -> rgw::auth::LocalApplier(acct_user=testid, acct_name=M. Tester, subuser=, perm_mask=15, is_admin=1), owner=testid, perm=1
   -78> 2023-05-23T16:27:41.386+0000 7fda6a0ca700 10 req 0 0.004000050s s3:get_obj  identity=rgw::auth::SysReqApplier -> rgw::auth::LocalApplier(acct_user=testid, acct_name=M. Tester, subuser=, perm_mask=15, is_admin=1) requested perm (type)=1, policy perm=1, user_perm_mask=15, acl perm=1
   -77> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  2 req 0 0.004000050s s3:get_obj verifying op params
   -76> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  2 req 0 0.004000050s s3:get_obj pre-executing
   -75> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  2 req 0 0.004000050s s3:get_obj check rate limiting
   -74> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  2 req 0 0.004000050s s3:get_obj executing
   -73> 2023-05-23T16:27:41.386+0000 7fda6a0ca700 10 req 0 0.004000050s s3:get_obj > object_read::prepare bucket: test09, obj: file3.txt, size: 457
   -72> 2023-05-23T16:27:41.386+0000 7fda6a0ca700 15 req 0 0.004000050s Encryption mode: 
   -71> 2023-05-23T16:27:41.386+0000 7fda630bc700  2 req 0 0.004000050s s3:get_obj completing
   -70> 2023-05-23T16:27:41.386+0000 7fda630bc700  2 req 0 0.004000050s s3:get_obj op status=0
   -69> 2023-05-23T16:27:41.386+0000 7fda630bc700  2 req 0 0.004000050s s3:get_obj http status=200
   -68> 2023-05-23T16:27:41.386+0000 7fda630bc700  1 ====== req done req=0x7fd96a6ca740 op status=0 http_status=200 latency=0.004000050s ======
   -67> 2023-05-23T16:27:41.386+0000 7fda630bc700  1 beast: 0x7fd96a6ca740: 10.42.0.152 - testid [23/May/2023:16:27:41.382 +0000] "HEAD /test09/file3.txt HTTP/1.1" 200 0 - "aws-cli/1.22.34 Python/3.10.6 Linux/5.19.0-41-generic botocore/1.29.76" - latency=0.004000050s
   -66> 2023-05-23T16:27:53.910+0000 7fda7710b700 10 rgw UsageLogger: log_usage: TODO
   -65> 2023-05-23T16:28:23.910+0000 7fda7710b700 10 rgw UsageLogger: log_usage: TODO
   -64> 2023-05-23T16:28:53.910+0000 7fda7710b700 10 rgw UsageLogger: log_usage: TODO
   -63> 2023-05-23T16:29:23.911+0000 7fda7710b700 10 rgw UsageLogger: log_usage: TODO
   -62> 2023-05-23T16:29:53.911+0000 7fda7710b700 10 rgw UsageLogger: log_usage: TODO
   -61> 2023-05-23T16:30:23.912+0000 7fda7710b700 10 rgw UsageLogger: log_usage: TODO
   -60> 2023-05-23T16:30:38.328+0000 7fda620ba700  1 ====== starting new request req=0x7fd96a6ca740 =====
   -59> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 zone_unique_id: TODO
   -58> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 zone_unique_trans_id: TODO
   -57> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 get_host_id: TODO
   -56> 2023-05-23T16:30:38.328+0000 7fda620ba700  2 req 0 0.000000000s initializing for trans_id = 
   -55> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s rgw api priority: s3=8 s3website=7
   -54> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s host=s3gw.xxx.sslip.io
   -53> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s meta>> HTTP_X_AMZ_CONTENT_SHA256
   -52> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s meta>> HTTP_X_AMZ_COPY_SOURCE
   -51> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s meta>> HTTP_X_AMZ_DATE
   -50> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s x>> x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
   -49> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s x>> x-amz-copy-source:test09/file3.txt
   -48> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s x>> x-amz-date:20230523T163037Z
   -47> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s handler=22RGWHandler_REST_Obj_S3
   -46> 2023-05-23T16:30:38.328+0000 7fda620ba700  2 req 0 0.000000000s getting op 1
   -45> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s s3:copy_obj scheduling with throttler client=2 cost=1
   -44> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s s3:copy_obj op=22RGWCopyObj_ObjStore_S3
   -43> 2023-05-23T16:30:38.328+0000 7fda620ba700  2 req 0 0.000000000s s3:copy_obj verifying requester
   -42> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s v4 signature format = c92ce6ac7bb8e919924220ad3fd72340ff3c4ada64b42283331351f40f08021f
   -41> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s v4 credential format = test/20230523/us-east-1/s3/aws4_request
   -40> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s access key id = test
   -39> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s credential scope = 20230523/us-east-1/s3/aws4_request
   -38> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s canonical headers format = host:s3gw.xxx.sslip.io
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-copy-source:test09/file3.txt
x-amz-date:20230523T163037Z

   -37> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s payload request hash = e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
   -36> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s canonical request = PUT
/test09/file3.txt

host:s3gw.xxx.sslip.io
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-copy-source:test09/file3.txt
x-amz-date:20230523T163037Z

host;x-amz-content-sha256;x-amz-copy-source;x-amz-date
e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
   -35> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s canonical request hash = 8ad97132192e2f51dab0b82937033fc51be6601d298cea8c87c721792379ab60
   -34> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s string to sign = AWS4-HMAC-SHA256
20230523T163037Z
20230523/us-east-1/s3/aws4_request
8ad97132192e2f51dab0b82937033fc51be6601d298cea8c87c721792379ab60
   -33> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s date_k    = c38a65e317e028738dc307ca47c0118ae7509e74f69cad40910270fae8bcddcd
   -32> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s region_k  = 1e47545cb6663f578f67e3f9a90dfde06c0d693d30ba077f10ad1bc69c8d78a9
   -31> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s service_k = c2dfb24f9bdda6a34fada665ea7c984b9fd8e80439c72079791ed30040c35276
   -30> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s signing_k = 66f03664efad9a65cda606dcd0797a493620cd1e4c5438c2a4f5229c1ffc2b6c
   -29> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s generated signature = c92ce6ac7bb8e919924220ad3fd72340ff3c4ada64b42283331351f40f08021f
   -28> 2023-05-23T16:30:38.332+0000 7fda620ba700 15 req 0 0.004000050s s3:copy_obj string_to_sign=AWS4-HMAC-SHA256
20230523T163037Z
20230523/us-east-1/s3/aws4_request
8ad97132192e2f51dab0b82937033fc51be6601d298cea8c87c721792379ab60
   -27> 2023-05-23T16:30:38.332+0000 7fda620ba700 15 req 0 0.004000050s s3:copy_obj server signature=c92ce6ac7bb8e919924220ad3fd72340ff3c4ada64b42283331351f40f08021f
   -26> 2023-05-23T16:30:38.332+0000 7fda620ba700 15 req 0 0.004000050s s3:copy_obj client signature=c92ce6ac7bb8e919924220ad3fd72340ff3c4ada64b42283331351f40f08021f
   -25> 2023-05-23T16:30:38.332+0000 7fda620ba700 15 req 0 0.004000050s s3:copy_obj compare=0
   -24> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj normalizing buckets and tenants
   -23> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s s->object=file3.txt s->bucket=test09
   -22> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj init permissions
   -21> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s s3:copy_obj get_bucket: bucket: test09
   -20> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s s3:copy_obj get_bucket: bucket: test09
   -19> 2023-05-23T16:30:38.332+0000 7fda620ba700 15 req 0 0.004000050s s3:copy_obj decode_policy Read AccessControlPolicy<AccessControlPolicy xmlns="http://s3.amazonaws.com/doc/2006-03-01/"><Owner><ID>testid</ID><DisplayName>M. Tester</DisplayName></Owner><AccessControlList><Grant><Grantee xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="CanonicalUser"><ID>testid</ID><DisplayName>M. Tester</DisplayName></Grantee><Permission>FULL_CONTROL</Permission></Grant></AccessControlList></AccessControlPolicy>
   -18> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj recalculating target
   -17> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj reading permissions
   -16> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj init op
   -15> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 get_quota: TODO
   -14> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj verifying op mask
   -13> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj verifying op permissions
   -12> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s s3:copy_obj get_bucket: bucket: test09
   -11> 2023-05-23T16:30:38.332+0000 7fda620ba700 15 req 0 0.004000050s s3:copy_obj decode_policy Read AccessControlPolicy<AccessControlPolicy xmlns="http://s3.amazonaws.com/doc/2006-03-01/"><Owner><ID>testid</ID><DisplayName>M. Tester</DisplayName></Owner><AccessControlList><Grant><Grantee xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="CanonicalUser"><ID>testid</ID><DisplayName>M. Tester</DisplayName></Grantee><Permission>FULL_CONTROL</Permission></Grant></AccessControlList></AccessControlPolicy>
   -10> 2023-05-23T16:30:38.332+0000 7fda620ba700  0 req 0 0.004000050s s3:copy_obj This copy request is illegal because it is trying to copy an object to itself without changing the object's metadata, storage class, website redirect location or encryption attributes.
    -9> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 overriding permissions due to admin operation
    -8> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj verifying op params
    -7> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj pre-executing
    -6> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj check rate limiting
    -5> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj executing
    -4> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s s3:copy_obj x>> x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
    -3> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s s3:copy_obj x>> x-amz-copy-source:test09/file3.txt
    -2> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s s3:copy_obj x>> x-amz-date:20230523T163037Z
    -1> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 get_notification: return stub notification
     0> 2023-05-23T16:30:38.336+0000 7fda620ba700 -1 *** Caught signal (Segmentation fault) **
 in thread 7fda620ba700 thread_name:radosgw

 ceph version Development (no_version) reef (dev)
 1: /lib64/libpthread.so.0(+0x168c0) [0x7fda7c4368c0]
 2: (RGWCopyObj::execute(optional_yield)+0x727) [0x556bf8d07ee7]
 3: (rgw_process_authenticated(RGWHandler_REST*, RGWOp*&, RGWRequest*, req_state*, optional_yield, rgw::sal::Driver*, bool)+0xca4) [0x556bf8ab1f24]
 4: (process_request(RGWProcessEnv const&, RGWRequest*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, RGWRestfulIO*, optional_yield, rgw::dmclock::Scheduler*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >*, std::chrono::duration<unsigned long, std::ratio<1l, 1000000000l> >*, int*)+0x25b6) [0x556bf8ab5206]
 5: radosgw(+0xb70a53) [0x556bf89e0a53]
 6: radosgw(+0xb718e6) [0x556bf89e18e6]
 7: make_fcontext()
 NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- logging levels ---
   0/ 5 none
   0/ 1 lockdep
   0/ 1 context
   1/ 1 crush
   1/ 5 mds
   1/ 5 mds_balancer
   1/ 5 mds_locker
   1/ 5 mds_log
   1/ 5 mds_log_expire
   1/ 5 mds_migrator
   0/ 1 buffer
   0/ 1 timer
   0/ 1 filer
   0/ 1 striper
   0/ 1 objecter
   0/ 5 rados
   0/ 5 rbd
   0/ 5 rbd_mirror
   0/ 5 rbd_replay
   0/ 5 rbd_pwl
   0/ 5 journaler
   0/ 5 objectcacher
   0/ 5 immutable_obj_cache
   0/ 5 client
   1/ 5 osd
   0/ 5 optracker
   0/ 5 objclass
   1/ 3 filestore
   1/ 3 journal
   0/ 0 ms
   1/ 5 mon
   0/10 monc
   1/ 5 paxos
   0/ 5 tp
   1/ 5 auth
   1/ 5 crypto
   1/ 1 finisher
   1/ 1 reserver
   1/ 5 heartbeatmap
   1/ 5 perfcounter
  15/15 rgw
   1/ 5 rgw_sync
   1/ 5 rgw_datacache
   1/ 5 rgw_access
   1/ 5 rgw_dbstore
   1/ 5 rgw_flight
   1/ 5 javaclient
   1/ 5 asok
   1/ 1 throttle
   0/ 0 refs
   1/ 5 compressor
   1/ 5 bluestore
   1/ 5 bluefs
   1/ 3 bdev
   1/ 5 kstore
   4/ 5 rocksdb
   4/ 5 leveldb
   1/ 5 fuse
   2/ 5 mgr
   1/ 5 mgrc
   1/ 5 dpdk
   1/ 5 eventtrace
   1/ 5 prioritycache
   0/ 5 test
   0/ 5 cephfs_mirror
   0/ 5 cephsqlite
   0/ 5 seastore
   0/ 5 seastore_onode
   0/ 5 seastore_odata
   0/ 5 seastore_omap
   0/ 5 seastore_tm
   0/ 5 seastore_t
   0/ 5 seastore_cleaner
   0/ 5 seastore_epm
   0/ 5 seastore_lba
   0/ 5 seastore_fixedkv_tree
   0/ 5 seastore_cache
   0/ 5 seastore_journal
   0/ 5 seastore_device
   0/ 5 seastore_backref
   0/ 5 alienstore
   1/ 5 mclock
   0/ 5 cyanstore
   1/ 5 ceph_exporter
   1/ 5 memstore
  -2/-2 (syslog threshold)
  99/99 (stderr threshold)
votdev commented 1 year ago

[2/2]

--- pthread ID / name mapping for recent threads ---
  7fda620ba700 / radosgw
  7fda630bc700 / radosgw
  7fda6a0ca700 / radosgw
  7fda6c8ee700 / lifecycle_thr_2
  7fda6e8f2700 / lifecycle_thr_1
  7fda708f6700 / lifecycle_thr_0
  7fda728fa700 / rgw_gc
  7fda74105700 / kmip worker
  7fda76109700 / admin_socket
  7fda7710b700 / safe_timer
  7fda77922f80 / radosgw
  max_recent     10000
  max_new         1000
  log_file 
--- end dump of recent events ---
--- begin dump of recent events ---
  -203> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command assert hook 0x556bfa7c4c80
  -202> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command abort hook 0x556bfa7c4c80
  -201> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command leak_some_memory hook 0x556bfa7c4c80
  -200> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command perfcounters_dump hook 0x556bfa7c4c80
  -199> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command 1 hook 0x556bfa7c4c80
  -198> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command perf dump hook 0x556bfa7c4c80
  -197> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command perfcounters_schema hook 0x556bfa7c4c80
  -196> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command perf histogram dump hook 0x556bfa7c4c80
  -195> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command 2 hook 0x556bfa7c4c80
  -194> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command perf schema hook 0x556bfa7c4c80
  -193> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command counter dump hook 0x556bfa7c4c80
  -192> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command counter schema hook 0x556bfa7c4c80
  -191> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command perf histogram schema hook 0x556bfa7c4c80
  -190> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command perf reset hook 0x556bfa7c4c80
  -189> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command config show hook 0x556bfa7c4c80
  -188> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command config help hook 0x556bfa7c4c80
  -187> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command config set hook 0x556bfa7c4c80
  -186> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command config unset hook 0x556bfa7c4c80
  -185> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command config get hook 0x556bfa7c4c80
  -184> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command config diff hook 0x556bfa7c4c80
  -183> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command config diff get hook 0x556bfa7c4c80
  -182> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command injectargs hook 0x556bfa7c4c80
  -181> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command log flush hook 0x556bfa7c4c80
  -180> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command log dump hook 0x556bfa7c4c80
  -179> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command log reopen hook 0x556bfa7c4c80
  -178> 2023-05-23T16:26:53.865+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command dump_mempools hook 0x556bfb538068
  -177> 2023-05-23T16:26:53.885+0000 7fda77922f80 -1 Errors while parsing config file!
  -176> 2023-05-23T16:26:53.885+0000 7fda77922f80 -1 can't open ceph.conf: (2) No such file or directory
  -175> 2023-05-23T16:26:53.885+0000 7fda77922f80 -1 Errors while parsing config file!
  -174> 2023-05-23T16:26:53.885+0000 7fda77922f80 -1 can't open ceph.conf: (2) No such file or directory
  -173> 2023-05-23T16:26:53.885+0000 7fda77922f80  0 ceph version Development (no_version) reef (dev), process radosgw, pid 1
  -172> 2023-05-23T16:26:53.885+0000 7fda77922f80  0 framework: beast
  -171> 2023-05-23T16:26:53.885+0000 7fda77922f80  0 framework conf key: port, val: 7480
  -170> 2023-05-23T16:26:53.885+0000 7fda77922f80  0 framework conf key: ssl_port, val: 7481
  -169> 2023-05-23T16:26:53.885+0000 7fda77922f80  0 framework conf key: ssl_certificate, val: /s3gw-cluster-ip-tls/tls.crt
  -168> 2023-05-23T16:26:53.885+0000 7fda77922f80  0 framework conf key: ssl_private_key, val: /s3gw-cluster-ip-tls/tls.key
  -167> 2023-05-23T16:26:53.885+0000 7fda77922f80  1 init_numa not setting numa affinity
  -166> 2023-05-23T16:26:53.885+0000 7fda77922f80  5 asok(0x556bfaa78000) init /run//ceph-client.${ID}.1.93922255157408.asok
  -165> 2023-05-23T16:26:53.885+0000 7fda77922f80  5 asok(0x556bfaa78000) bind_and_listen /run//ceph-client.${ID}.1.93922255157408.asok
  -164> 2023-05-23T16:26:53.885+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command 0 hook 0x556bfa81e490
  -163> 2023-05-23T16:26:53.885+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command version hook 0x556bfa81e490
  -162> 2023-05-23T16:26:53.885+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command git_version hook 0x556bfa81e490
  -161> 2023-05-23T16:26:53.885+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command help hook 0x556bfa7c4c70
  -160> 2023-05-23T16:26:53.885+0000 7fda77922f80  5 asok(0x556bfaa78000) register_command get_command_descriptions hook 0x556bfa7c4c60
  -159> 2023-05-23T16:26:53.885+0000 7fda76109700  5 asok(0x556bfaa78000) entry start
  -158> 2023-05-23T16:26:53.889+0000 7fda77922f80  0 rgw main: sfs init!
  -157> 2023-05-23T16:26:53.889+0000 7fda74105700 10 entry start
  -156> 2023-05-23T16:26:53.905+0000 7fda77922f80  0 sfs serving data from "/data"
  -155> 2023-05-23T16:26:53.909+0000 7fda77922f80  0 rgw main: Found default user "testid" in database.
  -154> 2023-05-23T16:26:53.909+0000 7fda77922f80 10 rgw main: initialize
  -153> 2023-05-23T16:26:53.909+0000 7fda728fa700  2 garbage collection: > GCWorker::entry start
  -152> 2023-05-23T16:26:53.909+0000 7fda728fa700 10 garbage collection: > SFSGC::process garbage collection: processing with max_objects = 32
  -151> 2023-05-23T16:26:53.909+0000 7fda708f6700  5 lifecycle: schedule life cycle next start time: Wed May 24 00:00:00 2023
  -150> 2023-05-23T16:26:53.909+0000 7fda6e8f2700  5 lifecycle: schedule life cycle next start time: Wed May 24 00:00:00 2023
  -149> 2023-05-23T16:26:53.909+0000 7fda6c8ee700  5 lifecycle: schedule life cycle next start time: Wed May 24 00:00:00 2023
  -148> 2023-05-23T16:26:53.909+0000 7fda77922f80 10 get_sync_module: TODO
  -147> 2023-05-23T16:26:53.909+0000 7fda77922f80 10 get_sync_module: TODO
  -146> 2023-05-23T16:26:53.909+0000 7fda728fa700 10 garbage collection: > SFSGC::process_deleted_buckets deleted buckets found = 0
  -145> 2023-05-23T16:26:53.909+0000 7fda728fa700  2 garbage collection: > GCWorker::entry stop
  -144> 2023-05-23T16:26:53.909+0000 7fda77922f80 10 get_lua_manager: TODO
  -143> 2023-05-23T16:26:53.909+0000 7fda77922f80  0 framework: beast
  -142> 2023-05-23T16:26:53.909+0000 7fda77922f80  0 framework conf key: ssl_certificate, val: config://rgw/cert/$realm/$zone.crt
  -141> 2023-05-23T16:26:53.909+0000 7fda77922f80  0 framework conf key: ssl_private_key, val: config://rgw/cert/$realm/$zone.key
  -140> 2023-05-23T16:26:53.941+0000 7fda77922f80  0 starting handler: beast
  -139> 2023-05-23T16:26:53.941+0000 7fda77922f80  4 frontend listening on 0.0.0.0:7481
  -138> 2023-05-23T16:26:53.941+0000 7fda77922f80  4 frontend listening on [::]:7481
  -137> 2023-05-23T16:26:53.941+0000 7fda77922f80  4 frontend listening on 0.0.0.0:7480
  -136> 2023-05-23T16:26:53.941+0000 7fda77922f80  4 frontend listening on [::]:7480
  -135> 2023-05-23T16:26:53.941+0000 7fda77922f80  4 frontend spawning 512 threads
  -134> 2023-05-23T16:26:53.961+0000 7fda77922f80 10 rgw main: register_to_service_map: TODO
  -133> 2023-05-23T16:27:23.909+0000 7fda7710b700 10 rgw UsageLogger: log_usage: TODO
  -132> 2023-05-23T16:27:41.382+0000 7fda6a0ca700  1 ====== starting new request req=0x7fd96a6ca740 =====
  -131> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 zone_unique_id: TODO
  -130> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 zone_unique_trans_id: TODO
  -129> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 get_host_id: TODO
  -128> 2023-05-23T16:27:41.382+0000 7fda6a0ca700  2 req 0 0.000000000s initializing for trans_id = 
  -127> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s rgw api priority: s3=8 s3website=7
  -126> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s host=s3gw.xxx.sslip.io
  -125> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s meta>> HTTP_X_AMZ_CONTENT_SHA256
  -124> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s meta>> HTTP_X_AMZ_DATE
  -123> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s x>> x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
  -122> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s x>> x-amz-date:20230523T162740Z
  -121> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s handler=22RGWHandler_REST_Obj_S3
  -120> 2023-05-23T16:27:41.382+0000 7fda6a0ca700  2 req 0 0.000000000s getting op 3
  -119> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s s3:get_obj scheduling with throttler client=2 cost=1
  -118> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s s3:get_obj op=21RGWGetObj_ObjStore_S3
  -117> 2023-05-23T16:27:41.382+0000 7fda6a0ca700  2 req 0 0.000000000s s3:get_obj verifying requester
  -116> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s v4 signature format = abbc16b45b35518f9e0a06fafeeaa43e5be01e3935cae536e1ce930bc8efebda
  -115> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s v4 credential format = test/20230523/us-east-1/s3/aws4_request
  -114> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s access key id = test
  -113> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s credential scope = 20230523/us-east-1/s3/aws4_request
  -112> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s canonical headers format = host:s3gw.xxx.sslip.io
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-date:20230523T162740Z

  -111> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s payload request hash = e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
  -110> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s canonical request = HEAD
/test09/file3.txt

host:s3gw.xxx.sslip.io
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-date:20230523T162740Z

host;x-amz-content-sha256;x-amz-date
e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
  -109> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s canonical request hash = 0cdad2b724c409f65cae9b994fca8713cfc95c0613a9a345361da46a080e1d71
  -108> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s string to sign = AWS4-HMAC-SHA256
20230523T162740Z
20230523/us-east-1/s3/aws4_request
0cdad2b724c409f65cae9b994fca8713cfc95c0613a9a345361da46a080e1d71
  -107> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s date_k    = c38a65e317e028738dc307ca47c0118ae7509e74f69cad40910270fae8bcddcd
  -106> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s region_k  = 1e47545cb6663f578f67e3f9a90dfde06c0d693d30ba077f10ad1bc69c8d78a9
  -105> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s service_k = c2dfb24f9bdda6a34fada665ea7c984b9fd8e80439c72079791ed30040c35276
  -104> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s signing_k = 66f03664efad9a65cda606dcd0797a493620cd1e4c5438c2a4f5229c1ffc2b6c
  -103> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s generated signature = abbc16b45b35518f9e0a06fafeeaa43e5be01e3935cae536e1ce930bc8efebda
  -102> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 15 req 0 0.000000000s s3:get_obj string_to_sign=AWS4-HMAC-SHA256
20230523T162740Z
20230523/us-east-1/s3/aws4_request
0cdad2b724c409f65cae9b994fca8713cfc95c0613a9a345361da46a080e1d71
  -101> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 15 req 0 0.000000000s s3:get_obj server signature=abbc16b45b35518f9e0a06fafeeaa43e5be01e3935cae536e1ce930bc8efebda
  -100> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 15 req 0 0.000000000s s3:get_obj client signature=abbc16b45b35518f9e0a06fafeeaa43e5be01e3935cae536e1ce930bc8efebda
   -99> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 15 req 0 0.000000000s s3:get_obj compare=0
   -98> 2023-05-23T16:27:41.382+0000 7fda6a0ca700  2 req 0 0.000000000s s3:get_obj normalizing buckets and tenants
   -97> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s s->object=file3.txt s->bucket=test09
   -96> 2023-05-23T16:27:41.382+0000 7fda6a0ca700  2 req 0 0.000000000s s3:get_obj init permissions
   -95> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 10 req 0 0.000000000s s3:get_obj get_bucket: bucket: test09
   -94> 2023-05-23T16:27:41.382+0000 7fda6a0ca700 15 req 0 0.000000000s s3:get_obj decode_policy Read AccessControlPolicy<AccessControlPolicy xmlns="http://s3.amazonaws.com/doc/2006-03-01/"><Owner><ID>testid</ID><DisplayName>M. Tester</DisplayName></Owner><AccessControlList><Grant><Grantee xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="CanonicalUser"><ID>testid</ID><DisplayName>M. Tester</DisplayName></Grantee><Permission>FULL_CONTROL</Permission></Grant></AccessControlList></AccessControlPolicy>
   -93> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  2 req 0 0.004000050s s3:get_obj recalculating target
   -92> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  2 req 0 0.004000050s s3:get_obj reading permissions
   -91> 2023-05-23T16:27:41.386+0000 7fda6a0ca700 15 req 0 0.004000050s s3:get_obj decode_policy Read AccessControlPolicy<AccessControlPolicy xmlns="http://s3.amazonaws.com/doc/2006-03-01/"><Owner><ID>testid</ID><DisplayName>M. Tester</DisplayName></Owner><AccessControlList><Grant><Grantee xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="CanonicalUser"><ID>testid</ID><DisplayName>M. Tester</DisplayName></Grantee><Permission>FULL_CONTROL</Permission></Grant></AccessControlList></AccessControlPolicy>
   -90> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  2 req 0 0.004000050s s3:get_obj init op
   -89> 2023-05-23T16:27:41.386+0000 7fda6a0ca700 10 get_quota: TODO
   -88> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  2 req 0 0.004000050s s3:get_obj verifying op mask
   -87> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  2 req 0 0.004000050s s3:get_obj verifying op permissions
   -86> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  5 req 0 0.004000050s s3:get_obj Searching permissions for identity=rgw::auth::SysReqApplier -> rgw::auth::LocalApplier(acct_user=testid, acct_name=M. Tester, subuser=, perm_mask=15, is_admin=1) mask=49
   -85> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  5 req 0 0.004000050s s3:get_obj Searching permissions for uid=testid
   -84> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  5 req 0 0.004000050s s3:get_obj Found permission: 15
   -83> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  5 req 0 0.004000050s s3:get_obj Searching permissions for group=1 mask=49
   -82> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  5 req 0 0.004000050s s3:get_obj Permissions for group not found
   -81> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  5 req 0 0.004000050s s3:get_obj Searching permissions for group=2 mask=49
   -80> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  5 req 0 0.004000050s s3:get_obj Permissions for group not found
   -79> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  5 req 0 0.004000050s s3:get_obj -- Getting permissions done for identity=rgw::auth::SysReqApplier -> rgw::auth::LocalApplier(acct_user=testid, acct_name=M. Tester, subuser=, perm_mask=15, is_admin=1), owner=testid, perm=1
   -78> 2023-05-23T16:27:41.386+0000 7fda6a0ca700 10 req 0 0.004000050s s3:get_obj  identity=rgw::auth::SysReqApplier -> rgw::auth::LocalApplier(acct_user=testid, acct_name=M. Tester, subuser=, perm_mask=15, is_admin=1) requested perm (type)=1, policy perm=1, user_perm_mask=15, acl perm=1
   -77> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  2 req 0 0.004000050s s3:get_obj verifying op params
   -76> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  2 req 0 0.004000050s s3:get_obj pre-executing
   -75> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  2 req 0 0.004000050s s3:get_obj check rate limiting
   -74> 2023-05-23T16:27:41.386+0000 7fda6a0ca700  2 req 0 0.004000050s s3:get_obj executing
   -73> 2023-05-23T16:27:41.386+0000 7fda6a0ca700 10 req 0 0.004000050s s3:get_obj > object_read::prepare bucket: test09, obj: file3.txt, size: 457
   -72> 2023-05-23T16:27:41.386+0000 7fda6a0ca700 15 req 0 0.004000050s Encryption mode: 
   -71> 2023-05-23T16:27:41.386+0000 7fda630bc700  2 req 0 0.004000050s s3:get_obj completing
   -70> 2023-05-23T16:27:41.386+0000 7fda630bc700  2 req 0 0.004000050s s3:get_obj op status=0
   -69> 2023-05-23T16:27:41.386+0000 7fda630bc700  2 req 0 0.004000050s s3:get_obj http status=200
   -68> 2023-05-23T16:27:41.386+0000 7fda630bc700  1 ====== req done req=0x7fd96a6ca740 op status=0 http_status=200 latency=0.004000050s ======
   -67> 2023-05-23T16:27:41.386+0000 7fda630bc700  1 beast: 0x7fd96a6ca740: 10.42.0.152 - testid [23/May/2023:16:27:41.382 +0000] "HEAD /test09/file3.txt HTTP/1.1" 200 0 - "aws-cli/1.22.34 Python/3.10.6 Linux/5.19.0-41-generic botocore/1.29.76" - latency=0.004000050s
   -66> 2023-05-23T16:27:53.910+0000 7fda7710b700 10 rgw UsageLogger: log_usage: TODO
   -65> 2023-05-23T16:28:23.910+0000 7fda7710b700 10 rgw UsageLogger: log_usage: TODO
   -64> 2023-05-23T16:28:53.910+0000 7fda7710b700 10 rgw UsageLogger: log_usage: TODO
   -63> 2023-05-23T16:29:23.911+0000 7fda7710b700 10 rgw UsageLogger: log_usage: TODO
   -62> 2023-05-23T16:29:53.911+0000 7fda7710b700 10 rgw UsageLogger: log_usage: TODO
   -61> 2023-05-23T16:30:23.912+0000 7fda7710b700 10 rgw UsageLogger: log_usage: TODO
   -60> 2023-05-23T16:30:38.328+0000 7fda620ba700  1 ====== starting new request req=0x7fd96a6ca740 =====
   -59> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 zone_unique_id: TODO
   -58> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 zone_unique_trans_id: TODO
   -57> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 get_host_id: TODO
   -56> 2023-05-23T16:30:38.328+0000 7fda620ba700  2 req 0 0.000000000s initializing for trans_id = 
   -55> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s rgw api priority: s3=8 s3website=7
   -54> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s host=s3gw.xxx.sslip.io
   -53> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s meta>> HTTP_X_AMZ_CONTENT_SHA256
   -52> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s meta>> HTTP_X_AMZ_COPY_SOURCE
   -51> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s meta>> HTTP_X_AMZ_DATE
   -50> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s x>> x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
   -49> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s x>> x-amz-copy-source:test09/file3.txt
   -48> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s x>> x-amz-date:20230523T163037Z
   -47> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s handler=22RGWHandler_REST_Obj_S3
   -46> 2023-05-23T16:30:38.328+0000 7fda620ba700  2 req 0 0.000000000s getting op 1
   -45> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s s3:copy_obj scheduling with throttler client=2 cost=1
   -44> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s s3:copy_obj op=22RGWCopyObj_ObjStore_S3
   -43> 2023-05-23T16:30:38.328+0000 7fda620ba700  2 req 0 0.000000000s s3:copy_obj verifying requester
   -42> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s v4 signature format = c92ce6ac7bb8e919924220ad3fd72340ff3c4ada64b42283331351f40f08021f
   -41> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s v4 credential format = test/20230523/us-east-1/s3/aws4_request
   -40> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s access key id = test
   -39> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s credential scope = 20230523/us-east-1/s3/aws4_request
   -38> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s canonical headers format = host:s3gw.xxx.sslip.io
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-copy-source:test09/file3.txt
x-amz-date:20230523T163037Z

   -37> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s payload request hash = e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
   -36> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s canonical request = PUT
/test09/file3.txt

host:s3gw.xxx.sslip.io
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-copy-source:test09/file3.txt
x-amz-date:20230523T163037Z

host;x-amz-content-sha256;x-amz-copy-source;x-amz-date
e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
   -35> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s canonical request hash = 8ad97132192e2f51dab0b82937033fc51be6601d298cea8c87c721792379ab60
   -34> 2023-05-23T16:30:38.328+0000 7fda620ba700 10 req 0 0.000000000s string to sign = AWS4-HMAC-SHA256
20230523T163037Z
20230523/us-east-1/s3/aws4_request
8ad97132192e2f51dab0b82937033fc51be6601d298cea8c87c721792379ab60
   -33> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s date_k    = c38a65e317e028738dc307ca47c0118ae7509e74f69cad40910270fae8bcddcd
   -32> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s region_k  = 1e47545cb6663f578f67e3f9a90dfde06c0d693d30ba077f10ad1bc69c8d78a9
   -31> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s service_k = c2dfb24f9bdda6a34fada665ea7c984b9fd8e80439c72079791ed30040c35276
   -30> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s signing_k = 66f03664efad9a65cda606dcd0797a493620cd1e4c5438c2a4f5229c1ffc2b6c
   -29> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s generated signature = c92ce6ac7bb8e919924220ad3fd72340ff3c4ada64b42283331351f40f08021f
   -28> 2023-05-23T16:30:38.332+0000 7fda620ba700 15 req 0 0.004000050s s3:copy_obj string_to_sign=AWS4-HMAC-SHA256
20230523T163037Z
20230523/us-east-1/s3/aws4_request
8ad97132192e2f51dab0b82937033fc51be6601d298cea8c87c721792379ab60
   -27> 2023-05-23T16:30:38.332+0000 7fda620ba700 15 req 0 0.004000050s s3:copy_obj server signature=c92ce6ac7bb8e919924220ad3fd72340ff3c4ada64b42283331351f40f08021f
   -26> 2023-05-23T16:30:38.332+0000 7fda620ba700 15 req 0 0.004000050s s3:copy_obj client signature=c92ce6ac7bb8e919924220ad3fd72340ff3c4ada64b42283331351f40f08021f
   -25> 2023-05-23T16:30:38.332+0000 7fda620ba700 15 req 0 0.004000050s s3:copy_obj compare=0
   -24> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj normalizing buckets and tenants
   -23> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s s->object=file3.txt s->bucket=test09
   -22> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj init permissions
   -21> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s s3:copy_obj get_bucket: bucket: test09
   -20> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s s3:copy_obj get_bucket: bucket: test09
   -19> 2023-05-23T16:30:38.332+0000 7fda620ba700 15 req 0 0.004000050s s3:copy_obj decode_policy Read AccessControlPolicy<AccessControlPolicy xmlns="http://s3.amazonaws.com/doc/2006-03-01/"><Owner><ID>testid</ID><DisplayName>M. Tester</DisplayName></Owner><AccessControlList><Grant><Grantee xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="CanonicalUser"><ID>testid</ID><DisplayName>M. Tester</DisplayName></Grantee><Permission>FULL_CONTROL</Permission></Grant></AccessControlList></AccessControlPolicy>
   -18> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj recalculating target
   -17> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj reading permissions
   -16> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj init op
   -15> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 get_quota: TODO
   -14> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj verifying op mask
   -13> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj verifying op permissions
   -12> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s s3:copy_obj get_bucket: bucket: test09
   -11> 2023-05-23T16:30:38.332+0000 7fda620ba700 15 req 0 0.004000050s s3:copy_obj decode_policy Read AccessControlPolicy<AccessControlPolicy xmlns="http://s3.amazonaws.com/doc/2006-03-01/"><Owner><ID>testid</ID><DisplayName>M. Tester</DisplayName></Owner><AccessControlList><Grant><Grantee xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="CanonicalUser"><ID>testid</ID><DisplayName>M. Tester</DisplayName></Grantee><Permission>FULL_CONTROL</Permission></Grant></AccessControlList></AccessControlPolicy>
   -10> 2023-05-23T16:30:38.332+0000 7fda620ba700  0 req 0 0.004000050s s3:copy_obj This copy request is illegal because it is trying to copy an object to itself without changing the object's metadata, storage class, website redirect location or encryption attributes.
    -9> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 overriding permissions due to admin operation
    -8> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj verifying op params
    -7> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj pre-executing
    -6> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj check rate limiting
    -5> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 req 0 0.004000050s s3:copy_obj executing
    -4> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s s3:copy_obj x>> x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
    -3> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s s3:copy_obj x>> x-amz-copy-source:test09/file3.txt
    -2> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 req 0 0.004000050s s3:copy_obj x>> x-amz-date:20230523T163037Z
    -1> 2023-05-23T16:30:38.332+0000 7fda620ba700 10 get_notification: return stub notification
     0> 2023-05-23T16:30:38.336+0000 7fda620ba700 -1 *** Caught signal (Segmentation fault) **
 in thread 7fda620ba700 thread_name:radosgw

 ceph version Development (no_version) reef (dev)
 1: /lib64/libpthread.so.0(+0x168c0) [0x7fda7c4368c0]
 2: (RGWCopyObj::execute(optional_yield)+0x727) [0x556bf8d07ee7]
 3: (rgw_process_authenticated(RGWHandler_REST*, RGWOp*&, RGWRequest*, req_state*, optional_yield, rgw::sal::Driver*, bool)+0xca4) [0x556bf8ab1f24]
 4: (process_request(RGWProcessEnv const&, RGWRequest*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, RGWRestfulIO*, optional_yield, rgw::dmclock::Scheduler*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >*, std::chrono::duration<unsigned long, std::ratio<1l, 1000000000l> >*, int*)+0x25b6) [0x556bf8ab5206]
 5: radosgw(+0xb70a53) [0x556bf89e0a53]
 6: radosgw(+0xb718e6) [0x556bf89e18e6]
 7: make_fcontext()
 NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- logging levels ---
   0/ 5 none
   0/ 1 lockdep
   0/ 1 context
   1/ 1 crush
   1/ 5 mds
   1/ 5 mds_balancer
   1/ 5 mds_locker
   1/ 5 mds_log
   1/ 5 mds_log_expire
   1/ 5 mds_migrator
   0/ 1 buffer
   0/ 1 timer
   0/ 1 filer
   0/ 1 striper
   0/ 1 objecter
   0/ 5 rados
   0/ 5 rbd
   0/ 5 rbd_mirror
   0/ 5 rbd_replay
   0/ 5 rbd_pwl
   0/ 5 journaler
   0/ 5 objectcacher
   0/ 5 immutable_obj_cache
   0/ 5 client
   1/ 5 osd
   0/ 5 optracker
   0/ 5 objclass
   1/ 3 filestore
   1/ 3 journal
   0/ 0 ms
   1/ 5 mon
   0/10 monc
   1/ 5 paxos
   0/ 5 tp
   1/ 5 auth
   1/ 5 crypto
   1/ 1 finisher
   1/ 1 reserver
   1/ 5 heartbeatmap
   1/ 5 perfcounter
  15/15 rgw
   1/ 5 rgw_sync
   1/ 5 rgw_datacache
   1/ 5 rgw_access
   1/ 5 rgw_dbstore
   1/ 5 rgw_flight
   1/ 5 javaclient
   1/ 5 asok
   1/ 1 throttle
   0/ 0 refs
   1/ 5 compressor
   1/ 5 bluestore
   1/ 5 bluefs
   1/ 3 bdev
   1/ 5 kstore
   4/ 5 rocksdb
   4/ 5 leveldb
   1/ 5 fuse
   2/ 5 mgr
   1/ 5 mgrc
   1/ 5 dpdk
   1/ 5 eventtrace
   1/ 5 prioritycache
   0/ 5 test
   0/ 5 cephfs_mirror
   0/ 5 cephsqlite
   0/ 5 seastore
   0/ 5 seastore_onode
   0/ 5 seastore_odata
   0/ 5 seastore_omap
   0/ 5 seastore_tm
   0/ 5 seastore_t
   0/ 5 seastore_cleaner
   0/ 5 seastore_epm
   0/ 5 seastore_lba
   0/ 5 seastore_fixedkv_tree
   0/ 5 seastore_cache
   0/ 5 seastore_journal
   0/ 5 seastore_device
   0/ 5 seastore_backref
   0/ 5 alienstore
   1/ 5 mclock
   0/ 5 cyanstore
   1/ 5 ceph_exporter
   1/ 5 memstore
  -2/-2 (syslog threshold)
  99/99 (stderr threshold)
--- pthread ID / name mapping for recent threads ---
  7fda620ba700 / radosgw
  7fda630bc700 / radosgw
  7fda6a0ca700 / radosgw
  7fda6c8ee700 / lifecycle_thr_2
  7fda6e8f2700 / lifecycle_thr_1
  7fda708f6700 / lifecycle_thr_0
  7fda728fa700 / rgw_gc
  7fda74105700 / kmip worker
  7fda76109700 / admin_socket
  7fda7710b700 / safe_timer
  7fda77922f80 / radosgw
  max_recent     10000
  max_new         1000
  log_file /var/lib/ceph/crash/2023-05-23T16:30:38.339143Z_1a30db34-3ab6-477b-b272-50aaa4880a97/log
--- end dump of recent events ---
reraise_fatal: default handler for signal 11 didn't terminate the process?
jecluis commented 1 year ago

Lets push this until after the versioning and atomic writer go through its reworkings. We can check back then.

0xavi0 commented 1 year ago

I suspect I might need to re-visit this (or at least the get part of it) when doing the versioning work.

votdev commented 1 year ago

I can confirm that there is a Bug in sfs because copyObject works when the UI is connected to a Ceph RGW (using Rados).

Peek 2023-05-24 11-16

jhmarina commented 1 year ago

This issue will be fixed as part of the work being done for versioning in the Epic

0xavi0 commented 1 year ago

I think this is a copy of: https://github.com/aquarist-labs/s3gw/issues/183 I opened a bug upstream and it was fixed in this PR

The copy fails because it is trying to copy the object to itself.

It is detected by the verify_permissions call in rgw_op but is overwritten because the user is admin

   -10> 2023-05-23T16:30:38.332+0000 7fda620ba700  0 req 0 0.004000050s s3:copy_obj This copy request is illegal because it is trying to copy an object to itself without changing the object's metadata, storage class, website redirect location or encryption attributes.
    -9> 2023-05-23T16:30:38.332+0000 7fda620ba700  2 overriding permissions due to admin operation

The PR was merged upstream, so I would re-test this when we do next rebase.

jhmarina commented 1 year ago

I'm moving this to the blocked column since we need to wait for a rebase

votdev commented 1 year ago

It seems the issue has been fixed in the latest s3gw/ceph repo (for v0.18), maybe by https://github.com/aquarist-labs/ceph/pull/153. I can restore a versioned object successfully.

Peek 2023-06-12 13-44

The only problem is that the mtime property of a deleted object is still the time the file was created instead of the time the file was deleted. This issue breaks the order of the versions. See https://github.com/aquarist-labs/s3gw/issues/547

Bildschirmfoto vom 2023-06-12 13-43-43

jhmarina commented 1 year ago

Closing this issue since it is a duplicate of https://github.com/aquarist-labs/s3gw/issues/183