Skip to content
This repository has been archived by the owner on Jun 30, 2021. It is now read-only.

HTTP keepalive does not work by default #38

Closed
niol opened this issue Sep 25, 2017 · 15 comments
Closed

HTTP keepalive does not work by default #38

niol opened this issue Sep 25, 2017 · 15 comments
Assignees
@NathanFrench
Labels
bug CRITICAL thank you!
Milestone
v1.2.13

Comments

@niol
Copy link

niol commented Sep 25, 2017 •
edited
Loading

Details

From looking at the code, HTTP keepalive should work automatically if supported by the client. It seems however that evhtp_connection_free is called from libevent before a response can be sent.
Running in gdb, c->request->flags seems to include EVHTP_REQ_FLAG_KEEPALIVE so I do not know what's wrong. I'm still searching.

Context: I'm working on fixing haiwen/seafile#1119

Steps or code to reproduce the problem.

Please note below that wget is trying to reuse the TCP connection and fails because of no data received.

$ ./examples/test_basic &
$ LANG=C wget http://localhost:8081/simple/ http://localhost:8081/simple/
--2017-09-25 12:45:42--  http://localhost:8081/simple/
Resolving localhost (localhost)... ::1, 127.0.0.1
Connecting to localhost (localhost)|::1|:8081... failed: Connection refused.
Connecting to localhost (localhost)|127.0.0.1|:8081... connected.
HTTP request sent, awaiting response... 200 OK
Length: 6 [text/plain]
Saving to: 'index.html'

index.html        100%[===================>]       6  --.-KB/s    in 0s

2017-09-25 12:45:42 (779 KB/s) - 'index.html' saved [6/6]

--2017-09-25 12:45:42--  http://localhost:8081/simple/
Reusing existing connection to localhost:8081.
HTTP request sent, awaiting response... No data received.
Retrying.

--2017-09-25 12:45:43--  (try: 2)  http://localhost:8081/simple/
Connecting to localhost (localhost)|127.0.0.1|:8081... connected.
HTTP request sent, awaiting response... 200 OK
Length: 6 [text/plain]
Saving to: 'index.html'

index.html.3        100%[===================>]       6  --.-KB/s    in 0s

2017-09-25 12:45:43 (548 KB/s) - 'index.html' saved [6/6]

FINISHED --2017-09-25 12:45:43--
Total wall clock time: 1.1s
Downloaded: 2 files, 12 in 0s (644 KB/s)

Version

1.2.12-1
@NathanFrench NathanFrench self-assigned this Sep 25, 2017
@NathanFrench
Copy link
Collaborator

This looks like a pipeline issue. Would you mind doing a curl -vv http://... http//:...?

@NathanFrench
Copy link
Collaborator

NathanFrench commented Sep 25, 2017 •
edited
Loading 

 ~  wget -vv wget http://localhost:8081/simple/ http://localhost:8081/simple/                                                                                                                                                             Mon 25 Sep 2017 08:26:33 AM PDT
--2017-09-25 08:26:49--  http://wget/
Resolving wget (wget)... failed: Name or service not known.
wget: unable to resolve host address ‘wget’
--2017-09-25 08:26:50--  http://localhost:8081/simple/
Resolving localhost (localhost)... 127.0.0.1
Connecting to localhost (localhost)|127.0.0.1|:8081... connected.
HTTP request sent, awaiting response... 200 OK
Length: 734 [text/plain]
Saving to: ‘index.html’

index.html                                                         100%[==============================================================================================================================================================>]     734  --.-KB/s    in 0s      

2017-09-25 08:26:50 (69.3 MB/s) - ‘index.html’ saved [734/734]

--2017-09-25 08:26:50--  http://localhost:8081/simple/
Reusing existing connection to localhost:8081.
HTTP request sent, awaiting response... No data received.
Retrying.

--2017-09-25 08:26:51--  (try: 2)  http://localhost:8081/simple/
Connecting to localhost (localhost)|127.0.0.1|:8081... connected.
HTTP request sent, awaiting response... 200 OK
Length: 734 [text/plain]
Saving to: ‘index.html.1’

index.html.1                                                       100%[==============================================================================================================================================================>]     734  --.-KB/s    in 0s      

2017-09-25 08:26:51 (70.5 MB/s) - ‘index.html.1’ saved [734/734]

FINISHED --2017-09-25 08:26:51--
Total wall clock time: 1.8s
Downloaded: 2 files, 1.4K in 0s (69.9 MB/s)
 !  ~  cat index.html                                                                                                                                                                                                           1852ms  Mon 25 Sep 2017 08:26:51 AM PDT
print_path() full        = '/simple/'
             path        = '/simple/'
             file        = '(null)'
             match start = '/simple/'
             match_end   = ''
             methno      = '0'
print_kv() key = 'User-Agent', val = 'Wget/1.18 (linux-gnu)'
print_kv() key = 'Accept', val = '*/*'
print_kv() key = 'Accept-Encoding', val = 'identity'
print_kv() key = 'Host', val = 'localhost:8081'
print_kv() key = 'Connection', val = 'Keep-Alive'
print_kvs() key = 'User-Agent', val = 'Wget/1.18 (linux-gnu)'
print_kvs() key = 'Accept', val = '*/*'
print_kvs() key = 'Accept-Encoding', val = 'identity'
print_kvs() key = 'Host', val = 'localhost:8081'
print_kvs() key = 'Connection', val = 'Keep-Alive'
test_default_cb
 ~  cat index.html.1                                                                                                                                                                                                                      Mon 25 Sep 2017 08:27:00 AM PDT
print_path() full        = '/simple/'
             path        = '/simple/'
             file        = '(null)'
             match start = '/simple/'
             match_end   = ''
             methno      = '0'
print_kv() key = 'User-Agent', val = 'Wget/1.18 (linux-gnu)'
print_kv() key = 'Accept', val = '*/*'
print_kv() key = 'Accept-Encoding', val = 'identity'
print_kv() key = 'Host', val = 'localhost:8081'
print_kv() key = 'Connection', val = 'Keep-Alive'
print_kvs() key = 'User-Agent', val = 'Wget/1.18 (linux-gnu)'
print_kvs() key = 'Accept', val = '*/*'
print_kvs() key = 'Accept-Encoding', val = 'identity'
print_kvs() key = 'Host', val = 'localhost:8081'
print_kvs() key = 'Connection', val = 'Keep-Alive'
test_default_cb
 ~ 

Odd about that highlighted thing.

@NathanFrench
Copy link
Collaborator

Putting this here for reference:

DEBUG fd = 7, conn = 0x60a0000000a0   at htp__accept_cb_ (/home/mthomas/Code/libevhtp/evhtp.c:2558) 
DEBUG enter sock=7
   at htp__connection_accept_ (/home/mthomas/Code/libevhtp/evhtp.c:2392) 
DEBUG enter   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:595) 
DEBUG p == 0x625000000000   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:596) 
DEBUG [0x625000000000] data[0] = G (47)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_start   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:619) 
DEBUG enter   at hook_on_msg_begin_run (/home/mthomas/Code/libevhtp/parser.c:268) 
DEBUG [0x625000000000] data[1] = E (45)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_method   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:670) 
DEBUG enter   at hook_method_run (/home/mthomas/Code/libevhtp/parser.c:276) 
DEBUG [0x625000000000] data[4] = / (2f)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_spaces_before_uri   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:701) 
DEBUG [0x625000000000] data[5] = s (73)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_after_slash_in_uri   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:999) 
DEBUG [0x625000000000] data[6] = i (69)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_check_uri   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1074) 
DEBUG [0x625000000000] s_check_uri   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1074) 
DEBUG [0x625000000000] s_check_uri   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1074) 
DEBUG [0x625000000000] s_check_uri   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1074) 
DEBUG [0x625000000000] s_check_uri   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1074) 
DEBUG [0x625000000000] s_check_uri   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1074) 
DEBUG [0x625000000000] data[12] =   (20)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_after_slash_in_uri   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:999) 
DEBUG enter   at hook_path_run (/home/mthomas/Code/libevhtp/parser.c:280) 
DEBUG enter   at hook_uri_run (/home/mthomas/Code/libevhtp/parser.c:282) 
DEBUG [0x625000000000] data[13] = H (48)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_http_09   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1226) 
DEBUG [0x625000000000] data[14] = T (54)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_http_H   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1252) 
DEBUG [0x625000000000] data[15] = T (54)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] data[16] = P (50)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] data[17] = / (2f)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] data[18] = 1 (31)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] data[19] = . (2e)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] data[20] = 1 (31)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] data[21] =   (d)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] data[22] =   (a)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG enter   at hook_on_hdrs_begin_run (/home/mthomas/Code/libevhtp/parser.c:269) 
DEBUG [0x625000000000] data[23] = U (55)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_start   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1458) 
DEBUG [0x625000000000] data[24] = s (73)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_key   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1479) 
DEBUG enter   at hook_hdr_key_run (/home/mthomas/Code/libevhtp/parser.c:283) 
DEBUG [0x625000000000] data[34] =   (20)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_space_before_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1555) 
DEBUG [0x625000000000] data[35] = W (57)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_space_before_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1555) 
DEBUG [0x625000000000] data[36] = g (67)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] data[57] =   (a)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_almost_done   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1727) 
DEBUG [0x625000000000] data[58] = A (41)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_done   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1752) 
DEBUG enter   at hook_hdr_val_run (/home/mthomas/Code/libevhtp/parser.c:284) 
DEBUG [0x625000000000] data[59] = c (63)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_key   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1479) 
DEBUG enter   at hook_hdr_key_run (/home/mthomas/Code/libevhtp/parser.c:283) 
DEBUG [0x625000000000] data[65] =   (20)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_space_before_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1555) 
DEBUG [0x625000000000] data[66] = * (2a)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_space_before_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1555) 
DEBUG [0x625000000000] data[67] = / (2f)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] data[70] =   (a)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_almost_done   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1727) 
DEBUG [0x625000000000] data[71] = A (41)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_done   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1752) 
DEBUG enter   at hook_hdr_val_run (/home/mthomas/Code/libevhtp/parser.c:284) 
DEBUG [0x625000000000] data[72] = c (63)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_key   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1479) 
DEBUG enter   at hook_hdr_key_run (/home/mthomas/Code/libevhtp/parser.c:283) 
DEBUG [0x625000000000] data[87] =   (20)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_space_before_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1555) 
DEBUG [0x625000000000] data[88] = i (69)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_space_before_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1555) 
DEBUG [0x625000000000] data[89] = d (64)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] data[97] =   (a)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_almost_done   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1727) 
DEBUG [0x625000000000] data[98] = H (48)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_done   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1752) 
DEBUG enter   at hook_hdr_val_run (/home/mthomas/Code/libevhtp/parser.c:284) 
DEBUG [0x625000000000] data[99] = o (6f)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_key   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1479) 
DEBUG enter   at hook_hdr_key_run (/home/mthomas/Code/libevhtp/parser.c:283) 
DEBUG [0x625000000000] data[103] =   (20)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_space_before_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1555) 
DEBUG [0x625000000000] data[104] = l (6c)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_space_before_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1555) 
DEBUG [0x625000000000] data[105] = o (6f)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG enter   at hook_hostname_run (/home/mthomas/Code/libevhtp/parser.c:286) 
DEBUG [0x625000000000] data[119] =   (a)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_almost_done   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1727) 
DEBUG [0x625000000000] data[120] = C (43)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_done   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1752) 
DEBUG enter   at hook_hdr_val_run (/home/mthomas/Code/libevhtp/parser.c:284) 
DEBUG [0x625000000000] data[121] = o (6f)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_key   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1479) 
DEBUG enter   at hook_hdr_key_run (/home/mthomas/Code/libevhtp/parser.c:283) 
DEBUG [0x625000000000] data[131] =   (20)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_space_before_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1555) 
DEBUG [0x625000000000] data[132] = K (4b)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_space_before_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1555) 
DEBUG [0x625000000000] data[133] = e (65)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] data[143] =   (a)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_almost_done   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1727) 
DEBUG [0x625000000000] data[144] =   (d)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_done   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1752) 
DEBUG enter   at hook_hdr_val_run (/home/mthomas/Code/libevhtp/parser.c:284) 
DEBUG [0x625000000000] data[145] =   (a)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_almost_done   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1793) 
DEBUG enter   at hook_on_hdrs_complete_run (/home/mthomas/Code/libevhtp/parser.c:270) 
DEBUG enter   at hook_on_msg_complete_run (/home/mthomas/Code/libevhtp/parser.c:274) 
DEBUG nread = 146   at htp__connection_readcb_ (/home/mthomas/Code/libevhtp/evhtp.c:2100) 
DEBUG enter   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:595) 
DEBUG p == 0x625000000000   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:596) 
DEBUG [0x625000000000] data[0] = G (47)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_start   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:619) 
DEBUG enter   at hook_on_msg_begin_run (/home/mthomas/Code/libevhtp/parser.c:268) 
DEBUG nread = 1   at htp__connection_readcb_ (/home/mthomas/Code/libevhtp/evhtp.c:2100) 
DEBUG fd = 7, conn = 0x60a0000000a0   at htp__accept_cb_ (/home/mthomas/Code/libevhtp/evhtp.c:2558) 
DEBUG enter sock=7
   at htp__connection_accept_ (/home/mthomas/Code/libevhtp/evhtp.c:2392) 
DEBUG enter   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:595) 
DEBUG p == 0x625000000000   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:596) 
DEBUG [0x625000000000] data[0] = G (47)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_start   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:619) 
DEBUG enter   at hook_on_msg_begin_run (/home/mthomas/Code/libevhtp/parser.c:268) 
DEBUG [0x625000000000] data[1] = E (45)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_method   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:670) 
DEBUG enter   at hook_method_run (/home/mthomas/Code/libevhtp/parser.c:276) 
DEBUG [0x625000000000] data[4] = / (2f)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_spaces_before_uri   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:701) 
DEBUG [0x625000000000] data[5] = s (73)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_after_slash_in_uri   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:999) 
DEBUG [0x625000000000] data[6] = i (69)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_check_uri   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1074) 
DEBUG [0x625000000000] s_check_uri   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1074) 
DEBUG [0x625000000000] s_check_uri   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1074) 
DEBUG [0x625000000000] s_check_uri   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1074) 
DEBUG [0x625000000000] s_check_uri   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1074) 
DEBUG [0x625000000000] s_check_uri   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1074) 
DEBUG [0x625000000000] data[12] =   (20)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_after_slash_in_uri   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:999) 
DEBUG enter   at hook_path_run (/home/mthomas/Code/libevhtp/parser.c:280) 
DEBUG enter   at hook_uri_run (/home/mthomas/Code/libevhtp/parser.c:282) 
DEBUG [0x625000000000] data[13] = H (48)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_http_09   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1226) 
DEBUG [0x625000000000] data[14] = T (54)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_http_H   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1252) 
DEBUG [0x625000000000] data[15] = T (54)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] data[16] = P (50)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] data[17] = / (2f)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] data[18] = 1 (31)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] data[19] = . (2e)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] data[20] = 1 (31)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] data[21] =   (d)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] data[22] =   (a)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG enter   at hook_on_hdrs_begin_run (/home/mthomas/Code/libevhtp/parser.c:269) 
DEBUG [0x625000000000] data[23] = U (55)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_start   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1458) 
DEBUG [0x625000000000] data[24] = s (73)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_key   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1479) 
DEBUG enter   at hook_hdr_key_run (/home/mthomas/Code/libevhtp/parser.c:283) 
DEBUG [0x625000000000] data[34] =   (20)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_space_before_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1555) 
DEBUG [0x625000000000] data[35] = W (57)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_space_before_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1555) 
DEBUG [0x625000000000] data[36] = g (67)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] data[57] =   (a)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_almost_done   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1727) 
DEBUG [0x625000000000] data[58] = A (41)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_done   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1752) 
DEBUG enter   at hook_hdr_val_run (/home/mthomas/Code/libevhtp/parser.c:284) 
DEBUG [0x625000000000] data[59] = c (63)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_key   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1479) 
DEBUG enter   at hook_hdr_key_run (/home/mthomas/Code/libevhtp/parser.c:283) 
DEBUG [0x625000000000] data[65] =   (20)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_space_before_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1555) 
DEBUG [0x625000000000] data[66] = * (2a)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_space_before_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1555) 
DEBUG [0x625000000000] data[67] = / (2f)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] data[70] =   (a)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_almost_done   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1727) 
DEBUG [0x625000000000] data[71] = A (41)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_done   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1752) 
DEBUG enter   at hook_hdr_val_run (/home/mthomas/Code/libevhtp/parser.c:284) 
DEBUG [0x625000000000] data[72] = c (63)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_key   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1479) 
DEBUG enter   at hook_hdr_key_run (/home/mthomas/Code/libevhtp/parser.c:283) 
DEBUG [0x625000000000] data[87] =   (20)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_space_before_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1555) 
DEBUG [0x625000000000] data[88] = i (69)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_space_before_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1555) 
DEBUG [0x625000000000] data[89] = d (64)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] data[97] =   (a)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_almost_done   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1727) 
DEBUG [0x625000000000] data[98] = H (48)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_done   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1752) 
DEBUG enter   at hook_hdr_val_run (/home/mthomas/Code/libevhtp/parser.c:284) 
DEBUG [0x625000000000] data[99] = o (6f)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_key   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1479) 
DEBUG enter   at hook_hdr_key_run (/home/mthomas/Code/libevhtp/parser.c:283) 
DEBUG [0x625000000000] data[103] =   (20)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_space_before_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1555) 
DEBUG [0x625000000000] data[104] = l (6c)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_space_before_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1555) 
DEBUG [0x625000000000] data[105] = o (6f)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG enter   at hook_hostname_run (/home/mthomas/Code/libevhtp/parser.c:286) 
DEBUG [0x625000000000] data[119] =   (a)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_almost_done   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1727) 
DEBUG [0x625000000000] data[120] = C (43)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_done   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1752) 
DEBUG enter   at hook_hdr_val_run (/home/mthomas/Code/libevhtp/parser.c:284) 
DEBUG [0x625000000000] data[121] = o (6f)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_key   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1479) 
DEBUG enter   at hook_hdr_key_run (/home/mthomas/Code/libevhtp/parser.c:283) 
DEBUG [0x625000000000] data[131] =   (20)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_space_before_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1555) 
DEBUG [0x625000000000] data[132] = K (4b)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_space_before_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1555) 
DEBUG [0x625000000000] data[133] = e (65)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] s_hdrline_hdr_val   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1593) 
DEBUG [0x625000000000] data[143] =   (a)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_almost_done   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1727) 
DEBUG [0x625000000000] data[144] =   (d)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_hdr_done   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1752) 
DEBUG enter   at hook_hdr_val_run (/home/mthomas/Code/libevhtp/parser.c:284) 
DEBUG [0x625000000000] data[145] =   (a)   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:607) 
DEBUG [0x625000000000] s_hdrline_almost_done   at htparser_run (/home/mthomas/Code/libevhtp/parser.c:1793) 
DEBUG enter   at hook_on_hdrs_complete_run (/home/mthomas/Code/libevhtp/parser.c:270) 
DEBUG enter   at hook_on_msg_complete_run (/home/mthomas/Code/libevhtp/parser.c:274) 
DEBUG nread = 146   at htp__connection_readcb_ (/home/mthomas/Code/libevhtp/evhtp.c:2100)

@NathanFrench
Copy link
Collaborator 

---request begin---
GET /simple/ HTTP/1.1
User-Agent: Wget/1.18 (linux-gnu)
Accept: */*
Accept-Encoding: identity
Host: localhost:8081
Connection: Keep-Alive

---request end---
HTTP request sent, awaiting response... 
---response begin---
HTTP/1.1 200 OK
Content-Length: 734
Content-Type: text/plain

---response end---
200 OK
Registered socket 3 for persistent reuse.
Length: 734 [text/plain]
Saving to: ‘index.html.6’

index.html.6                                                       100%[==============================================================================================================================================================>]     734  --.-KB/s    in 0s      

2017-09-25 08:36:27 (195 MB/s) - ‘index.html.6’ saved [734/734]

URI encoding = ‘UTF-8’
Converted file name 'index.html' (UTF-8) -> 'index.html' (UTF-8)
--2017-09-25 08:36:27--  http://localhost:8081/simple/
Reusing existing connection to localhost:8081.
Reusing fd 3.

---request begin---
GET /simple/ HTTP/1.1
User-Agent: Wget/1.18 (linux-gnu)
Accept: */*
Accept-Encoding: identity
Host: localhost:8081
Connection: Keep-Alive

---request end---
HTTP request sent, awaiting response... No data received.
Disabling further reuse of socket 3.
Closed fd 3
Retrying.

--2017-09-25 08:36:28--  (try: 2)  http://localhost:8081/simple/
Found localhost in host_name_addresses_map (0x5646a7b8f3f0)
Connecting to localhost (localhost)|127.0.0.1|:8081... connected.
Created socket 3.
Releasing 0x00005646a7b8f3f0 (new refcount 1).

---request begin---
GET /simple/ HTTP/1.1
User-Agent: Wget/1.18 (linux-gnu)
Accept: */*
Accept-Encoding: identity
Host: localhost:8081
Connection: Keep-Alive

---request end---
HTTP request sent, awaiting response... 
---response begin---
HTTP/1.1 200 OK
Content-Length: 734
Content-Type: text/plain

---response end---
200 OK
Registered socket 3 for persistent reuse.
Length: 734 [text/plain]
Saving to: ‘index.html.7’

index.html.7                                                       100%[==============================================================================================================================================================>]     734  --.-KB/s    in 0s      

2017-09-25 08:36:28 (222 MB/s) - ‘index.html.7’ saved [734/734]

FINISHED --2017-09-25 08:36:28--
Total wall clock time: 1.9s
Downloaded: 2 files, 1.4K in 0s (208 MB/s)

```

@NathanFrench
Copy link
Collaborator

This is going to be a fun one. Thanks!

@niol
Copy link
Author

niol commented Sep 25, 2017 

$ LANG=C curl -4vv http://localhost:8081/simple/ http://localhost:8081/simple/
*   Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to localhost (127.0.0.1) port 8081 (#0)
> GET /simple/ HTTP/1.1
> Host: localhost:8081
> User-Agent: curl/7.55.1
> Accept: */*
>
< HTTP/1.1 200 OK
< Content-Length: 6
< Content-Type: text/plain
<
* Connection #0 to host localhost left intact
simple* Found bundle for host localhost: 0x563c24aa3350 [can pipeline]
* Re-using existing connection! (#0) with host localhost
* Connected to localhost (127.0.0.1) port 8081 (#0)
> GET /simple/ HTTP/1.1
> Host: localhost:8081
> User-Agent: curl/7.55.1
> Accept: */*
>
* Connection died, retrying a fresh connect
* Closing connection 0
* Issue another request to this URL: 'http://localhost:8081/simple/'
* Hostname localhost was found in DNS cache
*   Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to localhost (127.0.0.1) port 8081 (#1)
> GET /simple/ HTTP/1.1
> Host: localhost:8081
> User-Agent: curl/7.55.1
> Accept: */*
>
< HTTP/1.1 200 OK
< Content-Length: 6
< Content-Type: text/plain
<
* Connection #1 to host localhost left intact
simple

@NathanFrench
Copy link
Collaborator

DEBUG error 3, freeing connection at htp__connection_readcb_ (/home/mthomas/Code/libevhtp/evhtp.c:2140)

Blammo: 3 == htparse_error_inval_reqline.

Now we're getting somewhere.

@NathanFrench
Copy link
Collaborator

This is cropping up in many of my unit tests now; marking as critical.

@niol
Copy link
Author

niol commented Sep 27, 2017

htparser_run seems to be failing because ht_parser_init is called with type=htp_type_response.

The following statement feels wrong because c is a connection and c->type is either evhtp_type_server or evhtp_type_client but has nothing to do with request or response.

htparser_init(c->parser, c->type);

The following simple patch seems to fix the problem.

--- libevhtp-1.2.12-1.orig/evhtp.c
+++ libevhtp-1.2.12-1/evhtp.c
@@ -2217,7 +2217,7 @@ htp__connection_writecb_(struct bufferev
             c->htp = orig_htp;
         }

-        htparser_init(c->parser, c->type);
+        htparser_init(c->parser, htp_type_request);
         htparser_set_userdata(c->parser, c);

         return;

I'm happy, I've been stuck on this for a while, your comment really helped me. Is enabling debug documented somewhere?

@NathanFrench
Copy link
Collaborator

Not sure that above patch is the official fix since that function can be either client or server. type is defined in the constructor.

I just added the debug option at the last release

cmake -DEVHTP_DEBUG:STRING=ON -DCMAKE_BUILD_TYPE=Debug ..

And I'm adding more as I dig into this.

@NathanFrench
Copy link
Collaborator

Added more logging for this part; starting to come together.

DEBUG not type of request or response?   at htparser_run (/home/nathan/Code/libevhtp/parser.c:714) 
DEBUG struct htparser {
    htpparse_error = 0
    parser_state   = 0
    parser_flags   = 0
    eval_hdr_val   = 0
    htp_type       = 1
    htp_scheme     = 0
    htp_method     = 16
    multipart      = 
    major          = 
    minor          = 
    content_len    = 0
    orig_clen      = 0
    bytes_read     = 1
    total_read     = 1
    status         = 0
    status_count   = 0
    scheme_offset  = (null)
    host_offset    = (null)
    port_offset    = (null)
    path_offset    = (null)
    args_offset    = (null)
    userdata       = 0x60a0000000a0
    buf_idx        = 1
    buf            = G
};   at log__htparser_s_ (/home/nathan/Code/libevhtp/parser.c:178)

NathanFrench added a commit that referenced this issue Sep 28, 2017
@NathanFrench
[#38] some extra debug logging
9db2231
@NathanFrench
Copy link
Collaborator

Fix incoming.

@NathanFrench
Copy link
Collaborator

Lulz

(gdb) print &c->parser->type
$5 = (htp_type *) 0x625000000010
(gdb) watch *0x625000000010
Hardware watchpoint 3: *0x625000000010
(gdb) c
Continuing.
Hardware watchpoint 3: *0x625000000010

Old value = 0
New value = 1

htparser_init (p=0x625000000000, type=htp_type_response) at /home/mthomas/Code/libevhtp/parser.c:537
537	}

NathanFrench added a commit to NathanFrench/libevhtp that referenced this issue Sep 29, 2017
@NathanFrench
[Yellow-Camper#38] I'm an idiot, fix for parser_init.
7c13a57 
Dear everyone,

I am an idiot.

This fixes Yellow-Camper#38

Yours,
Nathan
@NathanFrench
Copy link
Collaborator

NathanFrench commented Sep 29, 2017 •
edited
Loading

Welp, there we go.

--2017-09-29 09:46:34--  http://wget/
Resolving wget (wget)... failed: Name or service not known.
wget: unable to resolve host address ‘wget’
--2017-09-29 09:46:35--  http://localhost:8081/simple/
Resolving localhost (localhost)... 127.0.0.1
Connecting to localhost (localhost)|127.0.0.1|:8081... connected.
HTTP request sent, awaiting response... 200 OK
Length: 734 [text/plain]
Saving to: ‘index.html.6’

index.html.6                     100%[==========================================================>]     734  --.-KB/s    in 0s      

2017-09-29 09:46:35 (57.0 MB/s) - ‘index.html.6’ saved [734/734]

--2017-09-29 09:46:35--  http://localhost:8081/simple/
Reusing existing connection to localhost:8081.
HTTP request sent, awaiting response... 200 OK
Length: 734 [text/plain]
Saving to: ‘index.html.7’

index.html.7                     100%[==========================================================>]     734  --.-KB/s    in 0s      

2017-09-29 09:46:35 (315 MB/s) - ‘index.html.7’ saved [734/734]

FINISHED --2017-09-29 09:46:35--
Total wall clock time: 0.9s
Downloaded: 2 files, 1.4K in 0s (96.6 MB/s)

Thank you very much for the issue!

@NathanFrench
Copy link
Collaborator

NathanFrench commented Sep 29, 2017 •
edited
Loading

This has been broken since the dawn of time by the way (and you were right) 👯‍♀️

@NathanFrench NathanFrench added this to the v1.2.13 milestone Nov 2, 2017
@flokli flokli mentioned this issue Nov 19, 2017
Open
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees

@NathanFrench NathanFrench

Labels
bug CRITICAL thank you!
Projects
None yet
Milestone
v1.2.13
Development

No branches or pull requests
2 participants
@niol @NathanFrench