[TS-942] Assert in HttpTransact::HandleCacheOpenReadMiss

• Type: Bug
• Status: Closed
• Priority: Critical
• Resolution: Invalid
• Affects Version/s: 3.1.1
• Component/s: HTTP
• Assignee: Unassigned
• Reporter: Leif Hedstrom
• Created: 02/Sep/11 22:39
• Updated: 05/Jun/13 22:42
• Resolved: 20/Nov/12 16:26

Description

I'm seeing a crasher (see below), and it happens in code like this:

    if (s->current.server->ip == 0) {
      ink_release_assert(s->current.request_to == PARENT_PROXY ||
                  s->http_config_param->no_dns_forward_to_parent != 0);
      if (s->current.request_to == PARENT_PROXY) {

What happens is that .server->ip is indeed 0, but current.request_to is != PARENT_PROXY (it is instead ORIGIN_SERVER). I've not seen this before, and it reproduces rarely, so wondering if it could be IPv6 related.

Crasher:

(gdb) bt
#0  0x0000003f2de327f5 in raise (sig=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#1  0x0000003f2de33fd5 in abort () at abort.c:92
#2  0x00000000006407a1 in ink_die_die_die (return_code=<value optimized out>, message_format=<value optimized out>, ap=0x2b0756137600) at ink_error.cc:43
#3  ink_fatal_va(int, const char *, typedef __va_list_tag __va_list_tag *) (return_code=<value optimized out>, message_format=<value optimized out>, ap=0x2b0756137600) at ink_error.cc:65
#4  0x00000000006408d6 in ink_fatal (return_code=<value optimized out>, message_format=<value optimized out>) at ink_error.cc:73
#5  0x000000000063f761 in _ink_assert (a=0x668400 "s->current.request_to == PARENT_PROXY || s->http_config_param->no_dns_forward_to_parent != 0", f=<value optimized out>, l=2952) at ink_assert.cc:44
#6  0x0000000000516d5c in HttpTransact::HandleCacheOpenReadMiss (s=0x2b0763638018) at HttpTransact.cc:2952
#7  0x00000000004f08e2 in HttpSM::call_transact_and_set_next_state (this=0x2b0763637fb0, f=<value optimized out>) at HttpSM.cc:6339
#8  0x00000000004fffda in HttpSM::handle_api_return (this=0x2b0763637fb0) at HttpSM.cc:1520
#9  0x00000000004f2d42 in HttpSM::state_hostdb_lookup (this=<value optimized out>, event=<value optimized out>, data=<value optimized out>) at HttpSM.cc:2064
#10 0x0000000000503de0 in HttpSM::main_handler (this=0x2b0763637fb0, event=500, data=0x2b0760231860) at HttpSM.cc:2454
#11 0x000000000058d07b in handleEvent (cont=0x2b0763637fb0, ar=0x2b0760231860) at ../../iocore/eventsystem/I_Continuation.h:146
#12 reply_to_cont (cont=0x2b0763637fb0, ar=0x2b0760231860) at HostDB.cc:552
#13 0x000000000058e939 in HostDBContinuation::dnsEvent (this=<value optimized out>, event=<value optimized out>, e=<value optimized out>) at HostDB.cc:1504
#14 0x000000000059d281 in handleEvent (this=0x2a1c340, event=<value optimized out>, e=<value optimized out>) at ../../iocore/eventsystem/I_Continuation.h:146
#15 DNSEntry::postEvent (this=0x2a1c340, event=<value optimized out>, e=<value optimized out>) at DNS.cc:1265
#16 0x0000000000638204 in handleEvent (this=0x2b0755e36010, e=0x2a61090, calling_code=1) at I_Continuation.h:146
#17 EThread::process_event (this=0x2b0755e36010, e=0x2a61090, calling_code=1) at UnixEThread.cc:140
#18 0x0000000000638c7b in EThread::execute (this=0x2b0755e36010) at UnixEThread.cc:189
#19 0x0000000000637052 in spawn_thread_internal (a=0x1b206b0) at Thread.cc:88
#20 0x0000003f2e6068e0 in start_thread (arg=0x2b0756138710) at pthread_create.c:297
#21 0x0000003f2dee0c9d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#22 0x0000000000000000 in ?? ()
(gdb) frame 6
#6  0x0000000000516d5c in HttpTransact::HandleCacheOpenReadMiss (s=0x2b0763638018) at HttpTransact.cc:2952
2952	                  s->http_config_param->no_dns_forward_to_parent != 0);
(gdb) print s->current.request_to
$1 = ORIGIN_SERVER
(gdb) print s->current.server->ip
$2 = 0