rgw: fix boost::asio::async_write() does not return error... #35904

mkogan1 · 2020-07-02T16:56:51Z

although remote has closed the connection

Fixes: https://tracker.ceph.com/issues/46332

Signed-off-by: Mark Kogan mkogan@redhat.com

Checklist

References tracker ticket
Updates documentation if necessary
Includes tests for new functionality or reproducer for bug

Show available Jenkins commands

jenkins retest this please
jenkins test classic perf
jenkins test crimson perf
jenkins test signed
jenkins test make check
jenkins test make check arm64
jenkins test submodules
jenkins test dashboard
jenkins test dashboard backend
jenkins test docs
jenkins render docs
jenkins test ceph-volume all
jenkins test ceph-volume tox

mattbenjamin

I'm not knowledgeable enough to say this works, but it looks very plausible; I take it this prevents further calls on the connection?

mattbenjamin

sorry, didn't mean to approve before getting feedback

cbodley · 2020-07-02T17:25:22Z

src/rgw/rgw_asio_frontend.cc

@@ -69,6 +69,9 @@ class StreamIO : public rgw::asio::ClientIO {
                                          yield[ec]);
    if (ec) {
      ldout(cct, 4) << "write_data failed: " << ec.message() << dendl;
+      if (ec==boost::asio::error::broken_pipe) {
+        stream.lowest_layer().shutdown(tcp::socket::shutdown_both, ec);


we're throwing ec as a rgw::io::Exception just below, but this call to shutdown() will mutate ec. maybe use a separate variable boost::system::error_code ec_ignored for the call to shutdown()?

the intention was to override the ec to indicate the specific condition has occured
for example the error printed to the log at

ceph/src/rgw/rgw_process.cc

Line 292 in 4425f3e

dout(0) << "ERROR: client_io->complete_request() returned "

changes from
7fb47eedc700 0 ERROR: client_io->complete_request() returned Broken pipe
to
7fc0e14da700 0 ERROR: client_io->complete_request() returned Transport endpoint is not connected

it is not essential, changing to ec_ignored

cbodley · 2020-07-02T17:28:11Z

have you narrowed down exactly which parts of the RGWListBuckets op was making additional calls to write after errors were returned? it sounds like we're missing some error handling, and i'd like to address that too if we can

mkogan1 · 2020-07-06T12:54:56Z

have you narrowed down exactly which parts of the RGWListBuckets op was making additional calls to write after errors were returned? it sounds like we're missing some error handling, and i'd like to address that too if we can

The flow is as follows

from process_request(...):

ceph/src/rgw/rgw_process.cc

Line 169 in 4425f3e

int process_request(rgw::sal::RGWRadosStore* const store,

the request is submited at:

ceph/src/rgw/rgw_process.cc

Line 235 in 4425f3e

std::tie(ret,c) = schedule_request(scheduler, s, op);

to:

ceph/src/rgw/rgw_op.cc

Line 2420 in 4425f3e

void RGWListBuckets::execute()
continues:

ceph/src/rgw/rgw_op.cc

Line 2492 in 4425f3e

send_response_begin(buckets.count() > 0);
- to:
  
  ceph/src/rgw/rgw_rest.cc
  
  Line 288 in 4425f3e
  
  void rgw_flush_formatter_and_reset(struct req_state *s, Formatter *formatter)
- continues:
  
  ceph/src/rgw/rgw_rest.cc
  
  Line 295 in 4425f3e
  
  dump_body(s, outs);
- and continues:
  
  ceph/src/rgw/rgw_rest.cc
  
  Line 760 in 4425f3e
  
  return RESTFUL_IO(s)->send_body(buf, len);
- - to:
    
    ceph/src/rgw/rgw_asio_client.h
    
    Line 50 in 4425f3e
    
    size_t send_body(const char* buf, size_t len) override {
- - continues:
    
    ceph/src/rgw/rgw_asio_client.h
    
    Line 51 in 4425f3e
    
    return write_data(buf, len);
- - - to:
      
      ceph/src/rgw/rgw_asio_frontend.cc
      
      Line 66 in 4425f3e
      
      size_t write_data(const char* buf, size_t len) override {
- - - this is the boost::asio::async_write(...)
      
      ceph/src/rgw/rgw_asio_frontend.cc
      
      Line 68 in 4425f3e
      
      auto bytes = boost::asio::async_write(stream, boost::asio::buffer(buf, len),
- - - and 'ec=system:104/Connection reset by peer' error is thrown from:
      
      ceph/src/rgw/rgw_asio_frontend.cc
      
      Line 72 in 4425f3e
      
      throw rgw::io::Exception(ec.value(), std::system_category());
- caught and propogated at:
  
  ceph/src/rgw/rgw_rest.cc
  
  Lines 761 to 762 in 4425f3e
  
  } catch (rgw::io::Exception& e) {
  
  return -e.code().value();
- back to (where it is not checked):
  
  ceph/src/rgw/rgw_rest.cc
  
  Line 307 in 4425f3e
  
  dump_body(s, outs);
next to:

ceph/src/rgw/rgw_op.cc

Line 2509 in 4425f3e

send_response_end();
- to:
  
  ceph/src/rgw/rgw_rest.cc
  
  Line 288 in 4425f3e
  
  void rgw_flush_formatter_and_reset(struct req_state *s, Formatter *formatter)
- continues:
  
  ceph/src/rgw/rgw_rest.cc
  
  Line 295 in 4425f3e
  
  dump_body(s, outs);
- and continues:
  
  ceph/src/rgw/rgw_rest.cc
  
  Line 760 in 4425f3e
  
  return RESTFUL_IO(s)->send_body(buf, len);
- - to:
    
    ceph/src/rgw/rgw_asio_client.h
    
    Line 50 in 4425f3e
    
    size_t send_body(const char* buf, size_t len) override {
- - continues:
    
    ceph/src/rgw/rgw_asio_client.h
    
    Line 51 in 4425f3e
    
    return write_data(buf, len);
- - - to:
      
      ceph/src/rgw/rgw_asio_frontend.cc
      
      Line 66 in 4425f3e
      
      size_t write_data(const char* buf, size_t len) override {
- - - again this is the boost::asio::async_write(...)
      
      ceph/src/rgw/rgw_asio_frontend.cc
      
      Line 68 in 4425f3e
      
      auto bytes = boost::asio::async_write(stream, boost::asio::buffer(buf, len),
- - - and 'ec=system:104/Connection reset by peer' error is thrown from:
      
      ceph/src/rgw/rgw_asio_frontend.cc
      
      Line 72 in 4425f3e
      
      throw rgw::io::Exception(ec.value(), std::system_category());
- caught and propogated at:
  
  ceph/src/rgw/rgw_rest.cc
  
  Lines 761 to 762 in 4425f3e
  
  } catch (rgw::io::Exception& e) {
  
  return -e.code().value();
- back to (where it is not checked):
  
  ceph/src/rgw/rgw_rest.cc
  
  Line 307 in 4425f3e
  
  dump_body(s, outs);

completing the requst:

ceph/src/rgw/rgw_process.cc

Lines 288 to 290 in 4425f3e

    
           done: 
        
             try { 
        
               client_io->complete_request();

to:

ceph/src/rgw/rgw_asio_frontend.cc

Line 66 in 4425f3e

size_t write_data(const char* buf, size_t len) override {
the boost::asio::async_write(...) at this point of the flow, is called 3rd time, before the fix, an error was not returned here.

ceph/src/rgw/rgw_asio_frontend.cc

Line 68 in 4425f3e

auto bytes = boost::asio::async_write(stream, boost::asio::buffer(buf, len),

after the fix, for example like:

ceph/src/rgw/rgw_asio_frontend.cc

Lines 72 to 74 in f7d43f3

    
           if (ec==boost::asio::error::broken_pipe) { 
        
             boost::system::error_code ec_ignored; 
        
             stream.lowest_layer().shutdown(tcp::socket::shutdown_both, ec_ignored);

an error (also 'ec=system:104/Connection reset by peer') is thrown from:

ceph/src/rgw/rgw_asio_frontend.cc

Line 76 in f7d43f3

throw rgw::io::Exception(ec.value(), std::system_category());

and caught at:

ceph/src/rgw/rgw_process.cc

Line 291 in 4425f3e

} catch (rgw::io::Exception& e) {

cbodley · 2020-07-06T15:08:18Z

src/rgw/rgw_process.cc

@@ -291,6 +291,8 @@ int process_request(rgw::sal::RGWRadosStore* const store,
  } catch (rgw::io::Exception& e) {
    dout(0) << "ERROR: client_io->complete_request() returned "
            << e.what() << dendl;
+    perfcounter->inc(l_rgw_qlen, -1);
+    perfcounter->inc(l_rgw_qactive, -1);


can we address this issue in a separate pr? the counters should be encapsulated by the frontends, and shouldn't leak into process_request()

Done & working on handling it at the frontend level.

hi @mkogan1 , is the pr fix perfcounter->inc(l_rgw_qlen, -1); already submit? i search no result for it, if have not summit, i would like to submit a new pr about it

@joke-lee It's not merged yet, waiting on PR #36428 to see if it will facilitate a better solution than directly modifying counters in precess_request

although remote has closed the connection Fixes: https://tracker.ceph.com/issues/46332 Signed-off-by: Mark Kogan <mkogan@redhat.com>

mkogan1 · 2020-07-09T14:47:34Z

teuthology run:
https://pulpito.ceph.com/mkogan-2020-07-09_12:19:38-rgw:verify-wip-fix-endpoint-not-connected_i02-distro-basic-smithi/

ivancich · 2020-07-10T02:40:29Z

Teuthology Results:
http://pulpito.ceph.com/ivancich-2020-07-09_17:27:12-rgw-wip-eric-testing-1-distro-basic-smithi/
http://pulpito.ceph.com/ivancich-2020-07-09_17:27:31-rgw-wip-eric-testing-1-distro-basic-smithi/

Re-run of Errors:
http://pulpito.ceph.com/ivancich-2020-07-09_22:59:32-rgw-wip-eric-testing-1-distro-basic-smithi/

mkogan1 added bug-fix rgw needs-review labels Jul 2, 2020

mkogan1 requested review from mattbenjamin and cbodley July 2, 2020 16:56

mkogan1 self-assigned this Jul 2, 2020

mattbenjamin approved these changes Jul 2, 2020

View reviewed changes

mattbenjamin self-requested a review July 2, 2020 17:06

mattbenjamin reviewed Jul 2, 2020

View reviewed changes

cbodley reviewed Jul 2, 2020

View reviewed changes

mkogan1 force-pushed the wip-fix-endpoint-not-connected-r2 branch from be5e45a to f7d43f3 Compare July 6, 2020 10:51

cbodley reviewed Jul 6, 2020

View reviewed changes

mkogan1 force-pushed the wip-fix-endpoint-not-connected-r2 branch from f7d43f3 to e02aff0 Compare July 7, 2020 09:52

cbodley approved these changes Jul 7, 2020

View reviewed changes

cbodley added needs-qa and removed needs-review labels Jul 7, 2020

rgw: fix boost::asio::async_write() does not return error...

c997eb6

although remote has closed the connection Fixes: https://tracker.ceph.com/issues/46332 Signed-off-by: Mark Kogan <mkogan@redhat.com>

mkogan1 force-pushed the wip-fix-endpoint-not-connected-r2 branch from e02aff0 to c997eb6 Compare July 9, 2020 08:40

ivancich added the wip-eric-testing-1 for ivancich testing label Jul 9, 2020

ivancich merged commit c757bc8 into ceph:master Jul 10, 2020

ivancich removed needs-qa wip-eric-testing-1 for ivancich testing labels Aug 10, 2020

smithfarm mentioned this pull request Aug 15, 2020

octopus: rgw: fix boost::asio::async_write() does not return error... #36647

Merged

smithfarm mentioned this pull request Sep 15, 2020

nautilus: rgw: fix boost::asio::async_write() does not return error... #37157

Merged

rgw: fix boost::asio::async_write() does not return error... #35904

rgw: fix boost::asio::async_write() does not return error... #35904

mkogan1 commented Jul 2, 2020 •

edited

mattbenjamin left a comment

mattbenjamin left a comment

cbodley Jul 2, 2020

mkogan1 Jul 6, 2020

cbodley commented Jul 2, 2020

mkogan1 commented Jul 6, 2020

cbodley Jul 6, 2020

mkogan1 Jul 7, 2020

joke-lee Nov 11, 2020

mkogan1 Nov 12, 2020

mkogan1 commented Jul 9, 2020

ivancich commented Jul 10, 2020

rgw: fix boost::asio::async_write() does not return error... #35904

rgw: fix boost::asio::async_write() does not return error... #35904

Conversation

mkogan1 commented Jul 2, 2020 • edited

Checklist

mattbenjamin left a comment

Choose a reason for hiding this comment

mattbenjamin left a comment

Choose a reason for hiding this comment

cbodley Jul 2, 2020

Choose a reason for hiding this comment

mkogan1 Jul 6, 2020

Choose a reason for hiding this comment

cbodley commented Jul 2, 2020

mkogan1 commented Jul 6, 2020

cbodley Jul 6, 2020

Choose a reason for hiding this comment

mkogan1 Jul 7, 2020

Choose a reason for hiding this comment

joke-lee Nov 11, 2020

Choose a reason for hiding this comment

mkogan1 Nov 12, 2020

Choose a reason for hiding this comment

mkogan1 commented Jul 9, 2020

ivancich commented Jul 10, 2020

mkogan1 commented Jul 2, 2020 •

edited