Skip to content
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.

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

[Bug]: crash on opening Multiplayer #9730

Closed
TrueBrain opened this issue Dec 4, 2021 · 5 comments · Fixed by #9731
Closed

[Bug]: crash on opening Multiplayer #9730

TrueBrain opened this issue Dec 4, 2021 · 5 comments · Fixed by #9731

Comments

@TrueBrain
Copy link
Member

TrueBrain commented Dec 4, 2021 •
edited

Version of OpenTTD

12.1, FreeBSD

Expected result

No crash

Actual result

As reported in #9728 by @RealDeuce.

Thread 7 received signal SIGBUS, Bus error.
Address not present.
[Switching to LWP 100805 of process 32847]
0x0000000000bb44b4 in NetworkTCPSocketHandler::CanSendReceive (this=0x807fcc488) at /usr/ports/games/openttd/work/openttd-12.1/src/network/core/tcp.cpp:226
226		FD_SET(this->sock, &read_fd);
(gdb) print this->sock
$1 = -1
(gdb) bt
#0  0x0000000000bb44b4 in NetworkTCPSocketHandler::CanSendReceive (this=0x807fcc488)
    at /usr/ports/games/openttd/work/openttd-12.1/src/network/core/tcp.cpp:226
#1  0x0000000000c318a6 in QueryNetworkGameSocketHandler::Receive (this=0x807fcc480)
    at /usr/ports/games/openttd/work/openttd-12.1/src/network/network_query.cpp:53
#2  0x0000000000c31ca1 in QueryNetworkGameSocketHandler::SendReceive ()
    at /usr/ports/games/openttd/work/openttd-12.1/src/network/network_query.cpp:147
#3  0x0000000000bd3f61 in NetworkBackgroundLoop ()
    at /usr/ports/games/openttd/work/openttd-12.1/src/network/network.cpp:1027
#4  0x000000000104e9d9 in GameLoop () at /usr/ports/games/openttd/work/openttd-12.1/src/openttd.cpp:1454
#5  0x0000000000da9d5e in VideoDriver::GameLoop (this=0x803694c00)
    at /usr/ports/games/openttd/work/openttd-12.1/src/video/video_driver.cpp:37
#6  0x0000000000da9dcb in VideoDriver::GameThread (this=0x803694c00)
    at /usr/ports/games/openttd/work/openttd-12.1/src/video/video_driver.cpp:44
#7  0x0000000000da9f05 in VideoDriver::GameThreadThunk (drv=0x803694c00)
    at /usr/ports/games/openttd/work/openttd-12.1/src/video/video_driver.cpp:81
#8  0x0000000000daba14 in StartNewThread<void (*)(VideoDriver*), VideoDriver*>(std::__1::thread*, char const*, void (*&&)(VideoDriver*), VideoDriver*&&)::{lambda(char const*, void (*&&)(VideoDriver*), VideoDriver*&&)#1}::operator()(char const*, void (*&&)(VideoDriver*), VideoDriver*&&) const (this=0x82ac66fa0, name=0x5e2bcd "ottd:game", 
    F=@0x82ac66fb0: 0xda9ef0 <VideoDriver::GameThreadThunk(VideoDriver*)>, A=@0x82ac66fb8: 0x803694c00)
    at /usr/ports/games/openttd/work/openttd-12.1/src/video/../thread.h:65
#9  0x0000000000dab8cf in std::__1::__invoke<StartNewThread<void (*)(VideoDriver*), VideoDriver*>(std::__1::thread*, char const*, void (*&&)(VideoDriver*), VideoDriver*&&)::{lambda(char const*, void (*&&)(VideoDriver*), VideoDriver*&&)#1}, char const*, void (*)(VideoDriver*), VideoDriver*> (__f=..., __args=@0x82ac66fb8: 0x803694c00, 
    __args=@0x82ac66fb8: 0x803694c00, __args=@0x82ac66fb8: 0x803694c00) at /usr/include/c++/v1/type_traits:3539
#10 0x0000000000dab830 in std::__1::__thread_execute<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct> >, StartNewThread<void (*)(VideoDriver*), VideoDriver*>(std::__1::thread*, char const*, void (*&&)(VideoDriver*), VideoDriver*&&)::{lambda(char const*, void (*&&)(VideoDriver*), VideoDriver*&&)#1}, char const*, void (*)(VideoDriver*), VideoDriver*, 2ul, 3ul, 4ul>(std::__1::tuple<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct> >, StartNewThread<void (*)(VideoDriver*), VideoDriver*>(std::__1::thread*, char const*, void (*&&)(VideoDriver*), VideoDriver*&&)::{lambda(char const*, void (*&&)(VideoDriver*), VideoDriver*&&)#1}, char const*, void (*)(VideoDriver*), VideoDriver*>&, std::__1::__tuple_indices<2ul, 3ul, 4ul>)
    (__t=...) at /usr/include/c++/v1/thread:273
#11 0x0000000000dab486 in std::__1::__thread_proxy<std::__1::tuple<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct> >, StartNewThread<void (*)(VideoDriver*), VideoDriver*>(std::__1::thread*, char const*, void (*&&)(VideoDriver*), VideoDriver*&&)::{lambda(char const*, void (*&&)(VideoDriver*), VideoDriver*&&)#1}, char const*, void (*)(VideoDriver*), VideoDriver*> >(void*) (__vp=0x82ac66fa0)
    at /usr/include/c++/v1/thread:284
#12 0x0000000801cbcfac in ?? () from /lib/libthr.so.3
#13 0x0000000000000000 in ?? ()
Backtrace stopped: Cannot access memory at address 0x7fffdf5f9000

With -dnet=6:

openttd -dnet=6
dbg: [net] Starting network
dbg: [net] Initializing UDP listeners
dbg: [net] Network online, multiplayer available
dbg: [net] Detected broadcast addresses:
dbg: [net]   0) 192.168.0.255
fluidsynth: error: fluid_is_soundfont(): fopen() failed: 'File does not exist.'
fluidsynth: error: fluid_is_soundfont(): fopen() failed: 'File does not exist.'
fluidsynth: error: fluid_is_soundfont(): fopen() failed: 'File does not exist.'
fluidsynth: error: fluid_is_soundfont(): fopen() failed: 'File does not exist.'
fluidsynth: error: fluid_is_soundfont(): fopen() failed: 'File does not exist.'
fluidsynth: error: fluid_is_soundfont(): fopen() failed: 'File does not exist.'
fluidsynth: error: fluid_is_soundfont(): fopen() failed: 'File does not exist.'
dbg: [net] 44.135.218.201:3979 resolved in:
dbg: [net] - 44.135.218.201:3979 (IPv4)
dbg: [net] Attempting to connect to 44.135.218.201:3979 (IPv4)
dbg: [net] dragon.rrx.ca:3979 resolved in:
dbg: [net] - [2602:80b:7007::65]:3979 (IPv6)
dbg: [net] - 44.31.37.65:3979 (IPv4)
dbg: [net] Attempting to connect to [2602:80b:7007::65]:3979 (IPv6)
dbg: [net] Attempting to connect to 44.31.37.65:3979 (IPv4)
dbg: [net] Could not connect to [2602:80b:7007::65]:3979 (IPv6): Connection refused
dbg: [net] Connected to dragon.rrx.ca:3979
dbg: [net] Failed to get address of the peer: Bad file descriptor
dbg: [net] - using [::]:0 (IPv6)
dbg: [net] Timeout while connecting to 44.135.218.201:3979
dbg: [net] Closed UDP listeners
dbg: [net] Initializing UDP listeners
dbg: [net] Closed UDP listeners
dbg: [net] Shutting down network

Steps to reproduce

  • Start game
  • Open multiplayer
@TrueBrain TrueBrain mentioned this issue Dec 4, 2021
Closed
@TrueBrain
Copy link
Member Author

Okay, seems we have some logic errors in tcp_connect.cpp. Early observations:

OpenTTD/src/network/core/tcp_connect.cpp

Line 370 in 802ca4e

Debug(net, 1, "Could not connect to {}: {}", this->sock_to_address[*it].GetAddressAsString(), socket_error.AsString());

prints the IPv6 "connection refused" error. Next

OpenTTD/src/network/core/tcp_connect.cpp

Line 403 in 802ca4e

Debug(net, 3, "Connected to {}", this->connection_string);

is called, despite not having an actual connection yet. Lastly,

OpenTTD/src/network/core/tcp_connect.cpp

Line 405 in 802ca4e

Debug(net, 5, "- using {}", NetworkAddress::GetPeerName(connected_socket));

gives the "bad file desecriptor", indicating we are calling OnConnect with an INVALID_SOCKET. This should never happen. As this is a release build (12.1), the assert doesn't trigger, as they are disabled.

@TrueBrain TrueBrain changed the title [Bug]: [FreeBSD] crash on opening Multiplayer [Bug]: crash on opening Multiplayer Dec 4, 2021
@TrueBrain
Copy link
Member Author

A quick fix seems to be to open up ~/.config/openttd/private.cfg and remove dragon.rrx.ca:3979 = under [servers]. That should get you going again. Doesn't actually fix the problem ofc :)

@RealDeuce
Copy link

I already have a quick fix that has gotten me up and running again without needing to remove the server I usually play on, thanks.

Anyway, with your PR (and a debug build) it asserts, though not in a new assert.

(gdb) r -dnet=6
Starting program: /usr/home/admin/src/OpenTTD/build/openttd -dnet=6
dbg: [net] Starting network
dbg: [net] Initializing UDP listeners
dbg: [net] Network online, multiplayer available
dbg: [net] Detected broadcast addresses:
dbg: [net]   0) 192.168.0.255
[New LWP 101803 of process 50300]
fluidsynth: error: fluid_is_soundfont(): fopen() failed: 'File does not exist.'
fluidsynth: error: fluid_is_soundfont(): fopen() failed: 'File does not exist.'
fluidsynth: error: fluid_is_soundfont(): fopen() failed: 'File does not exist.'
fluidsynth: error: fluid_is_soundfont(): fopen() failed: 'File does not exist.'
fluidsynth: error: fluid_is_soundfont(): fopen() failed: 'File does not exist.'
fluidsynth: error: fluid_is_soundfont(): fopen() failed: 'File does not exist.'
fluidsynth: error: fluid_is_soundfont(): fopen() failed: 'File does not exist.'
[New LWP 102289 of process 50300]
[New LWP 102290 of process 50300]
[New LWP 102291 of process 50300]
dbg: [net] 44.135.218.201:3979 resolved in:
dbg: [net] - 44.135.218.201:3979 (IPv4)
[LWP 102291 of process 50300 exited]
dbg: [net] dragon.rrx.ca:3979 resolved in:
dbg: [net] - [2602:80b:7007::65]:3979 (IPv6)
dbg: [net] - 44.31.37.65:3979 (IPv4)
[LWP 102290 of process 50300 exited]
dbg: [net] Attempting to connect to [2602:80b:7007::65]:3979 (IPv6)
dbg: [net] Attempting to connect to 44.135.218.201:3979 (IPv4)
dbg: [net] Attempting to connect to 44.31.37.65:3979 (IPv4)
dbg: [net] Could not connect to [2602:80b:7007::65]:3979 (IPv6): Connection refused
Assertion failed: (connected_socket != INVALID_SOCKET), function CheckActivity, file /home/admin/src/OpenTTD/src/network/core/tcp_connect.cpp, line 401.

Thread 3 received signal SIGABRT, Aborted.
Sent by thr_kill() from pid 50300 and user 1000.
[Switching to LWP 102289 of process 50300]
0x0000000802044c2a in thr_kill () from /lib/libc.so.7
(gdb) bt
#0  0x0000000802044c2a in thr_kill () from /lib/libc.so.7
#1  0x0000000802043084 in raise () from /lib/libc.so.7
#2  0x0000000801fb9279 in abort () from /lib/libc.so.7
#3  0x0000000802033291 in __assert () from /lib/libc.so.7
#4  0x0000000000bdf025 in TCPConnecter::CheckActivity (this=0x806107080)
    at /home/admin/src/OpenTTD/src/network/core/tcp_connect.cpp:401
#5  0x0000000000bdf453 in TCPServerConnecter::CheckActivity (this=0x806107080)
    at /home/admin/src/OpenTTD/src/network/core/tcp_connect.cpp:423
#6  0x0000000000bdf624 in TCPConnecter::CheckCallbacks ()
    at /home/admin/src/OpenTTD/src/network/core/tcp_connect.cpp:479
#7  0x0000000000bf96f7 in NetworkBackgroundLoop () at /home/admin/src/OpenTTD/src/network/network.cpp:1025
#8  0x00000000010a3c99 in GameLoop () at /home/admin/src/OpenTTD/src/openttd.cpp:1454
#9  0x0000000000de965e in VideoDriver::GameLoop (this=0x80318cc00)
    at /home/admin/src/OpenTTD/src/video/video_driver.cpp:37
#10 0x0000000000de96cb in VideoDriver::GameThread (this=0x80318cc00)
    at /home/admin/src/OpenTTD/src/video/video_driver.cpp:44
#11 0x0000000000de9805 in VideoDriver::GameThreadThunk (drv=0x80318cc00)
    at /home/admin/src/OpenTTD/src/video/video_driver.cpp:81
#12 0x0000000000deb314 in StartNewThread<void (*)(VideoDriver*), VideoDriver*>(std::__1::thread*, char const*, void (*&&)(VideoDriver*), VideoDriver*&&)::{lambda(char const*, void (*&&)(VideoDriver*), VideoDriver*&&)#1}::operator()(char const*, void (*&&)(VideoDriver*), VideoDriver*&&) const (this=0x82acd1b40, name=0x5e6954 "ottd:game", 
    F=@0x82acd1b50: 0xde97f0 <VideoDriver::GameThreadThunk(VideoDriver*)>, A=@0x82acd1b58: 0x80318cc00)
    at /home/admin/src/OpenTTD/src/video/../thread.h:65
#13 0x0000000000deb1cf in std::__1::__invoke<StartNewThread<void (*)(VideoDriver*), VideoDriver*>(std::__1::thread*, char const*, void (*&&)(VideoDriver*), VideoDriver*&&)::{lambda(char const*, void (*&&)(VideoDriver*), VideoDriver*&&)#1}, char const*, void (*)(VideoDriver*), VideoDriver*> (__f=..., __args=@0x82acd1b58: 0x80318cc00, 
    __args=@0x82acd1b58: 0x80318cc00, __args=@0x82acd1b58: 0x80318cc00) at /usr/include/c++/v1/type_traits:3539
#14 0x0000000000deb130 in std::__1::__thread_execute<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct> >, StartNewThread<void (*)(VideoDriver*), VideoDriver*>(std::__1::thread*, char const*, void (*&&)(VideoDriver*), VideoDriver*&&)::{lambda(char const*, void (*&&)(VideoDriver*), VideoDriver*&&)#1}, char const*, void (*)(VideoDriver*), VideoDriver*, 2ul, 3ul, 4ul>(std::__1::tuple<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct> >, StartNewThread<void (*)(VideoDriver*), VideoDriver*>(std::__1::thread*, char const*, void (*&&)(VideoDriver*), VideoDriver*&&)::{lambda(char const*, void (*&&)(VideoDriver*), VideoDriver*&&)#1}, char const*, void (*)(VideoDriver*), VideoDriver*>&, std::__1::__tuple_indices<2ul, 3ul, 4ul>)
    (__t=...) at /usr/include/c++/v1/thread:273
#15 0x0000000000dead86 in std::__1::__thread_proxy<std::__1::tuple<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct> >, StartNewThread<void (*)(VideoDriver*), VideoDriver*>(std::__1::thread*, char const*, void (*&&)(VideoDriver*), VideoDriver*&&)::{lambda(char const*, void (*&&)(VideoDriver*), VideoDriver*&&)#1}, char const*, void (*)(VideoDriver*), VideoDriver*> >(void*) (__vp=0x82acd1b40)
    at /usr/include/c++/v1/thread:284
#16 0x0000000801d34fac in ?? () from /lib/libthr.so.3
#17 0x0000000000000000 in ?? ()
Backtrace stopped: Cannot access memory at address 0x7fffdfdfd000
(gdb) up 4
#4  0x0000000000bdf025 in TCPConnecter::CheckActivity (this=0x806107080)
    at /home/admin/src/OpenTTD/src/network/core/tcp_connect.cpp:401
401		assert(connected_socket != INVALID_SOCKET);

It seems likely that this is related to my configured servers. I have two configured, the first one is a hostname which has both an IPv4 and IPv6 address and the second is an IPv4 address literal. Neither server is running when the crash occurs.

Anyway, I'm not especially interested in engaging with this issue. I have a workaround that fixes my problem, and I'm satisfied with it. If you have any questions regarding reproducing it, I'm happy to answer, but I'm not likely to try various patches and report if it worked or not, nor am I going to debug the issue any further on my own.

One thing I noticed in passing is that there's a comment before the assert that is hit that "At this point, there is at least one socket connected" or something along those lines. This is clearly false.

@TrueBrain
Copy link
Member Author

Tnx for the backtrace, that confirms what I am suspecting ..

Basically, it is a matter of poor timing of the network stack. IPv6 takes more than 250ms to realise it cannot connect. By that time an IPv4 connection is attempted, but before that is connected, the IPv6 reports it failed to connect. That in result causes our code to get confused, and use an invalid socket. Now for a fix ... which is widely more difficult ...

@TrueBrain TrueBrain mentioned this issue Dec 4, 2021
Merged
@TrueBrain
Copy link
Member Author

Right, I think #9731 solves the problem, and even allows you to connect to your favorite server (I think you currently cannot, or at least, I suspect it often fails). If you feel like it, I surely could use the confirmation it resolves the issue for you too. If not, that is fine, I could somewhat reproduce the issue and it at least solves a problem for sure :D

TrueBrain added a commit that referenced this issue Dec 4, 2021
@TrueBrain
Fix #9730: [Network] connections can use an invalid socket due to a r…
ea4f6bb 
…ace condition

A race condition happens when an IPv6 connection takes more than
250ms to report an error, but does return before the IPv4 connection
is established.
In result, an invalid socket might be used for that connection.
TrueBrain added a commit to TrueBrain/OpenTTD that referenced this issue Jan 3, 2022
@TrueBrain
Fix OpenTTD#9730: [Network] connections can use an invalid socket due…
4cf1472 
… to a race condition

A race condition happens when an IPv6 connection takes more than
250ms to report an error, but does return before the IPv4 connection
is established.
In result, an invalid socket might be used for that connection.
TrueBrain added a commit that referenced this issue Jan 5, 2022
@TrueBrain
Fix #9730: [Network] connections can use an invalid socket due to a r…
97f545b 
…ace condition

A race condition happens when an IPv6 connection takes more than
250ms to report an error, but does return before the IPv4 connection
is established.
In result, an invalid socket might be used for that connection.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Fix: [Network] connections can use an invalid socket due to a race condition TrueBrain/OpenTTD
2 participants
@TrueBrain @RealDeuce