|
"ts","@host","@rawstring"
|
|
"22:04:28.429","dev-10-74-0-74","2022-11-02T22:04:28.429-0400 7f07b255b700 20 req 15462255817190376745 0.058000408s s3:put_obj WARNING: blocking librados call"
|
|
"22:04:28.429","dev-10-74-0-74","2022-11-02T22:04:28.429-0400 7f07b255b700 -1 req 15462255817190376745 0.058000408s s3:put_obj int rgw::cls::fifo::FIFO::push_entries(const DoutPrefixProvider*, const std::deque<ceph::buffer::v15_2_0::list>&, uint64_t, optional_yield):1165 blp calling push_part part_oid=data_log.127.WkMkUiakL0/.6 head_part_num 6 tag h3s2iIcPp6nE1EIB tid=72267"
|
|
"22:04:28.429","dev-10-74-0-74","2022-11-02T22:04:28.429-0400 7f07b255b700 20 req 15462255817190376745 0.058000408s s3:put_obj int rgw::cls::fifo::FIFO::push_entries(const DoutPrefixProvider*, const std::deque<ceph::buffer::v15_2_0::list>&, uint64_t, optional_yield):1157 entering: tid=72267"
|
|
"22:04:28.429","dev-10-74-0-74","2022-11-02T22:04:28.429-0400 7f07b255b700 20 req 15462255817190376745 0.058000408s s3:put_obj int rgw::cls::fifo::FIFO::push(const DoutPrefixProvider*, const std::vector<ceph::buffer::v15_2_0::list>&, optional_yield):1448 prepared push: remaining=0 batch=1 retries=0 batch_len=172 tid=72267"
|
|
"22:04:28.429","dev-10-74-0-74","2022-11-02T22:04:28.429-0400 7f07b255b700 20 req 15462255817190376745 0.058000408s s3:put_obj int rgw::cls::fifo::FIFO::push(const DoutPrefixProvider*, const std::vector<ceph::buffer::v15_2_0::list>&, optional_yield):1428 preparing push: remaining=1 batch=0 retries=0 tid=72267"
|
|
"22:04:28.429","dev-10-74-0-74","2022-11-02T22:04:28.429-0400 7f07b255b700 20 req 15462255817190376745 0.058000408s s3:put_obj int rgw::cls::fifo::FIFO::push(const DoutPrefixProvider*, const std::vector<ceph::buffer::v15_2_0::list>&, optional_yield):1391 entering: tid=72267"
|
|
"22:04:28.429","dev-10-74-0-74","2022-11-02T22:04:28.429-0400 7f07b255b700 20 req 15462255817190376745 0.058000408s s3:put_obj RGWDataChangesLog::add_entry() sending update with now=2022-11-02T22:04:28.430363-0400 cur_expiration=2022-11-02T22:04:58.430363-0400"
|
|
"22:04:28.429","dev-10-74-0-74","2022-11-02T22:04:28.429-0400 7f07b255b700 20 req 15462255817190376745 0.058000408s s3:put_obj blp RGWDataChangesLog::add_entry() bucket.name=cosinc10-dev-2k-thisisbcstestload00340 shard_id=6gen.gen0 now=2022-11-02T22:04:28.430363-0400 cur_expiration=1969-12-31T19:00:00.000000-0500"
|
|
"22:04:28.429","dev-10-74-0-74","2022-11-02T22:04:28.429-0400 7f07b255b700 20 req 15462255817190376745 0.058000408s s3:put_obj couldn't put bucket_sync_policy cache entry, might have raced with data changes"
|
|
"22:04:28.429","dev-10-74-0-74","2022-11-02T22:04:28.429-0400 7f07b255b700 20 req 15462255817190376745 0.058000408s s3:put_obj chain_cache_entry: couldn't find cache locator"
|
|
"22:04:28.429","dev-10-74-0-74","2022-11-02T22:04:28.429-0400 7f07b255b700 10 req 15462255817190376745 0.058000408s s3:put_obj chain_cache_entry: cache_locator="
|
|
"22:04:28.429","dev-10-74-0-74","2022-11-02T22:04:28.429-0400 7f07b255b700 20 req 15462255817190376745 0.058000408s s3:put_obj reflect(): flow manager (bucket=): adding dest pipe: {s={b=*,z=43e66047-e6b5-472d-8813-6224a31ce963,az=0},d={b=*,z=efbc7556-9443-4b58-b3d9-ee2c31880b2b,az=0}}"
|
|
"22:04:28.429","dev-10-74-0-74","2022-11-02T22:04:28.429-0400 7f07b255b700 20 req 15462255817190376745 0.058000408s s3:put_obj reflect(): flow manager (bucket=): adding source pipe: {s={b=*,z=efbc7556-9443-4b58-b3d9-ee2c31880b2b,az=0},d={b=*,z=43e66047-e6b5-472d-8813-6224a31ce963,az=0}}"
|
|
"22:04:28.429","dev-10-74-0-74","2022-11-02T22:04:28.429-0400 7f07b255b700 20 req 15462255817190376745 0.058000408s s3:put_obj reflect(): flow manager (bucket=cosinc10-dev-2k-thisisbcstestload00340:43e66047-e6b5-472d-8813-6224a31ce963.5353.5830): adding dest pipe: {s={b=cosinc10-dev-2k-thisisbcstestload00340:43e66047-e6b5-472d-8813-6224a31ce963.5353.5830,z=43e66047-e6b5-472d-8813-6224a31ce963,az=0},d={b=cosinc10-dev-2k-thisisbcstestload00340:43e66047-e6b5-472d-8813-6224a31ce963.5353.5830,z=efbc7556-9443-4b58-b3d9-ee2c31880b2b,az=0}}"
|
|
"22:04:28.429","dev-10-74-0-74","2022-11-02T22:04:28.429-0400 7f07b255b700 20 req 15462255817190376745 0.058000408s s3:put_obj reflect(): flow manager (bucket=cosinc10-dev-2k-thisisbcstestload00340:43e66047-e6b5-472d-8813-6224a31ce963.5353.5830): adding source pipe: {s={b=cosinc10-dev-2k-thisisbcstestload00340:43e66047-e6b5-472d-8813-6224a31ce963.5353.5830,z=efbc7556-9443-4b58-b3d9-ee2c31880b2b,az=0},d={b=cosinc10-dev-2k-thisisbcstestload00340:43e66047-e6b5-472d-8813-6224a31ce963.5353.5830,z=43e66047-e6b5-472d-8813-6224a31ce963,az=0}}"
|
|
"22:04:28.429","dev-10-74-0-74","2022-11-02T22:04:28.429-0400 7f07b255b700 10 req 15462255817190376745 0.058000408s s3:put_obj cache get: name=dev-zone-bcc-master.rgw.log++bucket.sync-target-hints.cosinc10-dev-2k-thisisbcstestload00340 : hit (negative entry)"
|
|
"22:04:28.429","dev-10-74-0-74","2022-11-02T22:04:28.429-0400 7f07b255b700 10 req 15462255817190376745 0.058000408s s3:put_obj moving dev-zone-bcc-master.rgw.log++bucket.sync-target-hints.cosinc10-dev-2k-thisisbcstestload00340 to cache LRU end"
|
|
"22:04:28.429","dev-10-74-0-74","2022-11-02T22:04:28.429-0400 7f07b255b700 20 req 15462255817190376745 0.058000408s s3:put_obj cache get: touching lru, lru_counter=13687227 promotion_ts=13680487"
|
|
"22:04:28.429","dev-10-74-0-74","2022-11-02T22:04:28.429-0400 7f07b255b700 10 req 15462255817190376745 0.058000408s s3:put_obj cache get: name=dev-zone-bcc-master.rgw.log++bucket.sync-source-hints.cosinc10-dev-2k-thisisbcstestload00340 : hit (negative entry)"
|
|
"22:04:28.429","dev-10-74-0-74","2022-11-02T22:04:28.429-0400 7f07b255b700 10 req 15462255817190376745 0.058000408s s3:put_obj moving dev-zone-bcc-master.rgw.log++bucket.sync-source-hints.cosinc10-dev-2k-thisisbcstestload00340 to cache LRU end"
|
|
"22:04:28.429","dev-10-74-0-74","2022-11-02T22:04:28.429-0400 7f07b255b700 20 req 15462255817190376745 0.058000408s s3:put_obj cache get: touching lru, lru_counter=13687226 promotion_ts=13680486"
|
|
"22:04:28.400","dev-10-74-0-74","2022-11-02T22:04:28.400-0400 7f07b255b700 20 req 15462255817190376745 0.029000204s s3:put_obj WARNING: blocking librados call"
|
|
"22:04:02.240","dev-10-74-0-74","2022-11-02T22:04:02.240-0400 7f0894f20700 -1 req 5088696114136079603 0.045000315s s3:put_obj int rgw::cls::fifo::FIFO::push_entries(const DoutPrefixProvider*, const std::deque<ceph::buffer::v15_2_0::list>&, uint64_t, optional_yield):1165 blp calling push_part part_oid=data_log.114.2ixwYv5zF9P.7 head_part_num 7 tag 9oUCBoB2pnAK9zne tid=72267"
|
|
"22:04:02.240","dev-10-74-0-74","2022-11-02T22:04:02.240-0400 7f0894f20700 20 req 5088696114136079603 0.045000315s s3:put_obj int rgw::cls::fifo::FIFO::push_entries(const DoutPrefixProvider*, const std::deque<ceph::buffer::v15_2_0::list>&, uint64_t, optional_yield):1157 entering: tid=72267"
|
|
"22:04:02.240","dev-10-74-0-74","2022-11-02T22:04:02.240-0400 7f0894f20700 20 req 5088696114136079603 0.045000315s s3:put_obj int rgw::cls::fifo::FIFO::push(const DoutPrefixProvider*, const std::vector<ceph::buffer::v15_2_0::list>&, optional_yield):1448 prepared push: remaining=0 batch=1 retries=0 batch_len=172 tid=72267"
|
|
"22:04:02.240","dev-10-74-0-74","2022-11-02T22:04:02.240-0400 7f0894f20700 20 req 5088696114136079603 0.045000315s s3:put_obj int rgw::cls::fifo::FIFO::push(const DoutPrefixProvider*, const std::vector<ceph::buffer::v15_2_0::list>&, optional_yield):1428 preparing push: remaining=1 batch=0 retries=0 tid=72267"
|
|
"22:04:02.240","dev-10-74-0-74","2022-11-02T22:04:02.240-0400 7f0894f20700 20 req 5088696114136079603 0.045000315s s3:put_obj int rgw::cls::fifo::FIFO::push(const DoutPrefixProvider*, const std::vector<ceph::buffer::v15_2_0::list>&, optional_yield):1391 entering: tid=72267"
|
|
"22:04:24.898","dev-10-74-0-74","2022-11-02T22:04:24.898-0400 7f06c237b700 -1 req 15581787109761966335 0.063000441s s3:put_obj int rgw::cls::fifo::FIFO::push_entries(const DoutPrefixProvider*, const std::deque<ceph::buffer::v15_2_0::list>&, uint64_t, optional_yield):1165 blp calling push_part part_oid=data_log.16.EM0H4xMBlrv.6 head_part_num 6 tag qIj7uFfRtglum6kL tid=72267"
|
|
"22:04:24.898","dev-10-74-0-74","2022-11-02T22:04:24.898-0400 7f06c237b700 20 req 15581787109761966335 0.063000441s s3:put_obj int rgw::cls::fifo::FIFO::push_entries(const DoutPrefixProvider*, const std::deque<ceph::buffer::v15_2_0::list>&, uint64_t, optional_yield):1157 entering: tid=72267"
|
|
"22:04:24.898","dev-10-74-0-74","2022-11-02T22:04:24.898-0400 7f06c237b700 20 req 15581787109761966335 0.063000441s s3:put_obj int rgw::cls::fifo::FIFO::push(const DoutPrefixProvider*, const std::vector<ceph::buffer::v15_2_0::list>&, optional_yield):1448 prepared push: remaining=0 batch=1 retries=0 batch_len=172 tid=72267"
|
|
"22:04:24.898","dev-10-74-0-74","2022-11-02T22:04:24.898-0400 7f06c237b700 20 req 15581787109761966335 0.063000441s s3:put_obj int rgw::cls::fifo::FIFO::push(const DoutPrefixProvider*, const std::vector<ceph::buffer::v15_2_0::list>&, optional_yield):1428 preparing push: remaining=1 batch=0 retries=0 tid=72267"
|
|
"22:04:24.898","dev-10-74-0-74","2022-11-02T22:04:24.898-0400 7f06c237b700 20 req 15581787109761966335 0.063000441s s3:put_obj int rgw::cls::fifo::FIFO::push(const DoutPrefixProvider*, const std::vector<ceph::buffer::v15_2_0::list>&, optional_yield):1391 entering: tid=72267"
|
|
"22:04:28.532","dev-10-74-0-74","2022-11-02T22:04:28.532-0400 7f0679aea700 2 req 15462255817190376745 0.161001116s s3:put_obj http status=200"
|
|
"22:04:28.532","dev-10-74-0-74","2022-11-02T22:04:28.532-0400 7f0679aea700 2 req 15462255817190376745 0.161001116s s3:put_obj op status=0"
|
|
"22:04:28.532","dev-10-74-0-74","2022-11-02T22:04:28.532-0400 7f0679aea700 10 req 15462255817190376745 0.161001116s cache get: name=dev-zone-bcc-master.rgw.log++script.postrequest. : hit (negative entry)"
|
|
"22:04:28.532","dev-10-74-0-74","2022-11-02T22:04:28.532-0400 7f07b255b700 2 req 15462255817190376745 0.161001116s s3:put_obj completing"
|
|
"22:04:28.532","dev-10-74-0-74","2022-11-02T22:04:28.532-0400 7f07b255b700 -1 req 15462255817190376745 0.161001116s s3:put_obj ERROR: failed writing data log"
|
|
"22:04:28.532","dev-10-74-0-74","2022-11-02T22:04:28.532-0400 7f07b255b700 -1 req 15462255817190376745 0.161001116s s3:put_obj virtual int RGWDataChangesFIFO::push(const DoutPrefixProvider*, int, ceph::real_time, const string&, ceph::buffer::v15_2_0::list&&)blp: unable to push to FIFO: data_log.127: (5) Input/output error"
|
|
"22:04:28.532","dev-10-74-0-74","2022-11-02T22:04:28.532-0400 7f07b255b700 -1 req 15462255817190376745 0.161001116s s3:put_obj int rgw::cls::fifo::FIFO::push(const DoutPrefixProvider*, const std::vector<ceph::buffer::v15_2_0::list>&, optional_yield):1464 prepare_new_head failed: r=-5 tid=72267"
|
|
"22:04:28.532","dev-10-74-0-74","2022-11-02T22:04:28.532-0400 7f07b255b700 -1 req 15462255817190376745 0.161001116s s3:put_obj int rgw::cls::fifo::FIFO::_prepare_new_head(const DoutPrefixProvider*, int64_t, uint64_t, optional_yield):870 inconsistency, push part less than head part: tid=72267"
|
|
"22:04:28.532","dev-10-74-0-74","2022-11-02T22:04:28.532-0400 7f07b255b700 -1 req 15462255817190376745 0.161001116s s3:put_obj int rgw::cls::fifo::FIFO::process_journal(const DoutPrefixProvider*, uint64_t, optional_yield):674 processing entry failed: entry=op: Op::create, part_num: 6, part_tag: 4wzV7UX5fcP6Mnb1 r=-17 tid=72267"
|
|
"22:04:28.532","dev-10-74-0-74","2022-11-02T22:04:28.532-0400 7f07b255b700 -1 req 15462255817190376745 0.161001116s s3:put_obj int rgw::cls::fifo::FIFO::create_part(const DoutPrefixProvider*, int64_t, std::string_view, uint64_t, optional_yield):597 part_init failed: r=-17 tid=72267"
|
|
"22:04:30.183","dev-10-74-0-74","2022-11-02T22:04:30.183-0400 7f08e3fbe700 -1 req 8424495382838603123 0.038000267s s3:put_obj int rgw::cls::fifo::FIFO::push_entries(const DoutPrefixProvider*, const std::deque<ceph::buffer::v15_2_0::list>&, uint64_t, optional_yield):1165 blp calling push_part part_oid=data_log.96.eOJIEsf2D1+.6 head_part_num 6 tag mUhZeU7zxFWXMOx4 tid=72267"
|
|
"22:04:30.183","dev-10-74-0-74","2022-11-02T22:04:30.183-0400 7f08e3fbe700 20 req 8424495382838603123 0.038000267s s3:put_obj int rgw::cls::fifo::FIFO::push_entries(const DoutPrefixProvider*, const std::deque<ceph::buffer::v15_2_0::list>&, uint64_t, optional_yield):1157 entering: tid=72267"
|
|
"22:04:30.183","dev-10-74-0-74","2022-11-02T22:04:30.183-0400 7f08e3fbe700 20 req 8424495382838603123 0.038000267s s3:put_obj int rgw::cls::fifo::FIFO::push(const DoutPrefixProvider*, const std::vector<ceph::buffer::v15_2_0::list>&, optional_yield):1448 prepared push: remaining=0 batch=1 retries=0 batch_len=172 tid=72267"
|
|
"22:04:30.183","dev-10-74-0-74","2022-11-02T22:04:30.183-0400 7f08e3fbe700 20 req 8424495382838603123 0.038000267s s3:put_obj int rgw::cls::fifo::FIFO::push(const DoutPrefixProvider*, const std::vector<ceph::buffer::v15_2_0::list>&, optional_yield):1428 preparing push: remaining=1 batch=0 retries=0 tid=72267"
|
|
"22:04:30.183","dev-10-74-0-74","2022-11-02T22:04:30.183-0400 7f08e3fbe700 20 req 8424495382838603123 0.038000267s s3:put_obj int rgw::cls::fifo::FIFO::push(const DoutPrefixProvider*, const std::vector<ceph::buffer::v15_2_0::list>&, optional_yield):1391 entering: tid=72267"
|
|
"22:04:28.505","dev-10-74-0-74","2022-11-02T22:04:28.505-0400 7f07b255b700 20 req 15462255817190376745 0.134000942s s3:put_obj WARNING: blocking librados call"
|
|
"22:04:28.505","dev-10-74-0-74","2022-11-02T22:04:28.505-0400 7f07b255b700 20 req 15462255817190376745 0.134000942s s3:put_obj int rgw::cls::fifo::FIFO::create_part(const DoutPrefixProvider*, int64_t, std::string_view, uint64_t, optional_yield):586 entering: tid=72267"
|
|
"22:04:28.505","dev-10-74-0-74","2022-11-02T22:04:28.505-0400 7f07b255b700 20 req 15462255817190376745 0.134000942s s3:put_obj int rgw::cls::fifo::FIFO::process_journal(const DoutPrefixProvider*, uint64_t, optional_yield):643blp create entry.part_num 6entry.part_tag 4wzV7UX5fcP6Mnb1 tid=72267"
|
|
"22:04:28.505","dev-10-74-0-74","2022-11-02T22:04:28.505-0400 7f07b255b700 20 req 15462255817190376745 0.134000942s s3:put_obj int rgw::cls::fifo::FIFO::process_journal(const DoutPrefixProvider*, uint64_t, optional_yield):638 processing entry: entry=op: Op::create, part_num: 6, part_tag: 4wzV7UX5fcP6Mnb1 tid=72267"
|
|
"22:04:28.505","dev-10-74-0-74","2022-11-02T22:04:28.505-0400 7f07b255b700 20 req 15462255817190376745 0.134000942s s3:put_obj int rgw::cls::fifo::FIFO::process_journal(const DoutPrefixProvider*, uint64_t, optional_yield):625blp entering: tid=72267"
|
|
"22:04:28.505","dev-10-74-0-74","2022-11-02T22:04:28.505-0400 7f07b255b700 20 req 15462255817190376745 0.134000942s s3:put_obj int rgw::cls::fifo::FIFO::_prepare_new_part(const DoutPrefixProvider*, int64_t, bool, uint64_t, optional_yield):811blp raced, journaled but not processed: i=1 tid=72267"
|
|
"22:04:28.505","dev-10-74-0-74","2022-11-02T22:04:28.505-0400 7f07b255b700 20 req 15462255817190376745 0.134000942s s3:put_obj int rgw::cls::fifo::FIFO::_update_meta(const DoutPrefixProvider*, const rados::cls::fifo::update&, rados::cls::fifo::objv, bool*, uint64_t, optional_yield):484 canceled: tid=72267"
|
|
"22:04:28.501","dev-10-74-0-74","2022-11-02T22:04:28.501-0400 7f07b255b700 20 req 15462255817190376745 0.130000919s s3:put_obj WARNING: blocking librados call"
|
|
"22:04:28.501","dev-10-74-0-74","2022-11-02T22:04:28.501-0400 7f07b255b700 20 req 15462255817190376745 0.130000919s s3:put_obj int rgw::cls::fifo::FIFO::read_meta(const DoutPrefixProvider*, uint64_t, optional_yield):1289 entering: tid=72267"
|
|
"22:04:28.501","dev-10-74-0-74","2022-11-02T22:04:28.501-0400 7f07b255b700 -1 req 15462255817190376745 0.130000919s s3:put_obj int rgw::cls::fifo::FIFO::apply_update(const DoutPrefixProvider*, rados::cls::fifo::info*, const rados::cls::fifo::objv&, const rados::cls::fifo::update&, uint64_t):444 version mismatch, canceling: tid=72267"
|
|
"22:04:28.501","dev-10-74-0-74","2022-11-02T22:04:28.501-0400 7f07b255b700 20 req 15462255817190376745 0.130000919s s3:put_obj int rgw::cls::fifo::FIFO::apply_update(const DoutPrefixProvider*, rados::cls::fifo::info*, const rados::cls::fifo::objv&, const rados::cls::fifo::update&, uint64_t):440 entering: tid=72267"
|
|
"22:04:28.479","dev-10-74-0-74","2022-11-02T22:04:28.479-0400 7f07b255b700 20 req 15462255817190376745 0.108000755s s3:put_obj WARNING: blocking librados call"
|
|
"22:04:28.479","dev-10-74-0-74","2022-11-02T22:04:28.479-0400 7f07b255b700 20 req 15462255817190376745 0.108000755s s3:put_obj int rgw::cls::fifo::FIFO::_update_meta(const DoutPrefixProvider*, const rados::cls::fifo::update&, rados::cls::fifo::objv, bool*, uint64_t, optional_yield):465 entering: tid=72267"
|
|
"22:04:28.479","dev-10-74-0-74","2022-11-02T22:04:28.479-0400 7f07b255b700 20 req 15462255817190376745 0.108000755s s3:put_obj int rgw::cls::fifo::FIFO::_prepare_new_part(const DoutPrefixProvider*, int64_t, bool, uint64_t, optional_yield):796blp updating metadata: i=1 tid=72267"
|
|
"22:04:28.479","dev-10-74-0-74","2022-11-02T22:04:28.479-0400 7f07b255b700 20 req 15462255817190376745 0.108000755s s3:put_obj int rgw::cls::fifo::FIFO::_update_meta(const DoutPrefixProvider*, const rados::cls::fifo::update&, rados::cls::fifo::objv, bool*, uint64_t, optional_yield):484 canceled: tid=72267"
|
|
"22:04:28.470","dev-10-74-0-74","2022-11-02T22:04:28.470-0400 7f07b255b700 20 req 15462255817190376745 0.099000692s s3:put_obj WARNING: blocking librados call"
|
|
"22:04:28.470","dev-10-74-0-74","2022-11-02T22:04:28.470-0400 7f07b255b700 20 req 15462255817190376745 0.099000692s s3:put_obj int rgw::cls::fifo::FIFO::read_meta(const DoutPrefixProvider*, uint64_t, optional_yield):1289 entering: tid=72267"
|
|
"22:04:28.453","dev-10-74-0-74","2022-11-02T22:04:28.453-0400 7f07b255b700 20 req 15462255817190376745 0.082000576s s3:put_obj WARNING: blocking librados call"
|
|
"22:04:28.453","dev-10-74-0-74","2022-11-02T22:04:28.453-0400 7f07b255b700 20 req 15462255817190376745 0.082000576s s3:put_obj int rgw::cls::fifo::FIFO::_update_meta(const DoutPrefixProvider*, const rados::cls::fifo::update&, rados::cls::fifo::objv, bool*, uint64_t, optional_yield):465 entering: tid=72267"
|
|
"22:04:28.453","dev-10-74-0-74","2022-11-02T22:04:28.453-0400 7f07b255b700 20 req 15462255817190376745 0.082000576s s3:put_obj int rgw::cls::fifo::FIFO::_prepare_new_part(const DoutPrefixProvider*, int64_t, bool, uint64_t, optional_yield):796blp updating metadata: i=0 tid=72267"
|
|
"22:04:28.453","dev-10-74-0-74","2022-11-02T22:04:28.453-0400 7f07b255b700 20 req 15462255817190376745 0.082000576s s3:put_obj int rgw::cls::fifo::FIFO::_prepare_new_part(const DoutPrefixProvider*, int64_t, bool, uint64_t, optional_yield):784blp tid=72267 jentries.front().part_num 7 jentries.back().part_num 7"
|
|
"22:04:28.453","dev-10-74-0-74","2022-11-02T22:04:28.453-0400 7f07b255b700 20 req 15462255817190376745 0.082000576s s3:put_obj int rgw::cls::fifo::FIFO::_prepare_new_part(const DoutPrefixProvider*, int64_t, bool, uint64_t, optional_yield):779blp needs new head: tid=72267"
|
|
"22:04:28.453","dev-10-74-0-74","2022-11-02T22:04:28.453-0400 7f07b255b700 5 req 15462255817190376745 0.082000576s s3:put_obj int rgw::cls::fifo::FIFO::_prepare_new_part(const DoutPrefixProvider*, int64_t, bool, uint64_t, optional_yield):772blp new_part_num 7 is_head 1 version a2lqXIRnGQfmStV8{29} tid=72267"
|
|
"22:04:28.453","dev-10-74-0-74","2022-11-02T22:04:28.453-0400 7f07b255b700 20 req 15462255817190376745 0.082000576s s3:put_obj int rgw::cls::fifo::FIFO::_prepare_new_part(const DoutPrefixProvider*, int64_t, bool, uint64_t, optional_yield):755blp entering: tid=72267"
|
|
"22:04:28.453","dev-10-74-0-74","2022-11-02T22:04:28.453-0400 7f07b255b700 20 req 15462255817190376745 0.082000576s s3:put_obj int rgw::cls::fifo::FIFO::_prepare_new_head(const DoutPrefixProvider*, int64_t, uint64_t, optional_yield):859 need new part: tid=72267"
|
|
"22:04:28.453","dev-10-74-0-74","2022-11-02T22:04:28.453-0400 7f07b255b700 1 req 15462255817190376745 0.082000576s s3:put_obj int rgw::cls::fifo::FIFO::_prepare_new_head(const DoutPrefixProvider*, int64_t, uint64_t, optional_yield):847blp tid=72267 info.head_part_num: 6 max_push_part_num: 6 new_head_part_num: 7 info.part_oid(new_head_part_num): data_log.127.WkMkUiakL0/.7 version: a2lqXIRnGQfmStV8{29}"
|
|
"22:04:28.453","dev-10-74-0-74","2022-11-02T22:04:28.453-0400 7f07b255b700 1 req 15462255817190376745 0.082000576s s3:put_obj int rgw::cls::fifo::FIFO::_prepare_new_head(const DoutPrefixProvider*, int64_t, uint64_t, optional_yield):842 blp entering: tid=72267"
|
|
"22:04:28.453","dev-10-74-0-74","2022-11-02T22:04:28.453-0400 7f07b255b700 20 req 15462255817190376745 0.082000576s s3:put_obj int rgw::cls::fifo::FIFO::push(const DoutPrefixProvider*, const std::vector<ceph::buffer::v15_2_0::list>&, optional_yield):1458 blp need to retry and need new head head_part_num=6 tid=72267"
|
|
"22:04:28.453","dev-10-74-0-74","2022-11-02T22:04:28.453-0400 7f07b255b700 -1 req 15462255817190376745 0.082000576s s3:put_obj int rgw::cls::fifo::FIFO::push_entries(const DoutPrefixProvider*, const std::deque<ceph::buffer::v15_2_0::list>&, uint64_t, optional_yield):1172 blp push_part failed: r=-34 tid=72267"
|
|
"22:04:28.453","dev-10-74-0-74","2022-11-02T22:04:28.453-0400 7f07b255b700 -1 req 15462255817190376745 0.082000576s s3:put_obj int rgw::cls::fifo::{anonymous}::push_part(const DoutPrefixProvider*, librados::v14_2_0::IoCtx&, const string&, std::string_view, std::deque<ceph::buffer::v15_2_0::list>, uint64_t, optional_yield):160 fifo::op::PUSH_PART failed r=-34 tid=72267"
|
|
"22:04:28.374","dev-10-74-0-74","2022-11-02T22:04:28.374-0400 7f05c6183700 20 req 15462255817190376745 0.003000021s s3:put_obj bucket index object: dev-zone-bcc-master.rgw.buckets.index:.dir.43e66047-e6b5-472d-8813-6224a31ce963.5353.5830.6"
|
|
"22:04:28.374","dev-10-74-0-74","2022-11-02T22:04:28.374-0400 7f05c6183700 10 req 15462255817190376745 0.003000021s s3:put_obj setting object write_tag=43e66047-e6b5-472d-8813-6224a31ce963.5384.15462255817190376745"
|
|
"22:04:28.374","dev-10-74-0-74","2022-11-02T22:04:28.374-0400 7f05c6183700 20 req 15462255817190376745 0.003000021s s3:put_obj get_obj_state: rctx=0x558d055b0620 obj=:cosinc10-dev-2k-thisisbcstestload00340[43e66047-e6b5-472d-8813-6224a31ce963.5353.5830]):myobjects30004250 state=0x558d1ff931e8 s->prefetch_data=0"
|
|
"22:04:28.374","dev-10-74-0-74","2022-11-02T22:04:28.374-0400 7f05c6183700 20 req 15462255817190376745 0.003000021s s3:put_obj get_obj_state: setting s->obj_tag to 43e66047-e6b5-472d-8813-6224a31ce963.5347.2482386400441360935"
|
|
"22:04:28.374","dev-10-74-0-74","2022-11-02T22:04:28.374-0400 7f05c6183700 10 req 15462255817190376745 0.003000021s s3:put_obj manifest: total_size = 2000"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 20 req 15462255817190376745 0.001000007s s3:put_obj WARNING: blocking librados call"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 20 req 15462255817190376745 0.001000007s s3:put_obj get_obj_state: rctx=0x558d055b0620 obj=:cosinc10-dev-2k-thisisbcstestload00340[43e66047-e6b5-472d-8813-6224a31ce963.5353.5830]):myobjects30004250 state=0x558d1ff931e8 s->prefetch_data=0"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 5 req 15462255817190376745 0.001000007s s3:put_obj NOTICE: call to do_aws4_auth_completion"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 5 req 15462255817190376745 0.001000007s s3:put_obj NOTICE: call to do_aws4_auth_completion"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 10 req 15462255817190376745 0.001000007s cache get: name=dev-zone-bcc-master.rgw.log++script.putdata. : hit (negative entry)"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 20 req 15462255817190376745 0.001000007s s3:put_obj max_chunk_size=4194304"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 2 req 15462255817190376745 0.001000007s s3:put_obj executing"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 2 req 15462255817190376745 0.001000007s s3:put_obj check rate limiting"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 2 req 15462255817190376745 0.001000007s s3:put_obj pre-executing"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 2 req 15462255817190376745 0.001000007s s3:put_obj verifying op params"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 10 req 15462255817190376745 0.001000007s s3:put_obj identity=rgw::auth::SysReqApplier -> rgw::auth::LocalApplier(acct_user=cosbench-003, acct_name=cosbench-003, subuser=, perm_mask=15, is_admin=0) requested perm (type)=2, policy perm=2, user_perm_mask=2, acl perm=2"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 5 req 15462255817190376745 0.001000007s s3:put_obj -- Getting permissions done for identity=rgw::auth::SysReqApplier -> rgw::auth::LocalApplier(acct_user=cosbench-003, acct_name=cosbench-003, subuser=, perm_mask=15, is_admin=0), owner=cosbench-003, perm=2"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 5 req 15462255817190376745 0.001000007s s3:put_obj Permissions for group not found"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 5 req 15462255817190376745 0.001000007s s3:put_obj Searching permissions for group=2 mask=50"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 5 req 15462255817190376745 0.001000007s s3:put_obj Permissions for group not found"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 5 req 15462255817190376745 0.001000007s s3:put_obj Searching permissions for group=1 mask=50"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 5 req 15462255817190376745 0.001000007s s3:put_obj Found permission: 15"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 5 req 15462255817190376745 0.001000007s s3:put_obj Searching permissions for uid=cosbench-003"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 5 req 15462255817190376745 0.001000007s s3:put_obj Searching permissions for identity=rgw::auth::SysReqApplier -> rgw::auth::LocalApplier(acct_user=cosbench-003, acct_name=cosbench-003, subuser=, perm_mask=15, is_admin=0) mask=50"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 20 req 15462255817190376745 0.001000007s s3:put_obj -- Getting permissions begin with perm_mask=50"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 20 req 15462255817190376745 0.001000007s get_encryption_defaults: kms_attr_seen is 0 and sse_algorithm is"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 2 req 15462255817190376745 0.001000007s s3:put_obj verifying op permissions"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 20 req 15462255817190376745 0.001000007s s3:put_obj required_mask= 2 user.op_mask=7"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 2 req 15462255817190376745 0.001000007s s3:put_obj verifying op mask"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 2 req 15462255817190376745 0.001000007s s3:put_obj init op"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 2 req 15462255817190376745 0.001000007s s3:put_obj reading permissions"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 2 req 15462255817190376745 0.001000007s s3:put_obj recalculating target"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 10 req 15462255817190376745 0.001000007s s3:put_obj cache get: name=dev-zone-bcc-master.rgw.meta+users.uid+cosbench-003 : hit (requested=0x13, cached=0x13)"
|
|
"22:04:28.372","dev-10-74-0-74","2022-11-02T22:04:28.372-0400 7f05c6183700 15 req 15462255817190376745 0.001000007s s3:put_obj decode_policy Read AccessControlPolicy<AccessControlPolicy xmlns=""http://s3.amazonaws.com/doc/2006-03-01/""><Owner><ID>cosbench-003</ID><DisplayName>cosbench-003</DisplayName></Owner><AccessControlList><Grant><Grantee xmlns:xsi=""http://www.w3.org/2001/XMLSchema-instance"" xsi:type=""CanonicalUser""><ID>cosbench-003</ID><DisplayName>cosbench-003</DisplayName></Grantee><Permission>FULL_CONTROL</Permission></Grant></AccessControlList></AccessControlPolicy>"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 10 req 15462255817190376745 0.000000000s s3:put_obj cache get: name=dev-zone-bcc-master.rgw.meta+root+cosinc10-dev-2k-thisisbcstestload00340 : hit (requested=0x11, cached=0x11)"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 2 req 15462255817190376745 0.000000000s s3:put_obj init permissions"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 10 req 15462255817190376745 0.000000000s s->object=myobjects30004250 s->bucket=cosinc10-dev-2k-thisisbcstestload00340"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 2 req 15462255817190376745 0.000000000s s3:put_obj normalizing buckets and tenants"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 20 req 15462255817190376745 0.000000000s s3:put_obj rgw::auth::s3::AWSAuthStrategy granted access"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 20 req 15462255817190376745 0.000000000s s3:put_obj rgw::auth::s3::LocalEngine granted access"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 15 req 15462255817190376745 0.000000000s s3:put_obj compare=0"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 15 req 15462255817190376745 0.000000000s s3:put_obj client signature=A0eKitJNM7bMoJXmFzb0dIetn2U="
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 15 req 15462255817190376745 0.000000000s s3:put_obj server signature=A0eKitJNM7bMoJXmFzb0dIetn2U="
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 15 req 15462255817190376745 0.000000000s s3:put_obj string_to_sign=PUT
|
|
|
|
application/octet-stream
|
|
Thu, 03 Nov 2022 02:04:28 GMT
|
|
/cosinc10-dev-2k-thisisbcstestload00340/myobjects30004250"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 10 req 15462255817190376745 0.000000000s string_to_sign:
|
|
PUT
|
|
|
|
application/octet-stream
|
|
Thu, 03 Nov 2022 02:04:28 GMT
|
|
/cosinc10-dev-2k-thisisbcstestload00340/myobjects30004250"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 10 req 15462255817190376745 0.000000000s get_canon_resource(): dest=/cosinc10-dev-2k-thisisbcstestload00340/myobjects30004250"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 20 req 15462255817190376745 0.000000000s s3:put_obj rgw::auth::s3::AWSAuthStrategy: trying rgw::auth::s3::LocalEngine"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 20 req 15462255817190376745 0.000000000s s3:put_obj rgw::auth::s3::S3AnonymousEngine denied with reason=-1"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 20 req 15462255817190376745 0.000000000s s3:put_obj rgw::auth::s3::AWSAuthStrategy: trying rgw::auth::s3::S3AnonymousEngine"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 20 req 15462255817190376745 0.000000000s s3:put_obj rgw::auth::StrategyRegistry::s3_main_strategy_t: trying rgw::auth::s3::AWSAuthStrategy"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 2 req 15462255817190376745 0.000000000s s3:put_obj verifying requester"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 10 req 15462255817190376745 0.000000000s s3:put_obj op=21RGWPutObj_ObjStore_S3"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 10 req 15462255817190376745 0.000000000s s3:put_obj scheduling with throttler client=2 cost=1"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 10 req 15462255817190376745 0.000000000s cache get: name=dev-zone-bcc-master.rgw.log++script.prerequest. : hit (negative entry)"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 2 req 15462255817190376745 0.000000000s getting op 1"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 10 req 15462255817190376745 0.000000000s handler=22RGWHandler_REST_Obj_S3"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 20 req 15462255817190376745 0.000000000s get_handler handler=22RGWHandler_REST_Obj_S3"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 20 req 15462255817190376745 0.000000000s final domain/bucket subdomain= domain= in_hosted_domain=0 in_hosted_domain_s3website=0 s->info.domain= s->info.request_uri=/cosinc10-dev-2k-thisisbcstestload00340/myobjects30004250"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 20 req 15462255817190376745 0.000000000s subdomain= domain= in_hosted_domain=0 in_hosted_domain_s3website=0"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 10 req 15462255817190376745 0.000000000s host=10.74.3.149"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 10 req 15462255817190376745 0.000000000s rgw api priority: s3=8 s3website=7"
|
|
"22:04:28.371","dev-10-74-0-74","2022-11-02T22:04:28.371-0400 7f05c6183700 2 req 15462255817190376745 0.000000000s initializing for trans_id = tx00000d694f7be41d98529-00636321ac-1508-dev-zone-bcc-master"
|
|
"22:04:06.997","dev-10-74-0-74","2022-11-02T22:04:06.997-0400 7f092c84f700 -1 req 15677424494094360016 0.068000481s s3:put_obj int rgw::cls::fifo::FIFO::push_entries(const DoutPrefixProvider*, const std::deque<ceph::buffer::v15_2_0::list>&, uint64_t, optional_yield):1165 blp calling push_part part_oid=data_log.11.lN1Akvyk6X0.6 head_part_num 6 tag 0EA31MxA0Jeb4Xw2 tid=72267"
|
|
"22:04:06.997","dev-10-74-0-74","2022-11-02T22:04:06.997-0400 7f092c84f700 20 req 15677424494094360016 0.068000481s s3:put_obj int rgw::cls::fifo::FIFO::push_entries(const DoutPrefixProvider*, const std::deque<ceph::buffer::v15_2_0::list>&, uint64_t, optional_yield):1157 entering: tid=72267"
|
|
"22:04:06.997","dev-10-74-0-74","2022-11-02T22:04:06.997-0400 7f092c84f700 20 req 15677424494094360016 0.068000481s s3:put_obj int rgw::cls::fifo::FIFO::push(const DoutPrefixProvider*, const std::vector<ceph::buffer::v15_2_0::list>&, optional_yield):1448 prepared push: remaining=0 batch=1 retries=0 batch_len=172 tid=72267"
|
|
"22:04:06.997","dev-10-74-0-74","2022-11-02T22:04:06.997-0400 7f092c84f700 20 req 15677424494094360016 0.068000481s s3:put_obj int rgw::cls::fifo::FIFO::push(const DoutPrefixProvider*, const std::vector<ceph::buffer::v15_2_0::list>&, optional_yield):1428 preparing push: remaining=1 batch=0 retries=0 tid=72267"
|
|
"22:04:06.997","dev-10-74-0-74","2022-11-02T22:04:06.997-0400 7f092c84f700 20 req 15677424494094360016 0.068000481s s3:put_obj int rgw::cls::fifo::FIFO::push(const DoutPrefixProvider*, const std::vector<ceph::buffer::v15_2_0::list>&, optional_yield):1391 entering: tid=72267"
|