8000 Fix for keep-alive memory leak by jbcrail · Pull Request #29 · haywire/haywire · GitHub
[go: up one dir, main page]
More Web Proxy on the site http://driver.im/
Skip to content

Fix for keep-alive memory leak #29

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Open
wants to merge 1 commit into
base: trying_to_fix_memory_leak
Choose a base branch
from
Open

Fix for keep-alive memory leak #29

wants to merge 1 commit into from

Conversation

jbcrail
Copy link
Contributor
@jbcrail jbcrail commented Jun 4, 2013

Building upon your work in http_request_on_header_field(), I refactored the code that set and deleted a request header into separate functions. I changed the body of http_request_on_header_field() and http_request_on_header_value() to be the same.

I ran the following tests:

bin/wrk/wrk -d20 -t8 -c64 --pipeline 2048 http://0.0.0.0:8000
ab -n 100000 -c 8 -k http://0.0.0.0:8000/
httperf-0.9.0/src/httperf --server=localhost --port=8000 --num-conns=4 --num-calls=10000

The result from valgrind was much better:

$ valgrind --tool=memcheck --leak-check=full --show-reachable=yes --track-origins=yes ./builds/unix/debug/hello_world
==21344== Memcheck, a memory error detector
==21344== Copyright (C) 2002-2012, and GNU GPL'd, by Julian Seward et al.
==21344== Using Valgrind-3.8.1 and LibVEX; rerun with -h for copyright info
==21344== Command: ./builds/unix/debug/hello_world
==21344==
Added route /
Listening on 0.0.0.0:8000
read: connection reset by peer
^C==21344==
==21344== HEAP SUMMARY:
==21344==     in use at exit: 1,408 bytes in 3 blocks
==21344==   total heap usage: 1,814,546 allocs, 1,814,543 frees, 9,362,912,032 bytes allocated
==21344==
==21344== 192 bytes in 1 blocks are still reachable in loss record 1 of 3
==21344==    at 0x4C2CD7B: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==21344==    by 0x404972: rxt_init (radix.c:467)
==21344==    by 0x4034F1: hw_http_add_route (http_server.c:41)
==21344==    by 0x4034B9: main (program.c:25)
==21344==
==21344== 192 bytes in 1 blocks are still reachable in loss record 2 of 3
==21344==    at 0x4C2CD7B: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==21344==    by 0x403FDE: rxt_put (radix.c:240)
==21344==    by 0x403512: hw_http_add_route (http_server.c:43)
==21344==    by 0x4034B9: main (program.c:25)
==21344==
==21344== 1,024 bytes in 1 blocks are still reachable in loss record 3 of 3
==21344==    at 0x4C2CF8E: realloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==21344==    by 0x40AA49: maybe_resize (core.c:605)
==21344==    by 0x40AC31: uv__io_start (core.c:642)
==21344==    by 0x4126BA: uv__read_start_common (stream.c:1301)
==21344==    by 0x412732: uv_read_start (stream.c:1310)
==21344==    by 0x4036FE: http_stream_on_connect (http_server.c:89)
==21344==    by 0x4106E6: uv__server_io (stream.c:533)
==21344==    by 0x4179C2: uv__io_poll (linux-core.c:211)
==21344==    by 0x40A53F: uv_run (core.c:317)
==21344==    by 0x403643: hw_http_open (http_server.c:71)
==21344==    by 0x4034C8: main (program.c:26)
==21344==
==21344== LEAK SUMMARY:
==21344==    definitely lost: 0 bytes in 0 blocks
==21344==    indirectly lost: 0 bytes in 0 blocks
==21344==      possibly lost: 0 bytes in 0 blocks
==21344==    still reachable: 1,408 bytes in 3 blocks
==21344==         suppressed: 0 bytes in 0 blocks
==21344==
==21344== For counts of detected and suppressed errors, rerun with: -v
==21344== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 2 from 2)

@kellabyte
Copy link
Collaborator

Do you have any results using Wrk? Every time I make a gain in Wrk I lose in HttpPerf and when I fix HttpPerf I lose in Wrk work loads. Could you please give it a run with Wrk? and post Valgrind results? :)

@jbcrail
Copy link
Contributor Author
jbcrail commented Jun 6, 2013

tl;dr I think the source of memory leaks is caused by the server being prematurely killed before the pending responses have a chance to finish and cleanup.

To answer your question, the above valgrind results are from my previous tests using wrk, ab, and httperf in one testing session.

However, I was able to replicate your memory leaks after I varied the order of tests in the same way that you did. I started the server and ran the following tests:

bin/wrk/wrk -d20 -t8 -c64 --pipeline 2048 http://0.0.0.0:8000
ab -n 100000 -c 8 -k http://0.0.0.0:8000/
httperf-0.9.0/src/httperf --server=localhost --port=8000 --num-conns=4 --num-calls=10000
ab -n 100000 -c 8 -k http://0.0.0.0:8000/
bin/wrk/wrk -d20 -t8 -c64 --pipeline 2048 http://0.0.0.0:8000

Here are the valgrind results:

$ valgrind  --tool=memcheck --leak-check=full --show-reachable=yes --track-origins=yes ./builds/unix/debug/hello_
world
==2483== Memcheck, a memory error detector
==2483== Copyright (C) 2002-2012, and GNU GPL'd, by Julian Seward et al.
==2483== Using Valgrind-3.8.1 and LibVEX; rerun with -h for copyright info
==2483== Command: ./builds/unix/debug/hello_world
==2483==
Added route /
Listening on 0.0.0.0:8000
^C==2483==
==2483== HEAP SUMMARY:
==2483==     in use at exit: 18,661,434 bytes in 105,569 blocks
==2483==   total heap usage: 6,444,396 allocs, 6,338,827 frees, 32,125,554,372 bytes allocated
==2483==
==2483== 2 bytes in 1 blocks are still reachable in loss record 1 of 11
==2483==    at 0x4C2CD7B: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==2483==    by 0x408A43: http_request_on_url (http_request.c:76)
==2483==    by 0x405C9B: http_parser_execute (http_parser.c:1031)
==2483==    by 0x403820: http_stream_on_read (http_server.c:118)
==2483==    by 0x411CB8: uv__read (stream.c:1023)
==2483==    by 0x4120EF: uv__stream_io (stream.c:1118)
==2483==    by 0x417A56: uv__io_poll (linux-core.c:211)
==2483==    by 0x40A5D3: uv_run (core.c:317)
==2483==    by 0x403643: hw_http_open (http_server.c:74)
==2483==    by 0x4034C8: main (program.c:26)
==2483==
==2483== 24 bytes in 1 blocks are still reachable in loss record 2 of 11
==2483==    at 0x4C2CD7B: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==2483==    by 0x4089BB: http_request_on_message_begin (http_request.c:65)
==2483==    by 0x40584A: http_parser_execute (http_parser.c:908)
==2483==    by 0x403820: http_stream_on_read (http_server.c:118)
==2483==    by 0x411CB8: uv__read (stream.c:1023)
==2483==    by 0x4120EF: uv__stream_io (stream.c:1118)
==2483==    by 0x417A56: uv__io_poll (linux-core.c:211)
==2483==    by 0x40A5D3: uv_run (core.c:317)
==2483==    by 0x403643: hw_http_open (http_server.c:74)
==2483==    by 0x4034C8: main (program.c:26)
==2483==
==2483== 176 bytes in 1 blocks are still reachable in loss record 3 of 11
==2483==    at 0x4C2CD7B: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==2483==    by 0x4038B6: http_server_write_response (http_server.c:139)
==2483==    by 0x408B9B: http_request_on_message_complete (http_request.c:117)
==2483==    by 0x4073F7: http_parser_execute (http_parser.c:1633)
==2483==    by 0x403820: http_stream_on_read (http_server.c:118)
==2483==    by 0x411CB8: uv__read (stream.c:1023)
==2483==    by 0x4120EF: uv__stream_io (stream.c:1118)
==2483==    by 0x417A56: uv__io_poll (linux-core.c:211)
==2483==    by 0x40A5D3: uv_run (core.c:317)
==2483==    by 0x403643: hw_http_open (http_server.c:74)
==2483==    by 0x4034C8: main (program.c:26)
==2483==
==2483== 192 bytes in 1 blocks are still reachable in loss record 4 of 11
==2483==    at 0x4C2CD7B: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==2483==    by 0x404A06: rxt_init (radix.c:467)
==2483==    by 0x4034F1: hw_http_add_route (http_server.c:44)
==2483==    by 0x4034B9: main (program.c:25)
==2483==
==2483== 192 bytes in 1 blocks are still reachable in loss record 5 of 11
==2483==    at 0x4C2CD7B: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==2483==    by 0x404072: rxt_put (radix.c:240)
==2483==    by 0x403512: hw_http_add_route (http_server.c:46)
==2483==    by 0x4034B9: main (program.c:25)
==2483==
==2483== 192 bytes in 1 blocks are still reachable in loss record 6 of 11
==2483==    at 0x4C2CD7B: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==2483==    by 0x404A06: rxt_init (radix.c:467)
==2483==    by 0x4089F0: http_request_on_message_begin (http_request.c:67)
==2483==    by 0x40584A: http_parser_execute (http_parser.c:908)
==2483==    by 0x403820: http_stream_on_read (http_server.c:118)
==2483==    by 0x411CB8: uv__read (stream.c:1023)
==2483==    by 0x4120EF: uv__stream_io (stream.c:1118)
==2483==    by 0x417A56: uv__io_poll (linux-core.c:211)
==2483==    by 0x40A5D3: uv_run (core.c:317)
==2483==    by 0x403643: hw_http_open (http_server.c:74)
==2483==    by 0x4034C8: main (program.c:26)
==2483==
==2483== 416 bytes in 1 blocks are still reachable in loss record 7 of 11
==2483==    at 0x4C2CD7B: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==2483==    by 0x403677: http_stream_on_connect (http_server.c:82)
==2483==    by 0x41077A: uv__server_io (stream.c:533)
==2483==    by 0x417A56: uv__io_poll (linux-core.c:211)
==2483==    by 0x40A5D3: uv_run (core.c:317)
==2483==    by 0x403643: hw_http_open (http_server.c:74)
==2483==    by 0x4034C8: main (program.c:26)
==2483==
==2483== 1,024 bytes in 1 blocks are still reachable in loss record 8 of 11
==2483==    at 0x4C2CF8E: realloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==2483==    by 0x40AADD: maybe_resize (core.c:605)
==2483==    by 0x40ACC5: uv__io_start (core.c:642)
==2483==    by 0x41274E: uv__read_start_common (stream.c:1301)
==2483==    by 0x4127C6: uv_read_start (stream.c:1310)
==2483==    by 0x4036FE: http_stream_on_connect (http_server.c:92)
==2483==    by 0x41077A: uv__server_io (stream.c:533)
==2483==    by 0x417A56: uv__io_poll (linux-core.c:211)
==2483==    by 0x40A5D3: uv_run (core.c:317)
==2483==    by 0x403643: hw_http_open (http_server.c:74)
==2483==    by 0x4034C8: main (program.c:26)
==2483==
==2483== 26,208 bytes in 63 blocks are possibly lost in loss record 9 of 11
==2483==    at 0x4C2CD7B: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==2483==    by 0x403677: http_stream_on_connect (http_server.c:82)
==2483==    by 0x41077A: uv__server_io (stream.c:533)
==2483==    by 0x417A56: uv__io_poll (linux-core.c:211)
==2483==    by 0x40A5D3: uv_run (core.c:317)
==2483==    by 0x403643: hw_http_open (http_server.c:74)
==2483==    by 0x4034C8: main (program.c:26)
==2483==
==2483== 65,536 bytes in 1 blocks are still reachable in loss record 10 of 11
==2483==    at 0x4C2CD7B: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==2483==    by 0x403751: http_stream_on_alloc (http_server.c:99)
==2483==    by 0x4117F1: uv__read (stream.c:955)
==2483==    by 0x4120EF: uv__stream_io (stream.c:1118)
==2483==    by 0x417A56: uv__io_poll (linux-core.c:211)
==2483==    by 0x40A5D3: uv_run (core.c:317)
==2483==    by 0x403643: hw_http_open (http_server.c:74)
==2483==    by 0x4034C8: main (program.c:26)
==2483==
==2483== 18,567,472 bytes in 105,497 blocks are possibly lost in loss record 11 of 11
==2483==    at 0x4C2CD7B: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==2483==    by 0x4038B6: http_server_write_response (http_server.c:139)
==2483==    by 0x408B9B: http_request_on_message_complete (http_request.c:117)
==2483==    by 0x4073F7: http_parser_execute (http_parser.c:1633)
==2483==    by 0x403820: http_stream_on_read (http_server.c:118)
==2483==    by 0x411CB8: uv__read (stream.c:1023)
==2483==    by 0x4120EF: uv__stream_io (stream.c:1118)
==2483==    by 0x417A56: uv__io_poll (linux-core.c:211)
==2483==    by 0x40A5D3: uv_run (core.c:317)
==2483==    by 0x403643: hw_http_open (http_server.c:74)
==2483==    by 0x4034C8: main (program.c:26)
==2483==
==2483== LEAK SUMMARY:
==2483==    definitely lost: 0 bytes in 0 blocks
==2483==    indirectly lost: 0 bytes in 0 blocks
==2483==      possibly lost: 18,593,680 bytes in 105,560 blocks
==2483==    still reachable: 67,754 bytes in 9 blocks
==2483==         suppressed: 0 bytes in 0 blocks
==2483==
==2483== For counts of detected and suppressed errors, rerun with: -v
==2483== ERROR SUMMARY: 2 errors from 2 contexts (suppressed: 2 from 2)

When investigating the source of the largest leak, http_server_write_response, I put in counters to keep track of the number of active connections and pending responses. I first noticed that there were more calls to http_server_write_response (where the response memory is allocated) than calls to http_server_after_write (where the response memory is deallocated).

Here is the sample output I added to http_server.c:

printf("active connections: %-4lu  pending responses: %lu\n", active_connections, pending_responses);

Whenever http_stream_on_connect or http_stream_on_close are called, I print the above statement. In short, I use this to track server activity during testing.

My hypothesis is that valgrind memory leaks are a result of the server being killed immediately after the tests have finished, even though the server is still active processing requests. Whenever both counters reach 0, then the server is idle and all memory has been deallocated; the server can be killed, and valgrind will be much happier.

I've included a diff of the debug statements I used in http_server.c

diff --git a/src/haywire/http_server.c b/src/haywire/http_server.c
index 5c1f68b..8358434 100644
--- a/src/haywire/http_server.c
+++ b/src/haywire/http_server.c
@@ -32,6 +32,9 @@ static uv_loop_t* uv_loop;
 static uv_tcp_t server;
 static http_parser_settings parser_settings;

+static size_t active_connections = 0;
+static size_t pending_responses = 0;
+
 rxt_node *routes = NULL;

 void hw_http_add_route(char *route, http_request_callback callback)
@@ -87,6 +90,7 @@ void http_stream_on_connect(uv_stream_t* stream, int status)

     r = uv_accept(stream, (uv_stream_t*)&context->stream);
     r = uv_read_start((uv_stream_t*)&context->stream, http_stream_on_alloc, http_stream_on_read);
+    printf("active connections: %-4lu  pending writes: %lu\n", ++active_connections, pending_responses);
 }

 uv_buf_t http_stream_on_alloc(uv_handle_t* client, size_t suggested_size)
@@ -101,6 +105,7 @@ void http_stream_on_close(uv_handle_t* handle)
 {
     http_request_context* context = (http_request_context*)handle->data;
     free(context);
+    printf("active connections: %-4lu  pending writes: %lu\n", --active_connections, pending_responses);
 }

 void http_stream_on_read(uv_stream_t* tcp, ssize_t nread, uv_buf_t buf)
@@ -141,12 +146,14 @@ int http_server_write_response(http_parser *parser, char *response)
     write_req->data = parser->data;

     r = uv_write(write_req, (uv_stream_t*)&context->stream, resbuf, 1, http_server_after_write);
+    pending_responses++;

     return 0;
 }

 void http_server_after_write(uv_write_t* req, int status)
 {
+    pending_responses--;
     //uv_close((uv_handle_t*)req->handle, http_stream_on_close);
     free(req);

With the debug statements, I ran the tests numerous times and in different orders. After waiting for both counters to reach 0, I was consistently able to get clean valgrind results. I hope you will be able to see similar results.

@nmdguerreiro
Copy link
Contributor

@kellabyte @jbcrail is this still happening with master?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers
No reviews
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.
3 participants
@jbcrail @kellabyte @nmdguerreiro
0