Skip to content
This repository has been archived by the owner on May 4, 2018. It is now read-only.

multi-accept benchmarks fail on Windows #1302

Open
kellabyte opened this issue May 29, 2014 · 1 comment
Open

multi-accept benchmarks fail on Windows #1302

kellabyte opened this issue May 29, 2014 · 1 comment

Comments

@kellabyte
Copy link

I've been debugging why my multi-accept inspired code in my own code base was failing on Windows but working on Linux and OSX. I decided to run the libuv benchmarks to see if the implementations in libuv were working on Windows and I found some issues.

There may be a race condition for when server_handle is initialized between these sequence of calls:

test_tcp() (new thread) -> server_cb() -> get_listen_handle() -> ipc_connect_cb() -> ipc_read_cb() -> server_handle is initialized

test_tcp() (new thread) -> server_cb() ->  uv_listen(server_handle)

https://github.com/joyent/libuv/blob/master/test/benchmark-multi-accept.c#L188
https://github.com/joyent/libuv/blob/master/test/benchmark-multi-accept.c#L269

uv_shutdown_t: 96 bytes
uv_write_t: 144 bytes
uv_connect_t: 96 bytes
uv_udp_send_t: 96 bytes
uv_tcp_t: 256 bytes
uv_pipe_t: 440 bytes
uv_tty_t: 280 bytes
uv_prepare_t: 88 bytes
uv_check_t: 88 bytes
uv_idle_t: 88 bytes
uv_async_t: 160 bytes
uv_timer_t: 128 bytes
uv_fs_poll_t: 72 bytes
uv_fs_event_t: 208 bytes
uv_process_t: 200 bytes
uv_poll_t: 320 bytes
uv_loop_t: 192 bytes
loop_count: 2000000 ticks in 1.26s (1584149/s)
loop_count: 8234660 ticks (1646932 ticks/s)
ping_pongs: 46039 roundtrips/s
1000000 write requests in 5.12s.
tcp_pump100_server: 3.7 gbit/s
tcp_pump100_client: 3.7 gbit/s
tcp_pump1_server: 3.6 gbit/s
tcp_pump1_client: 3.6 gbit/s
tcp-conn-pound-100: 13891 accepts/s (0 failed)
tcp-conn-pound-1000: 12243 accepts/s (0 failed)

`pipe_pump100_client` failed: exit code 3
Output from process `pipe_pump_server`:
Assertion failed in test\benchmark-pump.c on lOutput from process `pipe_pump100_client`:
unknown errorAssertion failed in test\benchmark-pump.c on line 217: status == 0
=============================================================
pipe_pump1_server: 11.1 gbit/s
pipe_pump1_client: 11.1 gbit/s
pipe-conn-pound-100: 99712 accepts/s (481968 failed)
pipe-conn-pound-1000: 101400 accepts/s (518680 failed)

`tcp_multi_accept2` failed: exit code 3
Output from process `tcp_multi_accept2`:
Assertion failed in test\benchmark-multi-accept.c on line 126: 0 == uv_accept(ipc_pipe, (uv_stream_t*) &pc->peer_handle)
=============================================================

`tcp_multi_accept4` failed: exit code 3
Output from process `tcp_multi_accept4`:
Assertion failed in test\benchmark-multi-accept.c on line 126: 0 == uv_accept(ipc_pipe, (uv_stream_t*) &pc->peer_handle)
=============================================================

`tcp_multi_accept8` failed: exit code 3
Output from process `tcp_multi_accept8`:
Assertion failed in test\benchmark-multi-accept.c on line 126: 0 == uv_accept(ipc_pipe, (uv_stream_t*) &pc->peer_handle)
Asserti=============================================================
udp_pummel_1v1: 122100/s received, 122100/s sent. 999997 received, 1000000 sent in 8.2 seconds.
udp_pummel_10v1: 120091/s received, 120091/s sent. 999997 received, 1000000 sent in 8.3 seconds.
udp_pummel_100v1: 119904/s received, 119904/s sent. 999998 received, 1000000 sent in 8.3 seconds.
udp_pummel_1000v1: 118315/s received, 118315/s sent. 999997 received, 1000000 sent in 8.5 seconds.
udp_pummel_10v10: 156764/s received, 156764/s sent. 1000000 received, 1000000 sent in 6.4 seconds.
udp_pummel_100v10: 159719/s received, 159719/s sent. 1000000 received, 1000000 sent in 6.3 seconds.
udp_pummel_1000v10: 158403/s received, 158403/s sent. 1000000 received, 1000000 sent in 6.3 seconds.
udp_pummel_100v100: 154154/s received, 154154/s sent. 1000000 received, 1000000 sent in 6.5 seconds.
udp_pummel_1000v100: 160282/s received, 160282/s sent. 1000000 received, 1000000 sent in 6.2 seconds.
udp_pummel_1000v1000: 128741/s received, 129182/s sent. 996584 received, 1000000 sent in 7.7 seconds.
udp_pummel_1v1: 119722/s received, 119723/s sent. 598130 received, 598135 sent in 5.0 seconds.
udp_pummel_10v1: 121638/s received, 121639/s sent. 608798 received, 608801 sent in 5.0 seconds.
udp_pummel_100v1: 119630/s received, 119631/s sent. 598391 received, 598395 sent in 5.0 seconds.
udp_pummel_1000v1: 119020/s received, 119021/s sent. 592365 received, 592369 sent in 5.0 seconds.
udp_pummel_10v10: 160516/s received, 160518/s sent. 802580 received, 802590 sent in 5.0 seconds.
udp_pummel_100v10: 160724/s received, 160726/s sent. 803780 received, 803790 sent in 5.0 seconds.
udp_pummel_1000v10: 157928/s received, 157930/s sent. 785690 received, 785700 sent in 5.0 seconds.
udp_pummel_100v100: 164163/s received, 164183/s sent. 819500 received, 819600 sent in 5.0 seconds.
udp_pummel_1000v100: 161384/s received, 161404/s sent. 802400 received, 802500 sent in 5.0 seconds.
udp_pummel_1000v1000: 126536/s received, 127431/s sent. 624584 received, 629000 sent in 4.9 seconds.
getaddrinfo: 17794 req/s

`fs_stat` failed: timeout
Output from process `fs_stat`:
1,000,000 stats (sync): 20.13s (49,672/s)
100,000 stats (1 concurrent): 3.04s (32,917/s)
100,000 stats (2 concurrent): 1.71s (58,573/s)
100,000 stats (3 concurrent): 1.32s (75,493/s)
100,000 stats (4 concurrent): 1.26s (79,329/s)
100,000 stats (5 concurrent): 1.29s (77,672/s)
100,000 stats (6 concurrent): 1.27s (79,031/s)
100,000 stats (7 concurrent): 1.27s (79,018/s)
100,000 stats (8 concurrent): 1.27s (78,794/s)
100,000 stats (9 concurrent): 1.27s (78,540/s)
100,000 stats (10 concurrent): 1.26s (79,191/s)
100,000 stats (11 concurrent): 1.26s (79,490/s)
100,000 stats (12 concurrent): 1.25s (79,745/s)
100,000 stats (13 concurrent): 1.25s (79,728/s)
100,000 stats (14 concurrent): 1.25s (79,801/s)
100,000 stats (15 concurrent): 1.26s (79,615/s)
100,000 stats (16 concurrent): 1.25s (79,843/s)
100,000 stats (17 concurrent): 1.25s (79,966/s)
100,000 stats (18 concurrent): 1.25s (80,031/s)
100,000 stats (19 concurrent): 1.26s (79,071/s)
<buffer too small> stats (20 concurrent): 1.24s (80,428/s)
<buffer too small> stats (21 concurrent): 1.24s (<buffer too small>/s)
<buffer too small> stats (22 concurrent): 1.24s (<buffer too small>/s)
<buffer too small> stats (23 concurrent): 1.25s (<buffer too small>/s)
<buffer too small> stats (24 concurrent): 1.25s (<buffer too small>/s)
<buffer too small> stats (25 concurrent): 1.24s (<buffer too small>/s)
<buffer too small> stats (26 concurrent): 1.25s (<buffer too small>/s)
<buffer too small> stats (27 concurrent): 1.25s (<buffer too small>/s)
<buffer too small> stats (28 concurrent): 1.24s (<buffer too small>/s)
<buffer too small> stats (29 concurrent): 1.24s (<buffer too small>/s)
=============================================================

`async1` failed: exit code 3
Output from process `async1`:
A s s e r t i o n   f a i l e d :   ! ( h a n d l e - > f l a g s   &   U V _ _ H A N D L E _ C L O S I N G ) ,   f i l e   s r c
\ w i n \ a s y n c . c ,   l i n e   7 7
 =============================================================

`async2` failed: exit code 3
Output from process `async2`:
A s s e r t i o n   f a i l e d :   ! ( h a n d l e - > f l a g s   &   U V _ _ H A N D L E _ C L O S I N G ) ,   f i l e   s r c
\ w i n \ a s y n c . c ,   l i n e   7 7
 =============================================================

`async4` failed: exit code 3
Output from process `async4`:
A s s e r t i o n   f a i l e d :   ! ( h a n d l e - > f l a g s   &   U V _ _ H A N D L E _ C L O S I N G ) ,   f i l e   s r c
\ w i n \ a s y n c . c ,   l i n e   7 7
 =============================================================

`async8` failed: exit code 3
Output from process `async8`:
A s s e r t i o n   f a i l e d :   ! ( h a n d l e - > f l a g s   &   U V _ _ H A N D L E _ C L O S I N G ) ,   f i l e   s r c
\ w i n \ a s y n c . c ,   l i n e   7 7
 A s s e r t i =============================================================
async_pummel_1: 1,000,000 callbacks in 0.91 seconds (1,104,847/sec)
async_pummel_2: 1,000,000 callbacks in 1.06 seconds (945,629/sec)
async_pummel_4: 1,000,000 callbacks in 1.15 seconds (867,877/sec)

`async_pummel_8` failed: timeout
Output from process `async_pummel_8`: (no output)
=============================================================

`spawn` failed: timeout
Output from process `spawn`: (no output)
=============================================================

`thread_create` failed: timeout
Output from process `thread_create`: (no output)
=============================================================
3,962,526 async events in 5.0 seconds (792,505/s, 1,048,576 unique handles seen)
30.00 seconds total
21.95 seconds init
6.53 seconds dispatch
1.53 seconds cleanup
@kellabyte
Copy link
Author

I'm not so sure if the race condition I identified above is actually the problem after some testing today, so don't take that as gospel.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant