Project

General

Profile

Bug #37386

radosgw crash after trying to upload object

Added by Timo Nieminen 12 months ago. Updated 12 months ago.

Status:
Resolved
Priority:
Normal
Assignee:
-
Target version:
Start date:
11/26/2018
Due date:
% Done:

0%

Source:
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Pull request ID:
Crash signature:

Description

We have a working ceph-cluster for openstack nova rbd usage. We are now working on implementing object storage with rgw and keystone authentication. Currently the documentation seems to be a bit lacking for this.
Ceph has been installed from Ubuntu Cloud Archive rocky-series.

Currently it is possible to create buckets from Horizon and by using command line swift -client.
Trying to upload an object either from Horizon or cli swift fails and the radosgw daemon crashes.

The daemon crashes after loggin NOTICE: call to do_aws4_auth_completion

Immediate crash reason seems to be:
terminate called after throwing an instance of 'boost::exception_detail::clone_impl<boost::exception_detail::error_info_injector<boost::bad_get> >'
what(): boost::bad_get: failed value get using boost::get

Relevant ceph.conf:

[client.rgw.c001]
host = c001
keyring = /var/lib/ceph/radosgw/ceph-rgw.c001/keyring
log file = /var/log/ceph/ceph-rgw-c001.log
rgw frontends = civetweb port=10.193.1.1:8080 num_threads=100
rgw keystone accepted roles = member, _member_, admin
rgw keystone admin domain = default
rgw keystone admin password = xxxx
rgw keystone admin project = service
rgw keystone admin user = radosgw
rgw keystone api version = 3
rgw keystone revocation interval = 900
rgw keystone verify ssl = false
rgw keystone url = http://10.193.0.10:5000/
rgw s3 auth use keystone = true
rgw trust forwarded https = true

[global]
cluster network = 10.193.0.0/16
fsid = 2316ae4d-fc7f-4961-bb05-481d4bbb00a8
mon host = 10.193.1.5,10.193.1.4,10.193.1.1,10.193.1.3,10.193.1.2
mon initial members = c005,c004,c001,c003,c002
ms_async_max_op_threads = 12
ms_async_op_threads = 6
ms_async_rdma_device_name = mlx5_bond_0
ms_async_rdma_polling_us = 0
ms_async_transport = rdma
ms_cluster_type = async+rdma
public network = 10.193.0.0/16

Log has been generated by running radosgw with:
sudo -u ceph /usr/bin/radosgw -f --clusterceph --name client.rgw.c001 --setuser ceph --setgroup ceph -d --debug_ms 10/10 --rgw_enable_ops_log=true

Log output:

2018-11-26 04:12:09.183 7f9c48c53700  1 ====== req done req=0x7f9c48c4a810 op status=1901 http_status=202 ======
2018-11-26 04:12:09.183 7f9c6b8a0700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.5:6815/63352 conn(0x55d60936e700 :-1 s=STATE_OPEN pgs=1992 cs=1 l=1).handle_write
2018-11-26 04:12:09.183 7f9c48c53700  1 civetweb: 0x55d6096f8000: 10.193.0.11 - - [26/Nov/2018:04:12:09 +0200] "PUT /swift/v1/test HTTP/1.1" 202 301 - python-swiftclient-3.6.0
2018-11-26 04:12:09.183 7f9c6b8a0700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.5:6815/63352 conn(0x55d60936e700 :-1 s=STATE_OPEN pgs=1992 cs=1 l=1)._try_send sent bytes 852 remaining bytes 0
2018-11-26 04:12:09.183 7f9c6b8a0700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.5:6815/63352 conn(0x55d60936e700 :-1 s=STATE_OPEN pgs=1992 cs=1 l=1).write_message sending 0x55d6099a2a40 done.
2018-11-26 04:12:09.199 7f9c48c53700  1 ====== starting new request req=0x7f9c48c4a810 =====
2018-11-26 04:12:09.199 7f9c48c53700  1 -- 10.193.1.1:0/2873863230 --> 10.193.1.4:6800/3902548 -- osd_op(unknown.0.0:915 23.0 23:028b2f56:root::14489dd57cab42549843a7b1d85c27c3%2ftest:head [call version.read,getxattrs,stat] snapc 0=[] ondisk+read+known_if_redirected e632) v8 -- 0x55d6099a3400 con 0
2018-11-26 04:12:09.199 7f9c6a09d700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.4:6800/3902548 conn(0x55d60936fc00 :-1 s=STATE_OPEN pgs=1156 cs=1 l=1).handle_write
2018-11-26 04:12:09.199 7f9c6a09d700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.4:6800/3902548 conn(0x55d60936fc00 :-1 s=STATE_OPEN pgs=1156 cs=1 l=1)._try_send sent bytes 412 remaining bytes 0
2018-11-26 04:12:09.199 7f9c6a09d700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.4:6800/3902548 conn(0x55d60936fc00 :-1 s=STATE_OPEN pgs=1156 cs=1 l=1).write_message sending 0x55d6099a3400 done.
2018-11-26 04:12:09.199 7f9c6a09d700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.4:6800/3902548 conn(0x55d60936fc00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=1156 cs=1 l=1).process aborted = 0
2018-11-26 04:12:09.199 7f9c6a09d700  5 -- 10.193.1.1:0/2873863230 >> 10.193.1.4:6800/3902548 conn(0x55d60936fc00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=1156 cs=1 l=1). rx osd.20 seq 11 0x55d6099a3400 osd_op_reply(915 14489dd57cab42549843a7b1d85c27c3/test [call,getxattrs,stat] v0'0 uv16 ondisk = 0) v8
2018-11-26 04:12:09.199 7f9c6a09d700  1 -- 10.193.1.1:0/2873863230 <== osd.20 10.193.1.4:6800/3902548 11 ==== osd_op_reply(915 14489dd57cab42549843a7b1d85c27c3/test [call,getxattrs,stat] v0'0 uv16 ondisk = 0) v8 ==== 265+0+139 (258594772 0 111697458) 0x55d6099a3400 con 0x55d60936fc00
2018-11-26 04:12:09.199 7f9c6a09d700 10 -- 10.193.1.1:0/2873863230 dispatch_throttle_release 404 to dispatch throttler 404/104857600
2018-11-26 04:12:09.199 7f9c48c53700  1 -- 10.193.1.1:0/2873863230 --> 10.193.1.5:6815/63352 -- osd_op(unknown.0.0:916 27.19s0 27:99acdbe5:::7306b577-7c55-4200-84e0-e5651eedaa32.4147209.1_test.txt:head [getxattrs,stat] snapc 0=[] ondisk+read+known_if_redirected e632) v8 -- 0x55d6099a09c0 con 0
2018-11-26 04:12:09.199 7f9c6b8a0700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.5:6815/63352 conn(0x55d60936e700 :-1 s=STATE_OPEN pgs=1992 cs=1 l=1).handle_write
2018-11-26 04:12:09.199 7f9c6b8a0700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.5:6815/63352 conn(0x55d60936e700 :-1 s=STATE_OPEN pgs=1992 cs=1 l=1)._try_send sent bytes 377 remaining bytes 0
2018-11-26 04:12:09.199 7f9c6b8a0700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.5:6815/63352 conn(0x55d60936e700 :-1 s=STATE_OPEN pgs=1992 cs=1 l=1).write_message sending 0x55d6099a09c0 done.
2018-11-26 04:12:09.203 7f9c6b8a0700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.5:6815/63352 conn(0x55d60936e700 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=1992 cs=1 l=1).process aborted = 0
2018-11-26 04:12:09.203 7f9c6b8a0700  5 -- 10.193.1.1:0/2873863230 >> 10.193.1.5:6815/63352 conn(0x55d60936e700 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=1992 cs=1 l=1). rx osd.14 seq 81 0x55d6099a09c0 osd_op_reply(916 7306b577-7c55-4200-84e0-e5651eedaa32.4147209.1_test.txt [getxattrs,stat] v0'0 uv0 ondisk = -2 ((2) No such file or directory)) v8
2018-11-26 04:12:09.203 7f9c6b8a0700  1 -- 10.193.1.1:0/2873863230 <== osd.14 10.193.1.5:6815/63352 81 ==== osd_op_reply(916 7306b577-7c55-4200-84e0-e5651eedaa32.4147209.1_test.txt [getxattrs,stat] v0'0 uv0 ondisk = -2 ((2) No such file or directory)) v8 ==== 241+0+0 (994389899 0 0) 0x55d6099a09c0 con 0x55d60936e700
2018-11-26 04:12:09.203 7f9c6b8a0700 10 -- 10.193.1.1:0/2873863230 dispatch_throttle_release 241 to dispatch throttler 241/104857600
2018-11-26 04:12:09.203 7f9c48c53700  1 -- 10.193.1.1:0/2873863230 --> 10.193.1.5:6815/63352 -- osd_op(unknown.0.0:917 24.7 24:f329c305:::2018-11-26-04-7306b577-7c55-4200-84e0-e5651eedaa32.4147209.1-14489dd57cab42549843a7b1d85c27c3%2ftest:head [append 0~496] snapc 0=[] ondisk+write+known_if_redirected e632) v8 -- 0x55d6099a1040 con 0
2018-11-26 04:12:09.203 7f9c6b8a0700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.5:6815/63352 conn(0x55d60936e700 :-1 s=STATE_OPEN pgs=1992 cs=1 l=1).handle_write
2018-11-26 04:12:09.203 7f9c48c53700  1 ====== req done req=0x7f9c48c4a810 op status=0 http_status=404 ======
2018-11-26 04:12:09.203 7f9c6b8a0700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.5:6815/63352 conn(0x55d60936e700 :-1 s=STATE_OPEN pgs=1992 cs=1 l=1)._try_send sent bytes 878 remaining bytes 0
2018-11-26 04:12:09.203 7f9c6b8a0700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.5:6815/63352 conn(0x55d60936e700 :-1 s=STATE_OPEN pgs=1992 cs=1 l=1).write_message sending 0x55d6099a1040 done.
2018-11-26 04:12:09.203 7f9c48c53700  1 civetweb: 0x55d6096f8000: 10.193.0.11 - - [26/Nov/2018:04:12:09 +0200] "HEAD /swift/v1/test/test.txt HTTP/1.1" 404 302 - python-swiftclient-3.6.0
2018-11-26 04:12:09.203 7f9c48c53700  1 ====== starting new request req=0x7f9c48c4a810 =====
2018-11-26 04:12:09.203 7f9c48c53700  1 -- 10.193.1.1:0/2873863230 --> 10.193.1.6:6812/40367 -- osd_op(unknown.0.0:918 30.5 30:ab217802:::.dir.7306b577-7c55-4200-84e0-e5651eedaa32.4147209.1:head [call rgw.bucket_list] snapc 0=[] ondisk+read+known_if_redirected e632) v8 -- 0x55d6099a1380 con 0
2018-11-26 04:12:09.203 7f9c6c0a1700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.6:6812/40367 conn(0x55d609370a00 :-1 s=STATE_OPEN pgs=53100 cs=1 l=1).handle_write
2018-11-26 04:12:09.203 7f9c6c0a1700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.6:6812/40367 conn(0x55d609370a00 :-1 s=STATE_OPEN pgs=53100 cs=1 l=1)._try_send sent bytes 378 remaining bytes 0
2018-11-26 04:12:09.203 7f9c6c0a1700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.6:6812/40367 conn(0x55d609370a00 :-1 s=STATE_OPEN pgs=53100 cs=1 l=1).write_message sending 0x55d6099a1380 done.
2018-11-26 04:12:09.207 7f9c6c0a1700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.6:6812/40367 conn(0x55d609370a00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=53100 cs=1 l=1).process aborted = 0
2018-11-26 04:12:09.207 7f9c6c0a1700  5 -- 10.193.1.1:0/2873863230 >> 10.193.1.6:6812/40367 conn(0x55d609370a00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=53100 cs=1 l=1). rx osd.13 seq 2 0x55d6099a1380 osd_op_reply(918 .dir.7306b577-7c55-4200-84e0-e5651eedaa32.4147209.1 [call] v0'0 uv3 ondisk = 0) v8
2018-11-26 04:12:09.207 7f9c6c0a1700  1 -- 10.193.1.1:0/2873863230 <== osd.13 10.193.1.6:6812/40367 2 ==== osd_op_reply(918 .dir.7306b577-7c55-4200-84e0-e5651eedaa32.4147209.1 [call] v0'0 uv3 ondisk = 0) v8 ==== 195+0+110 (278077344 0 3841259930) 0x55d6099a1380 con 0x55d609370a00
2018-11-26 04:12:09.207 7f9c6c0a1700 10 -- 10.193.1.1:0/2873863230 dispatch_throttle_release 305 to dispatch throttler 305/104857600
terminate called after throwing an instance of 'boost::exception_detail::clone_impl<boost::exception_detail::error_info_injector<boost::bad_get> >'
  what():  boost::bad_get: failed value get using boost::get
*** Caught signal (Aborted) **
 in thread 7f9c48c53700 thread_name:civetweb-worker
 ceph version 13.2.1 (5533ecdc0fda920179d7ad84e0aa65a127b20d77) mimic (stable)
 1: (()+0x293e70) [0x55d6067efe70]
 2: (()+0x12890) [0x7f9c7e8cf890]
 3: (gsignal()+0xc7) [0x7f9c73dc8e97]
 4: (abort()+0x141) [0x7f9c73dca801]
 5: (()+0x8c8b7) [0x7f9c7441f8b7]
 6: (()+0x92a06) [0x7f9c74425a06]
 7: (()+0x92a41) [0x7f9c74425a41]
 8: (()+0x92c74) [0x7f9c74425c74]
 9: (()+0x35e30d) [0x55d6068ba30d]
 10: (Option::size_t const md_config_t::get_val<Option::size_t>(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&) const+0x53) [0x55d6068faab3]
 11: (()+0x37df4f) [0x55d6068d9f4f]
 12: (RGWPutObj::execute()+0x1adb) [0x55d6068dbefb]
 13: (rgw_process_authenticated(RGWHandler_REST*, RGWOp*&, RGWRequest*, req_state*, bool)+0x1cd) [0x55d6068fbcfd]
 14: (process_request(RGWRados*, RGWREST*, RGWRequest*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, rgw::auth::StrategyRegistry const&, RGWRestfulIO*, OpsLogSocket*, int*)+0x15f0) [0x55d6068fd3f0]
 15: (RGWCivetWebFrontend::process(mg_connection*)+0x381) [0x55d6067726e1]
 16: (()+0x2851ee) [0x55d6067e11ee]
 17: (()+0x286e78) [0x55d6067e2e78]
 18: (()+0x287308) [0x55d6067e3308]
 19: (()+0x76db) [0x7f9c7e8c46db]
 20: (clone()+0x3f) [0x7f9c73eab88f]
2018-11-26 04:12:09.207 7f9c48c53700 -1 *** Caught signal (Aborted) **
 in thread 7f9c48c53700 thread_name:civetweb-worker

 ceph version 13.2.1 (5533ecdc0fda920179d7ad84e0aa65a127b20d77) mimic (stable)
 1: (()+0x293e70) [0x55d6067efe70]
 2: (()+0x12890) [0x7f9c7e8cf890]
 3: (gsignal()+0xc7) [0x7f9c73dc8e97]
 4: (abort()+0x141) [0x7f9c73dca801]
 5: (()+0x8c8b7) [0x7f9c7441f8b7]
 6: (()+0x92a06) [0x7f9c74425a06]
 7: (()+0x92a41) [0x7f9c74425a41]
 8: (()+0x92c74) [0x7f9c74425c74]
 9: (()+0x35e30d) [0x55d6068ba30d]
 10: (Option::size_t const md_config_t::get_val<Option::size_t>(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&) const+0x53) [0x55d6068faab3]
 11: (()+0x37df4f) [0x55d6068d9f4f]
 12: (RGWPutObj::execute()+0x1adb) [0x55d6068dbefb]
 13: (rgw_process_authenticated(RGWHandler_REST*, RGWOp*&, RGWRequest*, req_state*, bool)+0x1cd) [0x55d6068fbcfd]
 14: (process_request(RGWRados*, RGWREST*, RGWRequest*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, rgw::auth::StrategyRegistry const&, RGWRestfulIO*, OpsLogSocket*, int*)+0x15f0) [0x55d6068fd3f0]
 15: (RGWCivetWebFrontend::process(mg_connection*)+0x381) [0x55d6067726e1]
 16: (()+0x2851ee) [0x55d6067e11ee]
 17: (()+0x286e78) [0x55d6067e2e78]
 18: (()+0x287308) [0x55d6067e3308]
 19: (()+0x76db) [0x7f9c7e8c46db]
 20: (clone()+0x3f) [0x7f9c73eab88f]
 NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- begin dump of recent events ---
### shortened ###
   -73> 2018-11-26 04:12:09.183 7f9c48c53700  2 req 13:0.013675:swift:PUT /swift/v1/test:create_bucket:op status=1901
   -72> 2018-11-26 04:12:09.183 7f9c48c53700  2 req 13:0.013676:swift:PUT /swift/v1/test:create_bucket:http status=202
   -71> 2018-11-26 04:12:09.183 7f9c48c53700  1 ====== req done req=0x7f9c48c4a810 op status=1901 http_status=202 ======
   -70> 2018-11-26 04:12:09.183 7f9c6b8a0700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.5:6815/63352 conn(0x55d60936e700 :-1 s=STATE_OPEN pgs=1992 cs=1 l=1).handle_write
   -69> 2018-11-26 04:12:09.183 7f9c48c53700  1 civetweb: 0x55d6096f8000: 10.193.0.11 - - [26/Nov/2018:04:12:09 +0200] "PUT /swift/v1/test HTTP/1.1" 202 301 - python-swiftclient-3.6.0
   -68> 2018-11-26 04:12:09.183 7f9c6b8a0700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.5:6815/63352 conn(0x55d60936e700 :-1 s=STATE_OPEN pgs=1992 cs=1 l=1)._try_send sent bytes 852 remaining bytes 0
   -67> 2018-11-26 04:12:09.183 7f9c6b8a0700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.5:6815/63352 conn(0x55d60936e700 :-1 s=STATE_OPEN pgs=1992 cs=1 l=1).write_message sending 0x55d6099a2a40 done.
   -66> 2018-11-26 04:12:09.199 7f9c48c53700  1 ====== starting new request req=0x7f9c48c4a810 =====
   -65> 2018-11-26 04:12:09.199 7f9c48c53700  2 req 14:0.000014::HEAD /swift/v1/test/test.txt::initializing for trans_id = tx00000000000000000000e-005bfb5679-4312d1-default
   -64> 2018-11-26 04:12:09.199 7f9c48c53700  2 req 14:0.000034:swift:HEAD /swift/v1/test/test.txt::getting op 3
   -63> 2018-11-26 04:12:09.199 7f9c48c53700  2 req 14:0.000076:swift:HEAD /swift/v1/test/test.txt:get_obj:verifying requester
   -62> 2018-11-26 04:12:09.199 7f9c48c53700  2 req 14:0.000111:swift:HEAD /swift/v1/test/test.txt:get_obj:normalizing buckets and tenants
   -61> 2018-11-26 04:12:09.199 7f9c48c53700  2 req 14:0.000115:swift:HEAD /swift/v1/test/test.txt:get_obj:init permissions
   -60> 2018-11-26 04:12:09.199 7f9c48c53700  1 -- 10.193.1.1:0/2873863230 --> 10.193.1.4:6800/3902548 -- osd_op(unknown.0.0:915 23.0 23:028b2f56:root::14489dd57cab42549843a7b1d85c27c3%2ftest:head [call version.read,getxattrs,stat] snapc 0=[] ondisk+read+known_if_redirected e632) v8 -- 0x55d6099a3400 con 0
   -59> 2018-11-26 04:12:09.199 7f9c6a09d700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.4:6800/3902548 conn(0x55d60936fc00 :-1 s=STATE_OPEN pgs=1156 cs=1 l=1).handle_write
   -58> 2018-11-26 04:12:09.199 7f9c6a09d700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.4:6800/3902548 conn(0x55d60936fc00 :-1 s=STATE_OPEN pgs=1156 cs=1 l=1)._try_send sent bytes 412 remaining bytes 0
   -57> 2018-11-26 04:12:09.199 7f9c6a09d700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.4:6800/3902548 conn(0x55d60936fc00 :-1 s=STATE_OPEN pgs=1156 cs=1 l=1).write_message sending 0x55d6099a3400 done.
   -56> 2018-11-26 04:12:09.199 7f9c6a09d700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.4:6800/3902548 conn(0x55d60936fc00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=1156 cs=1 l=1).process aborted = 0
   -55> 2018-11-26 04:12:09.199 7f9c6a09d700  5 -- 10.193.1.1:0/2873863230 >> 10.193.1.4:6800/3902548 conn(0x55d60936fc00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=1156 cs=1 l=1). rx osd.20 seq 11 0x55d6099a3400 osd_op_reply(915 14489dd57cab42549843a7b1d85c27c3/test [call,getxattrs,stat] v0'0 uv16 ondisk = 0) v8
   -54> 2018-11-26 04:12:09.199 7f9c6a09d700  1 -- 10.193.1.1:0/2873863230 <== osd.20 10.193.1.4:6800/3902548 11 ==== osd_op_reply(915 14489dd57cab42549843a7b1d85c27c3/test [call,getxattrs,stat] v0'0 uv16 ondisk = 0) v8 ==== 265+0+139 (258594772 0 111697458) 0x55d6099a3400 con 0x55d60936fc00
   -53> 2018-11-26 04:12:09.199 7f9c6a09d700 10 -- 10.193.1.1:0/2873863230 dispatch_throttle_release 404 to dispatch throttler 404/104857600
   -52> 2018-11-26 04:12:09.199 7f9c48c53700  2 req 14:0.000469:swift:HEAD /swift/v1/test/test.txt:get_obj:recalculating target
   -51> 2018-11-26 04:12:09.199 7f9c48c53700  2 req 14:0.000475:swift:HEAD /swift/v1/test/test.txt:get_obj:reading permissions
   -50> 2018-11-26 04:12:09.199 7f9c48c53700  1 -- 10.193.1.1:0/2873863230 --> 10.193.1.5:6815/63352 -- osd_op(unknown.0.0:916 27.19s0 27:99acdbe5:::7306b577-7c55-4200-84e0-e5651eedaa32.4147209.1_test.txt:head [getxattrs,stat] snapc 0=[] ondisk+read+known_if_redirected e632) v8 -- 0x55d6099a09c0 con 0
   -49> 2018-11-26 04:12:09.199 7f9c6b8a0700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.5:6815/63352 conn(0x55d60936e700 :-1 s=STATE_OPEN pgs=1992 cs=1 l=1).handle_write
   -48> 2018-11-26 04:12:09.199 7f9c6b8a0700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.5:6815/63352 conn(0x55d60936e700 :-1 s=STATE_OPEN pgs=1992 cs=1 l=1)._try_send sent bytes 377 remaining bytes 0
   -47> 2018-11-26 04:12:09.199 7f9c6b8a0700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.5:6815/63352 conn(0x55d60936e700 :-1 s=STATE_OPEN pgs=1992 cs=1 l=1).write_message sending 0x55d6099a09c0 done.
   -46> 2018-11-26 04:12:09.203 7f9c6b8a0700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.5:6815/63352 conn(0x55d60936e700 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=1992 cs=1 l=1).process aborted = 0
   -45> 2018-11-26 04:12:09.203 7f9c6b8a0700  5 -- 10.193.1.1:0/2873863230 >> 10.193.1.5:6815/63352 conn(0x55d60936e700 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=1992 cs=1 l=1). rx osd.14 seq 81 0x55d6099a09c0 osd_op_reply(916 7306b577-7c55-4200-84e0-e5651eedaa32.4147209.1_test.txt [getxattrs,stat] v0'0 uv0 ondisk = -2 ((2) No such file or directory)) v8
   -44> 2018-11-26 04:12:09.203 7f9c6b8a0700  1 -- 10.193.1.1:0/2873863230 <== osd.14 10.193.1.5:6815/63352 81 ==== osd_op_reply(916 7306b577-7c55-4200-84e0-e5651eedaa32.4147209.1_test.txt [getxattrs,stat] v0'0 uv0 ondisk = -2 ((2) No such file or directory)) v8 ==== 241+0+0 (994389899 0 0) 0x55d6099a09c0 con 0x55d60936e700
   -43> 2018-11-26 04:12:09.203 7f9c6b8a0700 10 -- 10.193.1.1:0/2873863230 dispatch_throttle_release 241 to dispatch throttler 241/104857600
   -42> 2018-11-26 04:12:09.203 7f9c48c53700  1 -- 10.193.1.1:0/2873863230 --> 10.193.1.5:6815/63352 -- osd_op(unknown.0.0:917 24.7 24:f329c305:::2018-11-26-04-7306b577-7c55-4200-84e0-e5651eedaa32.4147209.1-14489dd57cab42549843a7b1d85c27c3%2ftest:head [append 0~496] snapc 0=[] ondisk+write+known_if_redirected e632) v8 -- 0x55d6099a1040 con 0
   -41> 2018-11-26 04:12:09.203 7f9c48c53700  2 req 14:0.000938:swift:HEAD /swift/v1/test/test.txt:get_obj:op status=0
   -40> 2018-11-26 04:12:09.203 7f9c48c53700  2 req 14:0.000939:swift:HEAD /swift/v1/test/test.txt:get_obj:http status=404
   -39> 2018-11-26 04:12:09.203 7f9c6b8a0700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.5:6815/63352 conn(0x55d60936e700 :-1 s=STATE_OPEN pgs=1992 cs=1 l=1).handle_write
   -38> 2018-11-26 04:12:09.203 7f9c48c53700  1 ====== req done req=0x7f9c48c4a810 op status=0 http_status=404 ======
   -37> 2018-11-26 04:12:09.203 7f9c6b8a0700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.5:6815/63352 conn(0x55d60936e700 :-1 s=STATE_OPEN pgs=1992 cs=1 l=1)._try_send sent bytes 878 remaining bytes 0
   -36> 2018-11-26 04:12:09.203 7f9c6b8a0700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.5:6815/63352 conn(0x55d60936e700 :-1 s=STATE_OPEN pgs=1992 cs=1 l=1).write_message sending 0x55d6099a1040 done.
   -35> 2018-11-26 04:12:09.203 7f9c48c53700  1 civetweb: 0x55d6096f8000: 10.193.0.11 - - [26/Nov/2018:04:12:09 +0200] "HEAD /swift/v1/test/test.txt HTTP/1.1" 404 302 - python-swiftclient-3.6.0
   -34> 2018-11-26 04:12:09.203 7f9c48c53700  1 ====== starting new request req=0x7f9c48c4a810 =====
   -33> 2018-11-26 04:12:09.203 7f9c48c53700  2 req 15:0.000010::PUT /swift/v1/test/test.txt::initializing for trans_id = tx00000000000000000000f-005bfb5679-4312d1-default
   -32> 2018-11-26 04:12:09.203 7f9c48c53700  2 req 15:0.000025:swift:PUT /swift/v1/test/test.txt::getting op 1
   -31> 2018-11-26 04:12:09.203 7f9c48c53700  2 req 15:0.000038:swift:PUT /swift/v1/test/test.txt:put_obj:verifying requester
   -30> 2018-11-26 04:12:09.203 7f9c48c53700  2 req 15:0.000062:swift:PUT /swift/v1/test/test.txt:put_obj:normalizing buckets and tenants
   -29> 2018-11-26 04:12:09.203 7f9c48c53700  2 req 15:0.000066:swift:PUT /swift/v1/test/test.txt:put_obj:init permissions
   -28> 2018-11-26 04:12:09.203 7f9c48c53700  2 req 15:0.000087:swift:PUT /swift/v1/test/test.txt:put_obj:recalculating target
   -27> 2018-11-26 04:12:09.203 7f9c48c53700  2 req 15:0.000090:swift:PUT /swift/v1/test/test.txt:put_obj:reading permissions
   -26> 2018-11-26 04:12:09.203 7f9c48c53700  2 req 15:0.000091:swift:PUT /swift/v1/test/test.txt:put_obj:init op
   -25> 2018-11-26 04:12:09.203 7f9c48c53700  2 req 15:0.000093:swift:PUT /swift/v1/test/test.txt:put_obj:verifying op mask
   -24> 2018-11-26 04:12:09.203 7f9c48c53700  2 req 15:0.000095:swift:PUT /swift/v1/test/test.txt:put_obj:verifying op permissions
   -23> 2018-11-26 04:12:09.203 7f9c48c53700  5 content type wasn't provided, trying to guess
   -22> 2018-11-26 04:12:09.203 7f9c48c53700  5 Searching permissions for identity=rgw::auth::ThirdPartyAccountApplier() -> rgw::auth::SysReqApplier -> rgw::auth::RemoteApplier(acct_user=14489dd57cab42549843a7b1d85c27c3, acct_name=admin, perm_mask=15, is_admin=0) mask=50
   -21> 2018-11-26 04:12:09.203 7f9c48c53700  5 Searching permissions for uid=14489dd57cab42549843a7b1d85c27c3
   -20> 2018-11-26 04:12:09.203 7f9c48c53700  5 Permissions for user not found
   -19> 2018-11-26 04:12:09.203 7f9c48c53700  5 Searching permissions for uid=14489dd57cab42549843a7b1d85c27c3$14489dd57cab42549843a7b1d85c27c3
   -18> 2018-11-26 04:12:09.203 7f9c48c53700  5 Found permission: 15
   -17> 2018-11-26 04:12:09.203 7f9c48c53700  5 Searching permissions for group=1 mask=50
   -16> 2018-11-26 04:12:09.203 7f9c48c53700  5 Permissions for group not found
   -15> 2018-11-26 04:12:09.203 7f9c48c53700  5 Searching permissions for group=2 mask=50
   -14> 2018-11-26 04:12:09.203 7f9c48c53700  5 Permissions for group not found
   -13> 2018-11-26 04:12:09.203 7f9c48c53700  5 -- Getting permissions done for identity=rgw::auth::ThirdPartyAccountApplier() -> rgw::auth::SysReqApplier -> rgw::auth::RemoteApplier(acct_user=14489dd57cab42549843a7b1d85c27c3, acct_name=admin, perm_mask=15, is_admin=0), owner=14489dd57cab42549843a7b1d85c27c3$14489dd57cab42549843a7b1d85c27c3, perm=2
   -12> 2018-11-26 04:12:09.203 7f9c48c53700  2 req 15:0.000121:swift:PUT /swift/v1/test/test.txt:put_obj:verifying op params
   -11> 2018-11-26 04:12:09.203 7f9c48c53700  2 req 15:0.000122:swift:PUT /swift/v1/test/test.txt:put_obj:pre-executing
   -10> 2018-11-26 04:12:09.203 7f9c48c53700  2 req 15:0.000123:swift:PUT /swift/v1/test/test.txt:put_obj:executing
    -9> 2018-11-26 04:12:09.203 7f9c48c53700  1 -- 10.193.1.1:0/2873863230 --> 10.193.1.6:6812/40367 -- osd_op(unknown.0.0:918 30.5 30:ab217802:::.dir.7306b577-7c55-4200-84e0-e5651eedaa32.4147209.1:head [call rgw.bucket_list] snapc 0=[] ondisk+read+known_if_redirected e632) v8 -- 0x55d6099a1380 con 0
    -8> 2018-11-26 04:12:09.203 7f9c6c0a1700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.6:6812/40367 conn(0x55d609370a00 :-1 s=STATE_OPEN pgs=53100 cs=1 l=1).handle_write
    -7> 2018-11-26 04:12:09.203 7f9c6c0a1700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.6:6812/40367 conn(0x55d609370a00 :-1 s=STATE_OPEN pgs=53100 cs=1 l=1)._try_send sent bytes 378 remaining bytes 0
    -6> 2018-11-26 04:12:09.203 7f9c6c0a1700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.6:6812/40367 conn(0x55d609370a00 :-1 s=STATE_OPEN pgs=53100 cs=1 l=1).write_message sending 0x55d6099a1380 done.
    -5> 2018-11-26 04:12:09.207 7f9c6c0a1700 10 -- 10.193.1.1:0/2873863230 >> 10.193.1.6:6812/40367 conn(0x55d609370a00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=53100 cs=1 l=1).process aborted = 0
    -4> 2018-11-26 04:12:09.207 7f9c6c0a1700  5 -- 10.193.1.1:0/2873863230 >> 10.193.1.6:6812/40367 conn(0x55d609370a00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=53100 cs=1 l=1). rx osd.13 seq 2 0x55d6099a1380 osd_op_reply(918 .dir.7306b577-7c55-4200-84e0-e5651eedaa32.4147209.1 [call] v0'0 uv3 ondisk = 0) v8
    -3> 2018-11-26 04:12:09.207 7f9c6c0a1700  1 -- 10.193.1.1:0/2873863230 <== osd.13 10.193.1.6:6812/40367 2 ==== osd_op_reply(918 .dir.7306b577-7c55-4200-84e0-e5651eedaa32.4147209.1 [call] v0'0 uv3 ondisk = 0) v8 ==== 195+0+110 (278077344 0 3841259930) 0x55d6099a1380 con 0x55d609370a00
    -2> 2018-11-26 04:12:09.207 7f9c6c0a1700 10 -- 10.193.1.1:0/2873863230 dispatch_throttle_release 305 to dispatch throttler 305/104857600
    -1> 2018-11-26 04:12:09.207 7f9c48c53700  5 NOTICE: call to do_aws4_auth_completion
     0> 2018-11-26 04:12:09.207 7f9c48c53700 -1 *** Caught signal (Aborted) **
 in thread 7f9c48c53700 thread_name:civetweb-worker

 ceph version 13.2.1 (5533ecdc0fda920179d7ad84e0aa65a127b20d77) mimic (stable)
 1: (()+0x293e70) [0x55d6067efe70]
 2: (()+0x12890) [0x7f9c7e8cf890]
 3: (gsignal()+0xc7) [0x7f9c73dc8e97]
 4: (abort()+0x141) [0x7f9c73dca801]
 5: (()+0x8c8b7) [0x7f9c7441f8b7]
 6: (()+0x92a06) [0x7f9c74425a06]
 7: (()+0x92a41) [0x7f9c74425a41]
 8: (()+0x92c74) [0x7f9c74425c74]
 9: (()+0x35e30d) [0x55d6068ba30d]
 10: (Option::size_t const md_config_t::get_val<Option::size_t>(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&) const+0x53) [0x55d6068faab3]
 11: (()+0x37df4f) [0x55d6068d9f4f]
 12: (RGWPutObj::execute()+0x1adb) [0x55d6068dbefb]
 13: (rgw_process_authenticated(RGWHandler_REST*, RGWOp*&, RGWRequest*, req_state*, bool)+0x1cd) [0x55d6068fbcfd]
 14: (process_request(RGWRados*, RGWREST*, RGWRequest*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, rgw::auth::StrategyRegistry const&, RGWRestfulIO*, OpsLogSocket*, int*)+0x15f0) [0x55d6068fd3f0]
 15: (RGWCivetWebFrontend::process(mg_connection*)+0x381) [0x55d6067726e1]
 16: (()+0x2851ee) [0x55d6067e11ee]
 17: (()+0x286e78) [0x55d6067e2e78]
 18: (()+0x287308) [0x55d6067e3308]
 19: (()+0x76db) [0x7f9c7e8c46db]
 20: (clone()+0x3f) [0x7f9c73eab88f]
 NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

History

#1 Updated by Timo Nieminen 12 months ago

Just confirmed that removing all keystone related configuration and creating user with "radosgw-admin user create --uid=testuser --display-name=testuser" ends up with similar crash after using s3cmd -cli utility. Bucket creation is fine, object upload causes exactly the same crash.

#2 Updated by James Page 12 months ago

Raised separately and tracking under https://bugs.launchpad.net/cloud-archive/+bug/1805145 as well

#3 Updated by James Page 12 months ago

I believe this issue is due to a distro patch we have in Ubuntu for 32 bit compatibility - revising the patch now test builds will appear in:

https://launchpad.net/~ci-train-ppa-service/+archive/ubuntu/3534/+packages

#4 Updated by Timo Nieminen 12 months ago

James Page wrote:

I believe this issue is due to a distro patch we have in Ubuntu for 32 bit compatibility - revising the patch now test builds will appear in:

https://launchpad.net/~ci-train-ppa-service/+archive/ubuntu/3534/+packages

I can confirm that installing packages from this ppa fixed the issue. I can now successfully upload files with keystone auth + swift and with ceph internal auth + s3cmd.

#5 Updated by Abhishek Lekshmanan 12 months ago

  • Status changed from New to Resolved

Also available in: Atom PDF