http://bugs.winehq.org/show_bug.cgi?id=30849
--- Comment #17 from voltara@gmail.com 2012-06-05 22:18:41 CDT --- Created attachment 40404 --> http://bugs.winehq.org/attachment.cgi?id=40404 Graph of wineserver and Diablo III cpu usage over time
I was able to reproduce the issue without even entering a game. All I did was start up Diablo III and log into battle.net, and waited until the server disconnected me.
Here's an annotated excerpt of the battle.net connection. Time is measured from the first SYN sent by the client. I omitted the login handshake chatter for clarity (the chatter around 7.5 seconds into the stream.) I also omitted acknowledgement packets.
At 64 seconds into the stream, the server sends a packet which has the following effects: a) "wineserver.exe" and "Diablo III.exe" collectively max out CPU usage (according to strace, wineserver is in an endless loop, repeatedly making the same sequence of system calls.) b) The game client does NOT send a response.
Annotated packet capture (tshark):
# t=24: server packet + client response 195 24.060708 12.130.244.193 -> 192.168.1.121 TCP 1119 > 37620 [PSH, ACK] Seq=12608 Ack=5525 Win=26944 Len=186 197 24.065767 192.168.1.121 -> 12.130.244.193 TCP 37620 > 1119 [PSH, ACK] Seq=5525 Ack=12794 Win=58400 Len=218
# t=44: server packet + client response 200 44.183155 12.130.244.193 -> 192.168.1.121 TCP 1119 > 37620 [PSH, ACK] Seq=12794 Ack=5743 Win=28628 Len=186 201 44.188558 192.168.1.121 -> 12.130.244.193 TCP 37620 > 1119 [PSH, ACK] Seq=5743 Ack=12980 Win=61320 Len=266
# t=64: server packet + NO RESPONSE 203 64.309408 12.130.244.193 -> 192.168.1.121 TCP 1119 > 37620 [PSH, ACK] Seq=12980 Ack=6009 Win=30312 Len=186
# t=164: server packet + NO RESPONSE 205 164.301667 12.130.244.193 -> 192.168.1.121 TCP 1119 > 37620 [PSH, ACK] Seq=13166 Ack=6009 Win=30312 Len=74
# t=194: disconnect 207 194.320058 12.130.244.193 -> 192.168.1.121 TCP 1119 > 37620 [FIN, ACK] Seq=13240 Ack=6009 Win=30312 Len=0 208 194.320251 192.168.1.121 -> 12.130.244.193 TCP 37620 > 1119 [FIN, ACK] Seq=6009 Ack=13241 Win=62780 Len=0
What wineserver is doing repeatedly (strace):
17551 1338948483.817603 epoll_wait(10, {{EPOLLIN, {u32=250, u64=250}}}, 128, 2) = 1 <0.000004> 17551 1338948483.817621 gettimeofday({1338948483, 817625}, NULL) = 0 <0.000005> 17551 1338948483.817638 read(22, "X\0\0\0\0\0\0\0\10\0\0\0\377\377\377\377\266\354\261\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 64) = 64 <0.000005> 17551 1338948483.817660 ptrace(PTRACE_ATTACH, 17948, 0, 0) = 0 <0.000006> 17551 1338948483.817679 --- SIGCHLD (Child exited) @ 0 (0) --- 17551 1338948483.817687 write(16, "\0", 1) = 1 <0.000005> 17551 1338948483.817704 sigreturn() = 0 <0.000005> 17551 1338948483.817720 alarm(3) = 0 <0.000005> 17551 1338948483.817736 wait4(17948, [{WIFSTOPPED(s) && WSTOPSIG(s) == SIGSTOP}], WSTOPPED|__WALL, NULL) = 17948 <0.000005> 17551 1338948483.817753 alarm(0) = 3 <0.000004> 17551 1338948483.817770 ptrace(PTRACE_PEEKDATA, 17948, 0xb1ecb4, [0x8bf377055e8ce8b]) = 0 <0.000005> 17551 1338948483.817788 ptrace(PTRACE_PEEKDATA, 17948, 0xb1ecb8, [0x8bf377039ffffe2]) = 0 <0.000005> 17551 1338948483.817806 ptrace(PTRACE_PEEKDATA, 17948, 0xb1ecbc, [0x8bf3770840fb05d]) = 0 <0.000005> 17551 1338948483.817824 ptrace(PTRACE_DETACH, 17948, 0x1, SIG_0) = 0 <0.000006> 17551 1338948483.817843 writev(27, [{"\0\0\0\0\10\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 64}, {"\350U\342\377\3779]\260", 8}], 2) = 72 <0.000006>
# Next iteration, just like the previous one: 17551 1338948483.817872 epoll_wait(10, {{EPOLLIN, {u32=250, u64=250}}, {EPOLLIN, {u32=4, u64=4}}}, 128, 1) = 2 <0.000005> 17551 1338948483.817893 gettimeofday({1338948483, 817897}, NULL) = 0 <0.000004> 17551 1338948483.817909 read(22, "X\0\0\0\0\0\0\0\10\0\0\0\377\377\377\377\266\354\261\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 64) = 64 <0.000005> ... # etc