[TS-4013] coredump in diag debug

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Fix Version/s: 6.1.0
• Assignee: James Peach
• Reporter: Masakazu Kitajo
• Created: 11/Nov/15 01:19
• Updated: 04/Feb/16 18:49
• Resolved: 11/Nov/15 05:07

Description

coredump under h2spec test if diag debug is enabled.

CONFIG proxy.config.diags.debug.enabled INT 1
CONFIG proxy.config.diags.debug.tags STRING http.*

xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxFATAL: Diags.cc:61: failed assert `nbytes < Size`
Process 39186 stopped
* thread #2: tid = 0x53dc08, 0x00007fff89b36286 libsystem_kernel.dylib`__pthread_kill + 10, name = '[ET_NET 4]', stop reason = signal SIGABRT
    frame #0: 0x00007fff89b36286 libsystem_kernel.dylib`__pthread_kill + 10
libsystem_kernel.dylib`__pthread_kill:
->  0x7fff89b36286 <+10>: jae    0x7fff89b36290            ; <+20>
    0x7fff89b36288 <+12>: movq   %rax, %rdi
    0x7fff89b3628b <+15>: jmp    0x7fff89b31c53            ; cerror_nocancel
    0x7fff89b36290 <+20>: retq   
(lldb) bt
* thread #2: tid = 0x53dc08, 0x00007fff89b36286 libsystem_kernel.dylib`__pthread_kill + 10, name = '[ET_NET 4]', stop reason = signal SIGABRT
  * frame #0: 0x00007fff89b36286 libsystem_kernel.dylib`__pthread_kill + 10
    frame #1: 0x00007fff91c249f9 libsystem_pthread.dylib`pthread_kill + 90
    frame #2: 0x00007fff87e199b3 libsystem_c.dylib`abort + 129
    frame #3: 0x000000000003a119 libtsutil.6.dylib`ink_die_die_die() + 9 at ink_error.cc:43
    frame #4: 0x000000000003a106 libtsutil.6.dylib`ink_fatal_va(fmt="%s:%d: failed assert `%s`", ap=0x00000000b048a7b0) + 198 at ink_error.cc:65
    frame #5: 0x000000000003a279 libtsutil.6.dylib`ink_fatal(message_format="%s:%d: failed assert `%s`") + 345 at ink_error.cc:73
    frame #6: 0x0000000000037e6f libtsutil.6.dylib`::_ink_assert(expression="nbytes < Size", file="Diags.cc", line=61) + 47 at ink_assert.cc:37
    frame #7: 0x000000000001c4db libtsutil.6.dylib`void vprintline<1024>(fp=0x00007fff775573f0, buffer=<no value available>, ap=0x00000000b048b100) [1024], __va_list_tag*) + 139 at Diags.cc:61
    frame #8: 0x000000000001c19b libtsutil.6.dylib`Diags::print_va(this=0x00000000007002d0, debug_tag="http2_hpack_decode", diags_level=DL_Debug, loc=0x00000000b048bc20, format_string="Decoded field: %s: %s", ap=0x00000000b048bc70) const + 1995 at Diags.cc:351
    frame #9: 0x000000000001ca7a libtsutil.6.dylib`Diags::log(this=0x00000000007002d0, tag="http2_hpack_decode", level=DL_Debug, file="HPACK.cc", func="decode_literal_header_field", line=665, format_string="Decoded field: %s: %s") const + 458 at Diags.cc:551
    frame #10: 0x0000000100199746 traffic_server`decode_literal_header_field(header=0x00000000b048be30, buf_start="", buf_end="", dynamic_table=0x0000000004f03b00) + 1222 at HPACK.cc:664
    frame #11: 0x000000010019b6d2 traffic_server`http2_decode_header_blocks(hdr=0x0000000005854790, buf_start="\x82\x87\x84A\x8a\b\x9d\\\v\x81p?y?\x99", buf_end="", dynamic_table=0x0000000004f03b00) + 322 at HTTP2.cc:607
    frame #12: 0x00000001001a6255 traffic_server`Http2Stream::decode_header_blocks(this=0x0000000005854740, dynamic_table=0x0000000004f03b00) + 69 at Http2Stream.h:97
    frame #13: 0x00000001001a55d1 traffic_server`rcv_continuation_frame(cs=0x0000000005024b50, cstate=0x0000000005024db8, frame=0x00000000b048c230) + 945 at Http2ConnectionState.cc:649

  5.1. Stream States
    ✓ idle: Sends a DATA frame
    ✓ idle: Sends a RST_STREAM frame
    ✓ idle: Sends a WINDOW_UPDATE frame
    ✓ idle: Sends a CONTINUATION frame
    ✓ half closed (remote): Sends a DATA frame
    ✓ half closed (remote): Sends a HEADERS frame
    ✓ half closed (remote): Sends a CONTINUATION frame
    × closed: Sends a CONTINUATION frame
      - The endpoint MUST treat this as a stream error (Section 5.4.2) of type STREAM_CLOSED.
        Expected: Stream close
          Actual: Test timeout