[Bug]: Errors and bad state when starting server on unavailable port

[digitalcora]

Describe the Bug

When attempting to start a server using a port number that is already in use, the app shows multiple errors and enters a strange "half-started" state that can only be fixed by restarting the app (as attempting to shut down the server gives another error).

To Reproduce

1. Select File > Start Server...
2. Enter a username and GM/Player passwords, leaving all options at their defaults
3. Enter a port number that is already in use on the system (on Windows, the "Local Address" column in the output of netstat -nq -p tcp can be used to find one)
4. Click OK

When I do this, I immediately get the following three error popups in succession:

Could not connect to server.
java.net.BindException: Address already in use: bind

You are already running a server.

Could not restart personal server.
java.net.ConnectException: Connection refused: connect

The map view then becomes solid black, and the app enters a state where it looks like it's connected to a server as "Anonymous User" instead of the name I entered in the Start Server dialog, and does not have GM privileges (most menu options are disabled). When I start a second instance of MapTool, a server appears in the LAN list as the username I entered (and in the RPTools.net list if I enter an alias), but trying to connect gives a "connection refused" error immediately.

When I choose File > Disconnect from Server..., I get a confirmation window saying I'm running a server and that this will disconnect all clients. If I confirm this, I get the following error popup:

java.lang.NullPointerException: Cannot invoke "net.rptools.clientserver.simple.server.SocketServer$ListeningThread.suppressErrors()" because "this.listeningThread" is null
  at net.rptools.clientserver.simple.server.SocketServer.close(SocketServer.java:51)
  at net.rptools.maptool.server.MapToolServerConnection.close(MapToolServerConnection.java:177)
  at net.rptools.maptool.server.MapToolServer.stop(MapToolServer.java:171)
  at net.rptools.maptool.client.MapTool.stopServer(MapTool.java:1081)
  at net.rptools.maptool.client.AppActions.disconnectFromServer(AppActions.java:2470)
  at net.rptools.maptool.client.AppActions$65.executeAction(AppActions.java:2456)
  at net.rptools.maptool.client.AppActions$ClientAction.execute(AppActions.java:3426)
  at net.rptools.maptool.client.AppActions$ClientAction.actionPerformed(AppActions.java:3458)
  at java.desktop/javax.swing.AbstractButton.fireActionPerformed(Unknown Source)
  at java.desktop/javax.swing.AbstractButton$Handler.actionPerformed(Unknown Source)
  at java.desktop/javax.swing.DefaultButtonModel.fireActionPerformed(Unknown Source)
  at java.desktop/javax.swing.DefaultButtonModel.setPressed(Unknown Source)
  at java.desktop/javax.swing.AbstractButton.doClick(Unknown Source)
  at java.desktop/javax.swing.plaf.basic.BasicMenuItemUI.doClick(Unknown Source)
  at java.desktop/javax.swing.plaf.basic.BasicMenuItemUI$Handler.mouseReleased(Unknown Source)
  at java.desktop/java.awt.AWTEventMulticaster.mouseReleased(Unknown Source)
  at java.desktop/java.awt.Component.processMouseEvent(Unknown Source)
  at java.desktop/javax.swing.JComponent.processMouseEvent(Unknown Source)
  at java.desktop/java.awt.Component.processEvent(Unknown Source)
  at java.desktop/java.awt.Container.processEvent(Unknown Source)
  at java.desktop/java.awt.Component.dispatchEventImpl(Unknown Source)
  at java.desktop/java.awt.Container.dispatchEventImpl(Unknown Source)
  at java.desktop/java.awt.Component.dispatchEvent(Unknown Source)
  at java.desktop/java.awt.LightweightDispatcher.retargetMouseEvent(Unknown Source)
  at java.desktop/java.awt.LightweightDispatcher.processMouseEvent(Unknown Source)
  at java.desktop/java.awt.LightweightDispatcher.dispatchEvent(Unknown Source)
  at java.desktop/java.awt.Container.dispatchEventImpl(Unknown Source)
  at java.desktop/java.awt.Window.dispatchEventImpl(Unknown Source)
  at java.desktop/java.awt.Component.dispatchEvent(Unknown Source)
  at java.desktop/java.awt.EventQueue.dispatchEventImpl(Unknown Source)
  at java.desktop/java.awt.EventQueue$4.run(Unknown Source)
  at java.desktop/java.awt.EventQueue$4.run(Unknown Source)
  at java.base/java.security.AccessController.doPrivileged(Unknown Source)
  at java.base/java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(Unknown Source)
  at java.base/java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(Unknown Source)
  at java.desktop/java.awt.EventQueue$5.run(Unknown Source)
  at java.desktop/java.awt.EventQueue$5.run(Unknown Source)
  at java.base/java.security.AccessController.doPrivileged(Unknown Source)
  at java.base/java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(Unknown Source)
  at java.desktop/java.awt.EventQueue.dispatchEvent(Unknown Source)
  at net.rptools.maptool.client.swing.MapToolEventQueue.dispatchEvent(MapToolEventQueue.java:54)
  at java.desktop/java.awt.EventDispatchThread.pumpOneEventForFilters(Unknown Source)
  at java.desktop/java.awt.EventDispatchThread.pumpEventsForFilter(Unknown Source)
  at java.desktop/java.awt.EventDispatchThread.pumpEventsForHierarchy(Unknown Source)
  at java.desktop/java.awt.EventDispatchThread.pumpEvents(Unknown Source)
  at java.desktop/java.awt.EventDispatchThread.pumpEvents(Unknown Source)
  at java.desktop/java.awt.EventDispatchThread.run(Unknown Source)

After this, the message "You have disconnected." appears in the chat pane, but the app still thinks I'm connected and the start/connect options are disabled; I can "Disconnect from Server" repeatedly and each time the above error comes up. The only way to escape this state is to close the app entirely.

Expected Behaviour

When trying to start a server on an unavailable port, the app should give an error message explaining this, and not proceed any further.

MapTool Info

1.13.2 (Windows, MSI, fresh install)

Desktop

Windows 10 version 22H2 (build 19045.3693)

Additional Context

Here is my "Gather Debug Information", with some data redacted:

==== MapTool Information ====
MapTool Version: 1.13.2
MapTool Home...: C:\Users\x\.maptool-rptools
MapTool Install: C:\Users\x\AppData\Local\MapTool\app
Max mem avail..: 3 GB
Max mem used...: 174 MB
Custom Property: -DMAPTOOL_LOGDIR=C:\Users\x\.maptool-rptools\logs
Custom Property: -DMAPTOOL_DATADIR=.maptool-rptools

==== Java Information ====
Java Home......: C:\Users\x\AppData\Local\MapTool\runtime
Java Vendor....: Eclipse Adoptium
Java Version...: 17.0.1
Java Parameters: 
  -Djpackage.app-version=1.0
  -Xss8M
  -Dsun.java2d.d3d=false
  -Dsentry.environment=Production
  -Dfile.encoding=UTF-8
  -Dpolyglot.engine.WarnInterpreterOnly=false
  -XX:+ShowCodeDetailsInExceptionMessages
  --add-opens=java.desktop/java.awt=ALL-UNNAMED
  --add-opens=java.desktop/java.awt.geom=ALL-UNNAMED
  --add-opens=java.desktop/sun.awt.geom=ALL-UNNAMED
  --add-opens=java.base/java.util=ALL-UNNAMED
  --add-opens=javafx.web/javafx.scene.web=ALL-UNNAMED
  --add-opens=javafx.web/com.sun.webkit=ALL-UNNAMED
  --add-opens=javafx.web/com.sun.webkit.dom=ALL-UNNAMED
  --add-opens=java.desktop/javax.swing=ALL-UNNAMED
  --add-opens=java.desktop/sun.awt.shell=ALL-UNNAMED
  --add-opens=java.desktop/com.sun.java.swing.plaf.windows=ALL-UNNAMED
  -Djpackage.app-path=C:\Users\x\AppData\Local\MapTool\MapTool.exe


==== OS Information ====
OS Name........: Windows 10
OS Version.....: 10.0
OS Architecture: amd64
Processor......: Intel64 Family 6 Model 158 Stepping 9, GenuineIntel
PATH...........: C:\Users\x\AppData\Local\MapTool;C:\WINDOWS\Sun\Java\bin;C:\WINDOWS\system32;C:\WINDOWS;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\WINDOWS\System32\WindowsPowerShell\v1.0\;C:\WINDOWS\System32\OpenSSH\;C:\Program Files\dotnet\;C:\Users\x\AppData\Local\Microsoft\WindowsApps;C:\Users\x\AppData\Local\Microsoft\WindowsApps;;C:\Users\x\AppData\Local\MapTool\app;.
Number of Procs: 4

==== User Information ====
User Name: x
User Home: C:\Users\x
User Dir.: C:\Users\x\AppData\Local\MapTool

==== Network Interfaces ====
Display Name..: Software Loopback Interface 1
Interface Name: lo
Address...: 127.0.0.1
Address...: 0:0:0:0:0:0:0:1

Display Name..: Qualcomm Atheros QCA61x4A Wireless Network Adapter
Interface Name: wlan3
Address...: 192.168.0.20

Host Address...: 192.168.0.20
Default Gateway: 192.168.0.1

==== Locale Information ====
Country.: United States
Language: English
Locale..: English (United States)
Variant.: 

==== Encoding Information ====
Default Locale:   en_US
Default Charset:  UTF-8
file.encoding:    UTF-8
sun.jnu.encoding: Cp1252
Default Encoding: UTF8

==== Display Information ====
Number of Displays: 1
Display 1: 1920x1200(32)

==== Internet Gateway Devices ====
  No IGDs Found!

[digitalcora]

On further experimentation (not sure why I didn't try this already), this problem only appears when certain port numbers are chosen for the server, including the default port number 51234 but also including e.g. 51235 and 51236. I'm not sure why, since according to netstat I do not have any applications listening on these ports. It's also not an issue with ephemeral port numbers in general, as 54321 works fine.

[emmebi]

Is it possible that some other application is using 51234 port as a the source port for a connection?

…

On Sun, Dec 3, 2023 at 8:24 PM Cora Grant ***@***.***> wrote: On further experimentation (not sure why I didn't try this already), this problem only appears when certain port numbers are chosen for the server, including the default port number 51234 but also including e.g. 51235 and 51236. I'm not sure why, since according to netstat I do not have any applications listening on these ports. It's also not an issue with ephemeral port numbers in general, as 54321 works fine. — Reply to this email directly, view it on GitHub <#4519 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AALWDPKL7W3L62VTRP53VMDYHTNY3AVCNFSM6AAAAABAFAOCKKVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTQMZXGU4DSOBWHE> . You are receiving this because you are subscribed to this thread.Message ID: ***@***.***>

-- Marco Bizzarri

[digitalcora]

Again using netstat, it doesn't look like anything is using 51234 as a source port, or any of the other ports I tried that resulted in errors. Of course, since these are ephemeral port numbers, it's technically possible that something is only using them when I'm not looking (but is consistently using them every time I try to start a MapTool server...?).

My current thoughts:

1. The default port number for MapTool servers maybe shouldn't be in the ephemeral range, given any application connecting to the network could be randomly occupying it at any time, preventing the server from starting for unclear reasons.

2. When this kind of error does happen, ideally it shouldn't leave the server in a glitched state that makes it unclear what went wrong and is not fixable without closing the application entirely.

3. Actual cause of the issue I'm personally having is still unclear, but the impact is very low, since I can switch to a working port number.

[kwvanderlinde]

Thought (2) is very important. It's too easy to accidentally reuse a port by accident - I've done it a lot - and we should be handle this case gracefully. And instead of three technical errors, there should be one clear and user-friendly message displayed.

For diagnosing your particular issue, can you share how you're using netstat? Just so we can all be on the same page (I know nothing about netstat on Windows, so maybe there are pitfalls in its usage 🤷). It could also be worth asking in the #networking support channel on our Discord server.

[digitalcora]

I've gone back to investigate this again today, but unfortunately can't reproduce it: starting a server on the default port 51234 works fine, under the same circumstances as before. The PC has been restarted at least once since the issue occurred, so my best guess is that maybe something was quietly but permanently "stuck" from a previous attempt to start a server, and a full restart cleared it. I'm not sure how this could have happened without the open socket appearing in netstat, but that's all I've got at the moment. If I ever get this issue to appear again, I'll try to debug it more thoroughly.

For future reference, netstat -nq -p tcp shows all bound TCP sockets on the system. -n skips trying to resolve IP addresses to domain names (takes a while and not useful here). Adding -o shows the owning PID which can be looked up in Task Manager.

Setting aside my elusive issue with the default port number for now, I think I'd like to either close this issue and open a new one focused on the "glitch state" and errors from trying to start a server on an already-used port, or rewrite this issue's title/OP to be about that instead. Which would be preferred? I'm leaning towards the first one (new issue).

[kwvanderlinde]

Since the bulk of the OP applies regardless, let's just keep using this bug report to track it.

[digitalcora]

I've updated the issue title and OP. Hopefully the conversation is not too confusing for anyone coming here in the future.

[digitalcora]

Possibly related to #3790.