Hi : I use libs3 to run test . The network is IB. The error in libcurl is the following:
== Info: Operation too slow. Less than 1 bytes/sec transferred the last 15 seconds == Info: Closing connection 766 and a full request error in rgw is as the following: 2018-07-12 15:42:30.501074 7fe8bc83f700 1 civetweb: 0x7fe940ebf000: 10.5.131.193 - - [12/Jul/2018:15:42:15 +0800] "PUT /yesonggao.hdd77/2217856 HTTP/1.1" 1 0 - Mozilla/4.0 (Compatible; s3; libs3 2.0; Linux x86_64) 2018-07-12 15:43:05.332318 7fe8bc83f700 20 HTTP_HOST=localhost 2018-07-12 15:43:05.332326 7fe8bc83f700 20 HTTP_VERSION=1.1 2018-07-12 15:43:05.332327 7fe8bc83f700 20 REMOTE_ADDR=10.5.131.193 2018-07-12 15:43:05.332328 7fe8bc83f700 20 REQUEST_METHOD=HEAD 2018-07-12 15:43:05.332330 7fe8bc83f700 20 REQUEST_URI=/ 2018-07-12 15:43:05.332331 7fe8bc83f700 20 SCRIPT_URI=/ 2018-07-12 15:43:05.332331 7fe8bc83f700 20 SERVER_PORT=80 2018-07-12 15:43:05.332333 7fe8bc83f700 1 ====== starting new request req=0x7fe8bc839110 ===== 2018-07-12 15:43:05.332344 7fe8bc83f700 2 req 18326229:0.000010::HEAD /::initializing for trans_id = tx00000000000000117a2d5-005b470689-d41b-default 2018-07-12 15:43:05.332351 7fe8bc83f700 10 rgw api priority: s3=5 s3website=4 2018-07-12 15:43:05.332352 7fe8bc83f700 10 host=localhost 2018-07-12 15:43:05.332354 7fe8bc83f700 20 subdomain= domain= in_hosted_domain=0 in_hosted_domain_s3website=0 2018-07-12 15:43:05.332355 7fe8bc83f700 20 final domain/bucket subdomain= domain= in_hosted_domain=0 in_hosted_domain_s3website=0 s->info.domain= s->info.request_uri=/ 2018-07-12 15:43:05.332367 7fe8bc83f700 20 get_handler handler=26RGWHandler_REST_Service_S3 2018-07-12 15:43:05.332370 7fe8bc83f700 10 handler=26RGWHandler_REST_Service_S3 2018-07-12 15:43:05.332371 7fe8bc83f700 2 req 18326229:0.000038:s3:HEAD /::getting op 3 2018-07-12 15:43:05.332373 7fe8bc83f700 10 op=26RGWListBuckets_ObjStore_S3 2018-07-12 15:43:05.332374 7fe8bc83f700 2 req 18326229:0.000041:s3:HEAD /:list_buckets:verifying requester 2018-07-12 15:43:05.332376 7fe8bc83f700 20 rgw::auth::StrategyRegistry::s3_main_strategy_t: trying rgw::auth::s3::AWSAuthStrategy 2018-07-12 15:43:05.332378 7fe8bc83f700 20 rgw::auth::s3::AWSAuthStrategy: trying rgw::auth::s3::S3AnonymousEngine 2018-07-12 15:43:05.332381 7fe8bc83f700 20 rgw::auth::s3::S3AnonymousEngine granted access 2018-07-12 15:43:05.332383 7fe8bc83f700 20 rgw::auth::s3::AWSAuthStrategy granted access 2018-07-12 15:43:05.332384 7fe8bc83f700 2 req 18326229:0.000051:s3:HEAD /:list_buckets:normalizing buckets and tenants 2018-07-12 15:43:05.332386 7fe8bc83f700 10 s->object=<NULL> s->bucket= 2018-07-12 15:43:05.332387 7fe8bc83f700 2 req 18326229:0.000054:s3:HEAD /:list_buckets:init permissions 2018-07-12 15:43:05.332400 7fe8bc83f700 2 req 18326229:0.000066:s3:HEAD /:list_buckets:recalculating target 2018-07-12 15:43:05.332402 7fe8bc83f700 2 req 18326229:0.000068:s3:HEAD /:list_buckets:reading permissions 2018-07-12 15:43:05.332403 7fe8bc83f700 2 req 18326229:0.000070:s3:HEAD /:list_buckets:init op [root@SH-IDC1-10-5-30-221 ceph]# grep 7fe8bc83f700 ceph-client.rgw.SH-IDC1-10-5-30-221.log | grep http_status=500 -B 50 -A 50 2018-07-12 15:42:15.499588 7fe8bc83f700 10 get_canon_resource(): dest=/yesonggao.hdd77/2217856 2018-07-12 15:42:15.499589 7fe8bc83f700 10 string_to_sign: 2018-07-12 15:42:15.499611 7fe8bc83f700 15 string_to_sign=PUT 2018-07-12 15:42:15.499620 7fe8bc83f700 15 server signature=14+b6nTNy3cPjVxFlqhRY+hahsA= 2018-07-12 15:42:15.499620 7fe8bc83f700 15 client signature=14+b6nTNy3cPjVxFlqhRY+hahsA= 2018-07-12 15:42:15.499621 7fe8bc83f700 15 compare=0 2018-07-12 15:42:15.499623 7fe8bc83f700 20 rgw::auth::s3::LocalEngine granted access 2018-07-12 15:42:15.499624 7fe8bc83f700 20 rgw::auth::s3::AWSAuthStrategy granted access 2018-07-12 15:42:15.499626 7fe8bc83f700 2 req 18325783:0.000112:s3:PUT /yesonggao.hdd77/2217856:put_obj:normalizing buckets and tenants 2018-07-12 15:42:15.499628 7fe8bc83f700 10 s->object=2217856 s->bucket=yesonggao.hdd77 2018-07-12 15:42:15.499630 7fe8bc83f700 2 req 18325783:0.000116:s3:PUT /yesonggao.hdd77/2217856:put_obj:init permissions 2018-07-12 15:42:15.499642 7fe8bc83f700 15 decode_policy Read AccessControlPolicy<AccessControlPolicy xmlns=" http://s3.amazonaws.com/doc/2006-03-01/";><Owner><ID>yesonggao</ID><DisplayName>yesonggao</DisplayName></Owner><AccessControlList><Grant><Grantee xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"; xsi:type="CanonicalUser"><ID>yesonggao</ID><DisplayName>yesonggao</DisplayName></Grantee><Permission>FULL_CONTROL</Permission></Grant></AccessControlList></AccessControlPolicy> 2018-07-12 15:42:15.499658 7fe8bc83f700 2 req 18325783:0.000144:s3:PUT /yesonggao.hdd77/2217856:put_obj:recalculating target 2018-07-12 15:42:15.499662 7fe8bc83f700 2 req 18325783:0.000148:s3:PUT /yesonggao.hdd77/2217856:put_obj:reading permissions 2018-07-12 15:42:15.499664 7fe8bc83f700 2 req 18325783:0.000150:s3:PUT /yesonggao.hdd77/2217856:put_obj:init op 2018-07-12 15:42:15.499666 7fe8bc83f700 2 req 18325783:0.000152:s3:PUT /yesonggao.hdd77/2217856:put_obj:verifying op mask 2018-07-12 15:42:15.499667 7fe8bc83f700 20 required_mask= 2 user.op_mask=7 2018-07-12 15:42:15.499668 7fe8bc83f700 2 req 18325783:0.000154:s3:PUT /yesonggao.hdd77/2217856:put_obj:verifying op permissions 2018-07-12 15:42:15.499670 7fe8bc83f700 20 -- Getting permissions begin with perm_mask=50 2018-07-12 15:42:15.499671 7fe8bc83f700 5 Searching permissions for identity=rgw::auth::SysReqApplier -> rgw::auth::LocalApplier(acct_user=yesonggao, acct_name=yesonggao, subuser=, perm_mask=15, is_admin=0) mask=50 2018-07-12 15:42:15.499673 7fe8bc83f700 5 Searching permissions for uid=yesonggao 2018-07-12 15:42:15.499674 7fe8bc83f700 5 Found permission: 15 2018-07-12 15:42:15.499675 7fe8bc83f700 5 Searching permissions for group=1 mask=50 2018-07-12 15:42:15.499676 7fe8bc83f700 5 Permissions for group not found 2018-07-12 15:42:15.499677 7fe8bc83f700 5 Searching permissions for group=2 mask=50 2018-07-12 15:42:15.499677 7fe8bc83f700 5 Permissions for group not found 2018-07-12 15:42:15.499678 7fe8bc83f700 5 -- Getting permissions done for identity=rgw::auth::SysReqApplier -> rgw::auth::LocalApplier(acct_user=yesonggao, acct_name=yesonggao, subuser=, perm_mask=15, is_admin=0), owner=yesonggao, perm=2 2018-07-12 15:42:15.499680 7fe8bc83f700 10 identity=rgw::auth::SysReqApplier -> rgw::auth::LocalApplier(acct_user=yesonggao, acct_name=yesonggao, subuser=, perm_mask=15, is_admin=0) requested perm (type)=2, policy perm=2, user_perm_mask=2, acl perm=2 2018-07-12 15:42:15.499682 7fe8bc83f700 2 req 18325783:0.000168:s3:PUT /yesonggao.hdd77/2217856:put_obj:verifying op params 2018-07-12 15:42:15.499684 7fe8bc83f700 2 req 18325783:0.000169:s3:PUT /yesonggao.hdd77/2217856:put_obj:pre-executing 2018-07-12 15:42:15.499695 7fe8bc83f700 30 AccountingFilter::send_100_continue: e=0, sent=25, total=0 2018-07-12 15:42:15.499697 7fe8bc83f700 2 req 18325783:0.000183:s3:PUT /yesonggao.hdd77/2217856:put_obj:executing 2018-07-12 15:42:15.499708 7fe8bc83f700 20 bucket quota: max_objects=-1 max_size=-1 2018-07-12 15:42:15.499710 7fe8bc83f700 20 bucket quota OK: stats.num_objects=8691569 stats.size=38504303859334 2018-07-12 15:42:15.499712 7fe8bc83f700 20 user quota: max_objects=-1 max_size=-1 2018-07-12 15:42:15.499713 7fe8bc83f700 20 user quota OK: stats.num_objects=11692824 stats.size=64478020156197 2018-07-12 15:42:15.499747 7fe8bc83f700 30 AccountingFilter::set_account: e=1 2018-07-12 15:42:30.500915 7fe8bc83f700 -1 ERROR: get_data, read_len = -5 2018-07-12 15:42:30.500938 7fe8bc83f700 2 req 18325783:15.001424:s3:PUT /yesonggao.hdd77/2217856:put_obj:completing 2018-07-12 15:42:30.500951 7fe8bc83f700 0 WARNING: set_req_state_err err_no=5 resorting to 500 2018-07-12 15:42:30.500956 7fe8bc83f700 30 AccountingFilter::send_status: e=1, sent=36, total=0 2018-07-12 15:42:30.500959 7fe8bc83f700 30 AccountingFilter::send_header: e=1, sent=0, total=36 2018-07-12 15:42:30.500975 7fe8bc83f700 30 AccountingFilter::send_content_length: e=1, sent=21, total=36 2018-07-12 15:42:30.500980 7fe8bc83f700 30 AccountingFilter::send_header: e=1, sent=0, total=57 2018-07-12 15:42:30.500982 7fe8bc83f700 30 AccountingFilter::send_header: e=1, sent=0, total=57 2018-07-12 15:42:30.501002 7fe8bc83f700 0 ERROR: RESTFUL_IO(s)->complete_header() returned err=Input/output error 2018-07-12 15:42:30.501006 7fe8bc83f700 30 AccountingFilter::set_account: e=1 2018-07-12 15:42:30.501020 7fe8bc83f700 30 AccountingFilter::complete_request: e=1, sent=0, total=57 2018-07-12 15:42:30.501025 7fe8bc83f700 2 req 18325783:15.001511:s3:PUT /yesonggao.hdd77/2217856:put_obj:op status=-5 2018-07-12 15:42:30.501027 7fe8bc83f700 2 req 18325783:15.001513:s3:PUT /yesonggao.hdd77/2217856:put_obj:http status=500 2018-07-12 15:42:30.501035 7fe8bc83f700 1 ====== req done req=0x7fe8bc839110 op status=-5 http_status=500 ====== 2018-07-12 15:42:30.501050 7fe8bc83f700 20 process_request() returned -5 Can you see anything wrong? And Do you have any idea about how I should debug next ? On Wed, Jul 4, 2018 at 5:23 PM <respo...@ifastnet.com> wrote: > Hi Drew, > > Try to increase debugging with > > debug ms = 1 > debug rgw = 20 > > Regards > Kev > > > ----- Original Message ----- > From: "Drew Weaver" <drew.wea...@thenap.com> > To: "ceph-users" <ceph-users@lists.ceph.com> > Sent: Tuesday, July 3, 2018 1:39:55 PM > Subject: [ceph-users] RADOSGW err=Input/output error > > An application is having general failures writing to a test cluster we > have setup. > > > > 2018-07-02 23:13:26.128282 7fe00b560700 0 WARNING: set_req_state_err > err_no=5 resorting to 500 > > 2018-07-02 23:13:26.128460 7fe00b560700 1 ====== req done > req=0x7fe00b55a110 op status=-5 http_status=500 ====== > > 2018-07-02 23:13:27.530236 7fe00b560700 1 civetweb: 0x55639acc0000: x - - > [02/Jul/2018:23:12:55 -0400] "PUT /my-new-bucket/BEOST_00000292/2752 > HTTP/1.1" 500 0 - APN/1.0 Veritas/1.0 BackupExec/20.0 > > 2018-07-02 23:13:27.532849 7fdfe2d0f700 1 ====== starting new request > req=0x7fdfe2d09110 ===== > > 2018-07-02 23:13:27.538476 7fdfe2d0f700 0 WARNING: set_req_state_err > err_no=5 resorting to 500 > > 2018-07-02 23:13:27.538554 7fdfe2d0f700 0 ERROR: > RESTFUL_IO(s)->complete_header() returned err=Input/output error > > 2018-07-02 23:13:27.538623 7fdfe2d0f700 1 ====== req done > req=0x7fdfe2d09110 op status=-5 http_status=500 ====== > > 2018-07-02 23:13:27.538683 7fdfe2d0f700 1 civetweb: 0x55639ae7d000: x - - > [02/Jul/2018:23:13:27 -0400] "PUT /my-new-bucket/BEOST_00000292/2753 > HTTP/1.1" 500 0 - APN/1.0 Veritas/1.0 BackupExec/20.0 > > 2018-07-02 23:13:28.252088 7fe002d4f700 1 ====== starting new request > req=0x7fe002d49110 ===== > > > > I’ve done a bit of Googling and trying to match the time up with logs on > other hosts but there really doesn’t seem to be very much else happening at > the time when this error occurs. This is version 12.2.5. > > > > Anyone have any hints at what I could look at to try and find the cause of > this? > > > > > > _______________________________________________ > ceph-users mailing list > ceph-users@lists.ceph.com > http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com > _______________________________________________ > ceph-users mailing list > ceph-users@lists.ceph.com > http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com >
_______________________________________________ ceph-users mailing list ceph-users@lists.ceph.com http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com
