Crash on MIMEScanner::append()

[masaori335]

AUTest(on Fedora 30) for #5585 crashed. The test is injecting over 16KB header in response.
FWIW, I didn't see this crash on CentOS 7.

#0  0x00007f5a1bdffeb5 in raise () from /lib64/libc.so.6
#1  0x00007f5a1bdea895 in abort () from /lib64/libc.so.6
#2  0x00007f5a1be42ee7 in __libc_message () from /lib64/libc.so.6
#3  0x00007f5a1be497bc in malloc_printerr () from /lib64/libc.so.6
#4  0x00007f5a1be4af2c in _int_free () from /lib64/libc.so.6
#5  0x00007f5a1c235cef in std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >::_M_mutate(unsigned long, unsigned long, char const*, unsigned long) ()
   from /lib64/libstdc++.so.6
#6  0x00007f5a1c237553 in std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >::_M_append(char const*, unsigned long) () from /lib64/libstdc++.so.6
#7  0x000000000079960c in std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >::append<ts::TextView> (this=0x7f59e1e4bf18, __svt=...)
    at /usr/include/c++/9/bits/basic_string.h:1323
#8  0x0000000000799595 in std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >::operator+=<ts::TextView> (this=0x7f59e1e4bf18, __svt=...)
    at /usr/include/c++/9/bits/basic_string.h:1212
#9  0x0000000000793b87 in MIMEScanner::append (this=0x7f59e1e4bf18, text=...) at MIME.cc:2324
#10 0x0000000000793f95 in MIMEScanner::get (this=0x7f59e1e4bf18, input=..., output=..., output_shares_input=@0x7f5a198eb92f: true, eof_p=false, scan_type=MIMEScanner::FIELD)
    at MIME.cc:2432
#11 0x00000000007941d9 in mime_parser_parse (parser=0x7f59e1e4bf18, heap=0x7f5a18087000, mh=0x7f5a180870b8, real_s=0x7f5a198ebad0,
    real_e=0x7f59e1ab4000 <error: Cannot access memory at address 0x7f59e1ab4000>, must_copy_strings=false, eof=false) at MIME.cc:2508
#12 0x0000000000785644 in http_parser_parse_resp (parser=0x7f59e1e4bf10, heap=0x7f5a18087000, hh=0x7f5a18087088, start=0x7f5a198ebad0,
    end=0x7f59e1ab4000 <error: Cannot access memory at address 0x7f59e1ab4000>, must_copy_strings=false, eof=false) at HTTP.cc:1297
#13 0x000000000078bfbe in HTTPHdr::parse_resp (this=0x7f59e1e4bdd0, parser=0x7f59e1e4bf10, r=0x11eeb30, bytes_used=0x7f5a198ebb6c, eof=false) at HdrTSOnly.cc:122
#14 0x0000000000725c5d in Http2Stream::update_write_request (this=0x7f59e1e4bd00, buf_reader=0x11eeb30, write_len=28716, call_update=false) at Http2Stream.cc:592
#15 0x0000000000724364 in Http2Stream::do_io_write (this=0x7f59e1e4bd00, c=0x7f59e1dc9390, nbytes=28716, abuffer=0x11eeb30, owner=false) at Http2Stream.cc:318
#16 0x0000000000700884 in HttpTunnel::producer_run (this=0x7f59e1dc9390, p=0x7f59e1dc95a0) at HttpTunnel.cc:882
#17 0x0000000000700027 in HttpTunnel::tunnel_run (this=0x7f59e1dc9390, p_arg=0x7f59e1dc95a0) at HttpTunnel.cc:699
#18 0x000000000069ce61 in HttpSM::handle_api_return (this=0x7f59e1dc8470) at HttpSM.cc:1658
#19 0x000000000069c5ad in HttpSM::state_api_callout (this=0x7f59e1dc8470, event=60000, data=0x0) at HttpSM.cc:1522
#20 0x000000000069b804 in HttpSM::state_api_callback (this=0x7f59e1dc8470, event=60000, data=0x0) at HttpSM.cc:1310
#21 0x000000000062c5ca in TSHttpTxnReenable (txnp=0x7f59e1dc8470, event=TS_EVENT_HTTP_CONTINUE) at traffic_server/InkAPI.cc:5926
#22 0x00007f59e2e74893 in cont_rewrite_headers (contp=0x11c9f60, event=TS_EVENT_HTTP_SEND_RESPONSE_HDR, edata=0x7f59e1dc8470) at header_rewrite/header_rewrite.cc:310
#23 0x000000000061fc22 in INKContInternal::handle_event (this=0x11c9f60, event=60007, edata=0x7f59e1dc8470) at traffic_server/InkAPI.cc:1074
#24 0x000000000061694b in Continuation::handleEvent (this=0x11c9f60, event=60007, data=0x7f59e1dc8470) at /usr/local/src/trafficserver/iocore/eventsystem/I_Continuation.h:190
#25 0x00000000006205c9 in APIHook::invoke (this=0x7f5a00039fe0, event=60007, edata=0x7f59e1dc8470) at traffic_server/InkAPI.cc:1299
#26 0x000000000069c325 in HttpSM::state_api_callout (this=0x7f59e1dc8470, event=0, data=0x0) at HttpSM.cc:1454
#27 0x00000000006ac070 in HttpSM::do_api_callout_internal (this=0x7f59e1dc8470) at HttpSM.cc:5137
#28 0x00000000006b5349 in HttpSM::set_next_state (this=0x7f59e1dc8470) at HttpSM.cc:7398
#29 0x00000000006b42ee in HttpSM::call_transact_and_set_next_state (this=0x7f59e1dc8470, f=0x0) at HttpSM.cc:7167
#30 0x000000000069c89c in HttpSM::handle_api_return (this=0x7f59e1dc8470) at HttpSM.cc:1590
#31 0x000000000069c5ad in HttpSM::state_api_callout (this=0x7f59e1dc8470, event=0, data=0x0) at HttpSM.cc:1522
#32 0x00000000006ac070 in HttpSM::do_api_callout_internal (this=0x7f59e1dc8470) at HttpSM.cc:5137
#33 0x00000000006bc8cf in HttpSM::do_api_callout (this=0x7f59e1dc8470) at HttpSM.cc:365
#34 0x000000000069e595 in HttpSM::state_read_server_response_header (this=0x7f59e1dc8470, event=100, data=0x7f5a14066468) at HttpSM.cc:1979

[maskit]

ASAN says:

==20372==ERROR: AddressSanitizer: attempting free on address which was not malloc()-ed: 0x000001409e48 in thread T2 ([ET_NET 0])

[maskit]

#0  __sanitizer::Die () at ../../../../libsanitizer/sanitizer_common/sanitizer_termination.cc:49
#1  0x00007ffff76a89cc in __asan::ScopedInErrorReport::~ScopedInErrorReport (this=0x7ffff148ba8e, __in_chrg=<optimized out>) at ../../../../libsanitizer/asan/asan_report.cc:185
#2  0x00007ffff76a6dd5 in __asan::ReportFreeNotMalloced (addr=21012040, free_stack=0x7ffff148c6b0) at ../../../../libsanitizer/asan/asan_report.cc:192
#3  0x00007ffff76a1989 in operator delete (ptr=0x1409e48 <http2StreamAllocator+552>) at ../../../../libsanitizer/asan/asan_new_delete.cc:165

[maskit]

@SolidWallOfCode Can you take a look? I was able to reproduce it with the config file for header_rewrite on #5585. It doesn't have to be on autest.

[masaori335]

As ASan reported, libstdc++-9.1.1-1 is attempting free on address in MIMEScanner::append().

trafficserver/proxy/hdrs/MIME.cc

Lines 2321 to 2326 in 2805b74

	MIMEScanner &
	MIMEScanner::append(TextView text)
	{
	m_line += text;
	return *this;
	}

The address looks &m_line + 10.

==19351==ERROR: AddressSanitizer: attempting free on address which was not malloc()-ed: 0x000001227f70 in thread T2 ([ET_NET 0])
    #0 0x7ffff76a49bf in operator delete(void*) (/lib64/libasan.so.5+0x1109bf)
    #1 0x7ffff6c28cee in std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >::_M_mutate(unsigned long, unsigned long, char const*, unsigned long) (/lib64/libstdc++.so.6+0x147cee)
    #2 0x7ffff6c2a552 in std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >::_M_append(char const*, unsigned long) (/lib64/libstdc++.so.6+0x149552)
    #3 0x9d60ec in std::enable_if<std::__and_<std::is_convertible<ts::TextView const&, std::basic_string_view<char, std::char_traits<char> > >, std::__not_<std::is_convertible<ts::TextView const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const*> >, std::__not_<std::is_convertible<ts::TextView const&, char const*> > >::value, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >&>::type std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char>>::append<ts::TextView>(ts::TextView const&) /usr/include/c++/9/bits/basic_string.h:1323
    #4 0x9d5f80 in std::enable_if<std::__and_<std::is_convertible<ts::TextView const&, std::basic_string_view<char, std::char_traits<char> > >, std::__not_<std::is_convertible<ts::TextView const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const*> >, std::__not_<std::is_convertible<ts::TextView const&, char const*> > >::value, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >&>::type std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >::operator+=<ts::TextView>(ts::TextView const&) /usr/include/c++/9/bits/basic_string.h:1212
    #5 0x9c88e2 in MIMEScanner::append(ts::TextView) /home/vagrant/trafficserver-asan/proxy/hdrs/MIME.cc:2324
...
0x000001227f70 is located 560 bytes inside of global variable 'http2StreamAllocator' defined in 'Http2Stream.cc:37:29' (0x1227d40) of size 3176
SUMMARY: AddressSanitizer: bad-free (/lib64/libasan.so.5+0x1109bf) in operator delete(void*)
...
(gdb) p &((Http2Stream *)(http2StreamAllocator.proto.typeObject)).http_parser.m_mime_parser.m_scanner.m_line
$37 = (std::string *) 0x1227f60 <http2StreamAllocator+544>
(gdb) p &((Http2Stream *)(http2StreamAllocator.proto.typeObject)).http_parser.m_mime_parser.m_scanner.m_state
$38 = (MimeParseState *) 0x1227f80 <http2StreamAllocator+576>

[masaori335]

In this case, the size of text (the arg of MIMEScanner::append) is 3216. This is obviously larger than default allocated size of m_line (std::string). (for gcc-9/libstdc++-9.1.1-1 , it's 15).
Then, reallocation is occurred and libstdc++-9.1.1-1 attempted to free address inside of MIMEScanner (in HTTPParser in Http2Stream) by somehow. Probably, m_line is created with replacement new.

trafficserver/proxy/hdrs/MIME.cc

Line 2318 in a98a1e3

new (&m_line) std::string;

From above hypothesis, if m_line is reserved enough size, the crash was not happened. (Obviously this is not solution)

diff --git a/proxy/hdrs/MIME.cc b/proxy/hdrs/MIME.cc
index 54b323f..4b3d878 100644
--- a/proxy/hdrs/MIME.cc
+++ b/proxy/hdrs/MIME.cc
@@ -2316,6 +2316,7 @@ MIMEScanner::init()
   // constructor in the proxy allocation system, call the CTOR here. Any memory that gets allocated
   // is supposed to be cleaned up by calling @c clear on this object.
   new (&m_line) std::string;
+  m_line.reserve(4096);
 }

Can we avoid using std::string for buffer in MIMEScanner?

[zwoop]

I was going to say, how did we end up with new and std::string here In the critical path?

[SolidWallOfCode]

It was #4948 and replaced a hand rolled ats_malloc. std::string isn't going to be any worse.

[SolidWallOfCode]

Sadly, I think @masaori335 is correct - the problem ultimately is the use of std::string in a situation where it's in a freelist controlled object. I think we can fix it with a tweak to http_parser_init and http_parser_clear. Let me get a PR for that and see if it fixes the problem. I presume testing this requires an HTTP2 client? Or alternatively I can run the AuTest?

[masaori335]

@SolidWallOfCode You can reproduce this crash with AUTest added by #5585. You can also reproduce this with the header rewrite config (huge_resp_hdrs.conf) with some H2 client (curl, nghttp2...whatever).

[masaori335]

#5605 looks reasonable for fixing this crash. Let's land it.

But I'm still wondering that we should keep the std::string or not. IIUC, it's internal buffer for a fragment of MIME header while parsing. Theoretically, we can keep the original chunk of header in the MIOBuffer, which we're parsing here, if we don't consume it. This sounds like we don't need to copy the chunk in the m_line.

[SolidWallOfCode]

You'd need an IOBufferChain because the field can span IO buffer blocks. There's also the possibility that the data isn't in an IOBufferBlock. I think this can be called from plugins (see TSHttpParserCreate / TSHttpParserClear / etc.). Those might depend on IOBufferBlock though. You definitely need to track down the uses of this to verify whether it can changed in that way.

[masaori335]

OK, leave it for now.