software-challenge / backend

Server, Client und Spiel-Plugins der Software-Challenge Germany
https://www.software-challenge.de
12 stars 9 forks source link

Spiel startet nicht #406

Closed 0xhtml closed 3 years ago

0xhtml commented 3 years ago

Beim Starten eines Spiels zwischen dem Beispiel-Computerspielers und einem Menschen passiert nichts, außer dass "Das Spiel startet... Bitte verbinde manuell gestartete Clients auf localhost:13050" angezeigt wird.

Java:

openjdk version "16.0.2" 2021-07-20
OpenJDK Runtime Environment (build 16.0.2+7)
OpenJDK 64-Bit Server VM (build 16.0.2+7, mixed mode)

System:

5.14.3-arch1-1 x86_64 GNU/Linux

Logs:

21:17:04,535 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [/home/logback.xml]
21:17:04,536 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback-test.xml] at [jar:file:/home/.cache/socha/socha.jar!/logback-test.xml]
21:17:04,548 |-INFO in ch.qos.logback.core.joran.spi.ConfigurationWatchList@196debbd - URL [jar:file:/home/.cache/socha/socha.jar!/logback-test.xml] is not of type file
21:17:04,679 |-INFO in ch.qos.logback.core.joran.action.TimestampAction - Using current interpretation time, i.e. now, as time reference.
21:17:04,680 |-INFO in ch.qos.logback.core.joran.action.TimestampAction - Adding property to the context with key="time" and value="09-17T211704" to the LOCAL scope
21:17:04,680 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [sc.util.TidyFileAppender]
21:17:04,687 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE]
21:17:04,718 |-WARN in sc.util.TidyFileAppender[FILE] - This appender no longer admits a layout as a sub-component, set an encoder instead.
21:17:04,718 |-WARN in sc.util.TidyFileAppender[FILE] - To ensure compatibility, wrapping your layout in LayoutWrappingEncoder.
21:17:04,718 |-WARN in sc.util.TidyFileAppender[FILE] - See also http://logback.qos.ch/codes.html#layoutInsteadOfEncoder for details
21:17:04,718 |-INFO in sc.util.TidyFileAppender[FILE] - File property is set to [log/game-server_09-17T211704.log]
21:17:04,719 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
21:17:04,720 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]
21:17:04,721 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.PatternLayout] for [layout] property
21:17:04,722 |-WARN in ch.qos.logback.core.ConsoleAppender[STDOUT] - This appender no longer admits a layout as a sub-component, set an encoder instead.
21:17:04,722 |-WARN in ch.qos.logback.core.ConsoleAppender[STDOUT] - To ensure compatibility, wrapping your layout in LayoutWrappingEncoder.
21:17:04,722 |-WARN in ch.qos.logback.core.ConsoleAppender[STDOUT] - See also http://logback.qos.ch/codes.html#layoutInsteadOfEncoder for details
21:17:04,723 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [sc] to DEBUG
21:17:04,723 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [sc.networking.clients.XStreamClient] to INFO
21:17:04,723 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [sc.gui] to TRACE
21:17:04,723 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO
21:17:04,723 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [FILE] to Logger[ROOT]
21:17:04,723 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ROOT]
21:17:04,724 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
21:17:04,724 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@50cbde79 - Registering current configuration as safe fallback point
Sept. 17, 2021 9:17:04 PM tornadofx.Stylesheet$Companion detectAndInstallUrlHandler
INFORMATION: Installing CSS url handler, since it was not picked up automatically
21:17:04,535 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [/home/logback.xml]
21:17:04,536 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback-test.xml] at [jar:file:/home/.cache/socha/socha.jar!/logback-test.xml]
21:17:04,548 |-INFO in ch.qos.logback.core.joran.spi.ConfigurationWatchList@196debbd - URL [jar:file:/home/.cache/socha/socha.jar!/logback-test.xml] is not of type file
21:17:04,679 |-INFO in ch.qos.logback.core.joran.action.TimestampAction - Using current interpretation time, i.e. now, as time reference.
21:17:04,680 |-INFO in ch.qos.logback.core.joran.action.TimestampAction - Adding property to the context with key="time" and value="09-17T211704" to the LOCAL scope
21:17:04,680 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [sc.util.TidyFileAppender]
21:17:04,687 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE]
21:17:04,718 |-WARN in sc.util.TidyFileAppender[FILE] - This appender no longer admits a layout as a sub-component, set an encoder instead.
21:17:04,718 |-WARN in sc.util.TidyFileAppender[FILE] - To ensure compatibility, wrapping your layout in LayoutWrappingEncoder.
21:17:04,718 |-WARN in sc.util.TidyFileAppender[FILE] - See also http://logback.qos.ch/codes.html#layoutInsteadOfEncoder for details
21:17:04,718 |-INFO in sc.util.TidyFileAppender[FILE] - File property is set to [log/game-server_09-17T211704.log]
21:17:04,719 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
21:17:04,720 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]
21:17:04,721 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.PatternLayout] for [layout] property
21:17:04,722 |-WARN in ch.qos.logback.core.ConsoleAppender[STDOUT] - This appender no longer admits a layout as a sub-component, set an encoder instead.
21:17:04,722 |-WARN in ch.qos.logback.core.ConsoleAppender[STDOUT] - To ensure compatibility, wrapping your layout in LayoutWrappingEncoder.
21:17:04,722 |-WARN in ch.qos.logback.core.ConsoleAppender[STDOUT] - See also http://logback.qos.ch/codes.html#layoutInsteadOfEncoder for details
21:17:04,723 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [sc] to DEBUG
21:17:04,723 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [sc.networking.clients.XStreamClient] to INFO
21:17:04,723 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [sc.gui] to TRACE
21:17:04,723 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO
21:17:04,723 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [FILE] to Logger[ROOT]
21:17:04,723 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ROOT]
21:17:04,724 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
21:17:04,724 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@50cbde79 - Registering current configuration as safe fallback point

21:17:04 WARN               sc.server.Configuration - Could not find server.properties at /home/server.properties, will use default values!
21:17:04 INFO   sc.server.network.NewClientListener - Listening on port 13050 for incoming connections.
21:17:04 DEBUG             sc.server.ServiceManager - Spawning thread for new service (name=NewClientListener, daemon=true)
21:17:04 DEBUG             sc.server.ServiceManager - Spawning thread for new service (name=ClientManager, daemon=true)
21:17:04 INFO       sc.server.network.ClientManager - ClientManager running
21:17:07 DEBUG      sc.gui.controller.AppController - Requested View change from START -> GAME_CREATION
21:17:11 DEBUG      sc.gui.controller.AppController - Requested View change from GAME_CREATION -> GAME_LOADING
21:17:11 INFO   sc.networking.clients.XStreamClient - Creating TCP Network for localhost:13050
21:17:11 INFO   sc.server.network.NewClientListener - A Client connected...
21:17:11 INFO   sc.server.network.NewClientListener - Added Client Client@47124b1a to ReadyQueue.
21:17:11 INFO       sc.server.network.ClientManager - Delegating new client to ClientManager...
21:17:11 INFO       sc.server.network.ClientManager - Delegation done
21:17:11 INFO   sc.networking.clients.XStreamClient - Creating TCP Network for localhost:13050
21:17:11 INFO   sc.server.network.NewClientListener - A Client connected...
Security framework of XStream not explicitly initialized, using predefined black list on your own risk.
21:17:11 INFO              sc.server.network.Client - Client authenticated as administrator
21:17:11 INFO   sc.networking.clients.XStreamClient - Creating TCP Network for localhost:13050
21:17:11 INFO   sc.server.network.NewClientListener - Added Client Client@251468fa to ReadyQueue.
21:17:11 INFO       sc.server.network.ClientManager - Delegating new client to ClientManager...
21:17:11 INFO       sc.server.network.ClientManager - Delegation done
21:17:11 INFO   sc.server.network.NewClientListener - A Client connected...
21:17:11 DEBUG                  sc.gui.LobbyManager - Starting new game (paused: false, players: [Player(name=Spieler 1, client=sc.gui.controller.client.GuiClient@2390520f type Beispiel-Computerspieler on localhost:13050), Player(name=Spieler 2, client=sc.gui.controller.client.GuiClient@28b15fde type Mensch on localhost:13050)])
21:17:11 INFO       sc.server.network.ClientManager - Delegating new client to ClientManager...
21:17:11 INFO       sc.server.network.ClientManager - Delegation done
21:17:11 INFO   sc.server.network.NewClientListener - Added Client Client@420a6ac2 to ReadyQueue.
21:17:11 DEBUG     sc.server.gaming.GameRoomManager - Adding room with id 346cf859-52c6-48d3-911a-0c0096bebcf0
21:17:11 WARN             sc.server.gaming.GameRoom - PAUSE is already false, dropping request
Security framework of XStream not explicitly initialized, using predefined black list on your own risk.
Security framework of XStream not explicitly initialized, using predefined black list on your own risk.
21:17:11 INFO   sc.server.gaming.ReservationManager - Reservation 362ee7bd-d4dc-422f-9a04-91721ccae823 was redeemed.
21:17:11 DEBUG            sc.server.gaming.GameRoom - startIfReady called
21:17:11 INFO             sc.server.gaming.GameRoom - Game not ready yet: Game(players=[ONE(Spieler 1), TWO(Spieler 2)], gameState=GameState R0T0 -> Rot (Bernsteine {}))
Security framework of XStream not explicitly initialized, using predefined black list on your own risk.
Security framework of XStream not explicitly initialized, using predefined black list on your own risk.
21:17:11 INFO   sc.server.gaming.ReservationManager - Reservation a4e5cf6f-51d0-4360-a866-b208bb0dbe5c was redeemed.
21:17:11 DEBUG            sc.server.gaming.GameRoom - startIfReady called
21:17:11 DEBUG    sc.framework.plugins.AbstractGame - Notifying sc.server.gaming.GameRoom@5c9bda10 about new game state
Security framework of XStream not explicitly initialized, using predefined black list on your own risk.
21:17:11 ERROR    sc.framework.plugins.AbstractGame - NewState Notification caused an exception
java.lang.NullPointerException: Cannot invoke "Object.toString()" because the return value of "java.util.Map$Entry.getValue()" is null
    at com.thoughtworks.xstream.core.DefaultConverterLookup.lookupConverterForType(DefaultConverterLookup.java:96)
    at com.thoughtworks.xstream.XStream$1.lookupConverterForType(XStream.java:485)
    at com.thoughtworks.xstream.core.TreeMarshaller.convertAnother(TreeMarshaller.java:48)
    at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.marshallField(AbstractReflectionConverter.java:270)
    at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter$2.writeField(AbstractReflectionConverter.java:174)
    at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.doMarshal(AbstractReflectionConverter.java:262)
    at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.marshal(AbstractReflectionConverter.java:90)
    at com.thoughtworks.xstream.core.TreeMarshaller.convert(TreeMarshaller.java:70)
    at com.thoughtworks.xstream.core.TreeMarshaller.convertAnother(TreeMarshaller.java:58)
    at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.marshallField(AbstractReflectionConverter.java:270)
    at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter$2.writeField(AbstractReflectionConverter.java:174)
    at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.doMarshal(AbstractReflectionConverter.java:262)
    at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.marshal(AbstractReflectionConverter.java:90)
    at com.thoughtworks.xstream.core.TreeMarshaller.convert(TreeMarshaller.java:70)
    at com.thoughtworks.xstream.core.TreeMarshaller.convertAnother(TreeMarshaller.java:58)
    at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.marshallField(AbstractReflectionConverter.java:270)
    at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter$2.writeField(AbstractReflectionConverter.java:174)
    at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.doMarshal(AbstractReflectionConverter.java:262)
    at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.marshal(AbstractReflectionConverter.java:90)
    at com.thoughtworks.xstream.core.TreeMarshaller.convert(TreeMarshaller.java:70)
    at com.thoughtworks.xstream.core.TreeMarshaller.convertAnother(TreeMarshaller.java:58)
    at com.thoughtworks.xstream.core.TreeMarshaller.convertAnother(TreeMarshaller.java:43)
    at com.thoughtworks.xstream.core.TreeMarshaller.start(TreeMarshaller.java:82)
    at com.thoughtworks.xstream.core.AbstractTreeMarshallingStrategy.marshal(AbstractTreeMarshallingStrategy.java:37)
    at com.thoughtworks.xstream.XStream.marshal(XStream.java:1278)
    at com.thoughtworks.xstream.XStream$3.writeToStream(XStream.java:2023)
    at com.thoughtworks.xstream.core.util.CustomObjectOutputStream.writeObjectOverride(CustomObjectOutputStream.java:87)
    at java.base/java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:348)
    at sc.networking.clients.XStreamClient.sendObject(XStreamClient.java:187)
    at sc.networking.clients.XStreamClient.send(XStreamClient.java:168)
    at sc.server.gaming.GameRoom.lambda$observerBroadcast$3(GameRoom.java:132)
    at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
    at sc.server.gaming.GameRoom.observerBroadcast(GameRoom.java:132)
    at sc.server.gaming.GameRoom.onStateChanged(GameRoom.java:145)
    at sc.framework.plugins.AbstractGame.notifyOnNewState(AbstractGame.kt:187)
    at sc.framework.plugins.AbstractGame.next(AbstractGame.kt:108)
    at sc.framework.plugins.AbstractGame.start(AbstractGame.kt:98)
    at sc.server.gaming.GameRoom.start(GameRoom.java:229)
    at sc.server.gaming.GameRoom.startIfReady(GameRoom.java:225)
    at sc.server.gaming.GameRoom.fillSlot(GameRoom.java:203)
    at sc.server.gaming.ReservationManager.redeemReservationCode(ReservationManager.java:38)
    at sc.server.Lobby.onRequest(Lobby.kt:45)
    at sc.server.network.Client.onObject(Client.java:110)
    at sc.networking.clients.XStreamClient.receiveThread(XStreamClient.java:114)
    at sc.networking.clients.XStreamClient$1.run(XStreamClient.java:79)
    at java.base/java.lang.Thread.run(Thread.java:831)
21:17:11 INFO     sc.framework.plugins.AbstractGame - Sending MoveRequest to player ONE(Spieler 1)
21:17:11 DEBUG          sc.framework.plugins.Player - Move requested from ONE(Spieler 1)
21:17:11 INFO             sc.server.gaming.GameRoom - Updating Status to ACTIVE (was: CREATED)
21:17:11 ERROR  sc.networking.clients.XStreamClient - Unknown Communication Error
java.lang.IllegalStateException: Received move request before GameState!
    at sc.gui.controller.client.InternalGameHandler.calculateMove(GuiClient.kt:37)
    at sc.player.PlayerClient.apply(PlayerClient.kt:31)
    at sc.player.PlayerClient.apply(PlayerClient.kt:24)
    at sc.networking.clients.LobbyClient.onObject(LobbyClient.java:85)
    at sc.networking.clients.XStreamClient.receiveThread(XStreamClient.java:114)
    at sc.networking.clients.XStreamClient$1.run(XStreamClient.java:79)
    at java.base/java.lang.Thread.run(Thread.java:831)
21:17:11 WARN   sc.networking.clients.XStreamClient - LobbyClient@3bc1cb03 disconnected (Cause: UNKNOWN, Exception: {})
java.lang.IllegalStateException: Received move request before GameState!
    at sc.gui.controller.client.InternalGameHandler.calculateMove(GuiClient.kt:37)
    at sc.player.PlayerClient.apply(PlayerClient.kt:31)
    at sc.player.PlayerClient.apply(PlayerClient.kt:24)
    at sc.networking.clients.LobbyClient.onObject(LobbyClient.java:85)
    at sc.networking.clients.XStreamClient.receiveThread(XStreamClient.java:114)
    at sc.networking.clients.XStreamClient$1.run(XStreamClient.java:79)
    at java.base/java.lang.Thread.run(Thread.java:831)
21:17:11 WARN   sc.networking.clients.XStreamClient - Client@251468fa disconnected (Cause: LOST_CONNECTION, Exception: {})
java.io.EOFException: null
    at com.thoughtworks.xstream.XStream$4.readFromStream(XStream.java:2102)
    at com.thoughtworks.xstream.core.util.CustomObjectInputStream.readObjectOverride(CustomObjectInputStream.java:123)
    at java.base/java.io.ObjectInputStream.readObject(ObjectInputStream.java:486)
    at java.base/java.io.ObjectInputStream.readObject(ObjectInputStream.java:453)
    at sc.networking.clients.XStreamClient.receiveThread(XStreamClient.java:102)
    at sc.networking.clients.XStreamClient$1.run(XStreamClient.java:79)
    at java.base/java.lang.Thread.run(Thread.java:831)
21:17:11 INFO   sc.networking.clients.XStreamClient - Stopping XStream-Receive id:28 of LobbyClient@3bc1cb03
21:17:11 INFO   sc.networking.clients.XStreamClient - Stopping XStream-Receive id:27 of Client@251468fa
21:17:11 WARN   sc.networking.clients.XStreamClient - ReceiveThread is stopping itself
21:17:11 WARN   sc.networking.clients.XStreamClient - ReceiveThread is stopping itself
21:17:11 INFO             sc.server.gaming.GameRoom - Started Game(players=[ONE(Spieler 1), TWO(Spieler 2)], gameState=GameState R0T0 -> Rot (Bernsteine {}))
21:17:11 DEBUG             sc.networking.TcpNetwork - Closing TcpNetwork{socket=Socket[addr=localhost/127.0.0.1,port=13050,localport=59652]}
21:17:11 DEBUG             sc.networking.TcpNetwork - Closing TcpNetwork{socket=Socket[addr=/127.0.0.1,port=59652,localport=13050]}
21:17:11 INFO       sc.server.network.ClientManager - Removing client Client@251468fa from client manager
21:17:11 INFO             sc.server.gaming.GameRoom - Removing ONE(Spieler 1) from sc.server.gaming.GameRoom@5c9bda10
21:17:11 INFO     sc.framework.plugins.AbstractGame - Stopping Game(players=[ONE(Spieler 1), TWO(Spieler 2)], gameState=GameState R0T0 -> Rot (Bernsteine {}))
21:17:11 INFO    sc.framework.plugins.ActionTimeout - HardTimout wasn't reached.
21:17:11 DEBUG                   sc.plugin2022.Game - Calculating score for ONE(Spieler 1)
21:17:11 DEBUG                   sc.plugin2022.Game - Calculating score for TWO(Spieler 2)
21:17:11 INFO             sc.server.gaming.GameRoom - Updating Status to OVER (was: ACTIVE)
21:17:11 INFO             sc.server.gaming.GameRoom - Game(players=[ONE(Spieler 1), TWO(Spieler 2)], gameState=GameState R0T0 -> Rot (Bernsteine {})) is over (regular=false)
21:17:11 WARN   sc.networking.clients.XStreamClient - Writing on a closed Stream -> dropped the packet (tried to send package of type RoomPacket)
21:17:11 WARN   sc.networking.clients.XStreamClient - LobbyClient@a6b701c disconnected (Cause: PROTOCOL_ERROR, Exception: {})
com.thoughtworks.xstream.converters.ConversionException: No converter available
---- Debugging information ----
message             : No converter available
type                : java.util.EnumMap
converter           : com.thoughtworks.xstream.converters.enums.EnumMapConverter
message[1]          : Could not initialize class com.thoughtworks.xstream.converters.enums.EnumMapConverter$Reflections
converter[1]        : com.thoughtworks.xstream.converters.reflection.SerializableConverter
message[2]          : Unable to make private void java.util.EnumMap.readObject(java.io.ObjectInputStream) throws java.io.IOException,java.lang.ClassNotFoundException accessible: module java.base does not "opens java.util" to unnamed module @5516c33a
converter[2]        : com.thoughtworks.xstream.converters.reflection.ReflectionConverter
message[3]          : Unable to make field transient java.util.Set java.util.AbstractMap.keySet accessible: module java.base does not "opens java.util" to unnamed module @5516c33a
class               : sc.plugin2022.GameState
required-type       : sc.plugin2022.GameState
converter-type      : com.thoughtworks.xstream.converters.reflection.ReflectionConverter
line number         : 79
class[1]            : sc.protocol.room.MementoMessage
required-type[1]    : sc.protocol.room.MementoMessage
class[2]            : sc.protocol.room.RoomPacket
required-type[2]    : sc.protocol.room.RoomPacket
version             : not available
-------------------------------
    at com.thoughtworks.xstream.core.DefaultConverterLookup.lookupConverterForType(DefaultConverterLookup.java:88)
    at com.thoughtworks.xstream.XStream$1.lookupConverterForType(XStream.java:485)
    at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:56)
    at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.unmarshallField(AbstractReflectionConverter.java:499)
    at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.doUnmarshal(AbstractReflectionConverter.java:425)
    at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.unmarshal(AbstractReflectionConverter.java:277)
    at com.thoughtworks.xstream.core.TreeUnmarshaller.convert(TreeUnmarshaller.java:72)
    at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:66)
    at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.unmarshallField(AbstractReflectionConverter.java:499)
    at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.doUnmarshal(AbstractReflectionConverter.java:425)
    at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.unmarshal(AbstractReflectionConverter.java:277)
    at com.thoughtworks.xstream.core.TreeUnmarshaller.convert(TreeUnmarshaller.java:72)
    at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:66)
    at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.unmarshallField(AbstractReflectionConverter.java:499)
    at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.doUnmarshal(AbstractReflectionConverter.java:425)
    at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.unmarshal(AbstractReflectionConverter.java:277)
    at com.thoughtworks.xstream.core.TreeUnmarshaller.convert(TreeUnmarshaller.java:72)
    at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:66)
    at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:50)
    at com.thoughtworks.xstream.core.TreeUnmarshaller.start(TreeUnmarshaller.java:134)
    at com.thoughtworks.xstream.core.AbstractTreeMarshallingStrategy.unmarshal(AbstractTreeMarshallingStrategy.java:32)
    at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:1431)
    at com.thoughtworks.xstream.XStream$4.readFromStream(XStream.java:2105)
    at com.thoughtworks.xstream.core.util.CustomObjectInputStream.readObjectOverride(CustomObjectInputStream.java:123)
    at java.base/java.io.ObjectInputStream.readObject(ObjectInputStream.java:486)
    at java.base/java.io.ObjectInputStream.readObject(ObjectInputStream.java:453)
    at sc.networking.clients.XStreamClient.receiveThread(XStreamClient.java:102)
    at sc.networking.clients.XStreamClient$1.run(XStreamClient.java:79)
    at java.base/java.lang.Thread.run(Thread.java:831)
21:17:11 INFO   sc.networking.clients.XStreamClient - Stopping XStream-Receive id:26 of LobbyClient@a6b701c
21:17:11 WARN   sc.networking.clients.XStreamClient - ReceiveThread is stopping itself
21:17:11 DEBUG             sc.networking.TcpNetwork - Closing TcpNetwork{socket=Socket[addr=localhost/127.0.0.1,port=13050,localport=59650]}
21:17:11 WARN   sc.networking.clients.XStreamClient - Client@47124b1a disconnected (Cause: LOST_CONNECTION, Exception: {})
java.io.EOFException: null
    at com.thoughtworks.xstream.XStream$4.readFromStream(XStream.java:2102)
    at com.thoughtworks.xstream.core.util.CustomObjectInputStream.readObjectOverride(CustomObjectInputStream.java:123)
    at java.base/java.io.ObjectInputStream.readObject(ObjectInputStream.java:486)
    at java.base/java.io.ObjectInputStream.readObject(ObjectInputStream.java:453)
    at sc.networking.clients.XStreamClient.receiveThread(XStreamClient.java:102)
    at sc.networking.clients.XStreamClient$1.run(XStreamClient.java:79)
    at java.base/java.lang.Thread.run(Thread.java:831)
21:17:11 INFO     sc.networking.clients.LobbyClient - Received game result: GameResult(winner=null, scores=[Spieler 1(cause=LEFT, reason='Der Spieler hat das Spiel verlassen', parts=[Siegpunkte=0, Bernsteine=0, Figur vorne=6]), Spieler 2(cause=REGULAR, reason='', parts=[Siegpunkte=2, Bernsteine=0, Figur vorne=7])])
21:17:11 WARN   sc.networking.clients.XStreamClient - Client@47124b1a disconnected (Cause: PROTOCOL_ERROR, Exception: {})
com.thoughtworks.xstream.io.StreamException: 
    at com.thoughtworks.xstream.core.util.QuickWriter.flush(QuickWriter.java:77)
    at com.thoughtworks.xstream.io.xml.PrettyPrintWriter.flush(PrettyPrintWriter.java:346)
    at com.thoughtworks.xstream.io.WriterWrapper.flush(WriterWrapper.java:49)
    at com.thoughtworks.xstream.io.StatefulWriter.flush(StatefulWriter.java:139)
    at com.thoughtworks.xstream.XStream$3.flush(XStream.java:2035)
    at com.thoughtworks.xstream.core.util.CustomObjectOutputStream.flush(CustomObjectOutputStream.java:145)
    at sc.networking.clients.XStreamClient.sendObject(XStreamClient.java:188)
    at sc.networking.clients.XStreamClient.send(XStreamClient.java:168)
    at sc.server.gaming.GameRoom.lambda$broadcast$2(GameRoom.java:127)
    at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
    at sc.server.gaming.GameRoom.broadcast(GameRoom.java:127)
    at sc.server.gaming.GameRoom.broadcast(GameRoom.java:121)
    at sc.server.gaming.GameRoom.onGameOver(GameRoom.java:76)
    at sc.framework.plugins.AbstractGame.notifyOnGameOver(AbstractGame.kt:176)
    at sc.framework.plugins.AbstractGame.stop(AbstractGame.kt:92)
    at sc.server.gaming.GameRoom.cancel(GameRoom.java:382)
    at sc.server.gaming.GameRoom.removePlayer(GameRoom.java:411)
    at sc.server.gaming.PlayerSlot.onClientDisconnected(PlayerSlot.java:90)
    at sc.server.network.Client.onDisconnect(Client.java:89)
    at sc.networking.clients.XStreamClient.handleDisconnect(XStreamClient.java:215)
    at sc.networking.clients.XStreamClient.receiveThread(XStreamClient.java:127)
    at sc.networking.clients.XStreamClient$1.run(XStreamClient.java:79)
    at java.base/java.lang.Thread.run(Thread.java:831)
Caused by: java.net.SocketException: Socket closed
    at java.base/sun.nio.ch.NioSocketImpl.ensureOpenAndConnected(NioSocketImpl.java:165)
    at java.base/sun.nio.ch.NioSocketImpl.beginWrite(NioSocketImpl.java:366)
    at java.base/sun.nio.ch.NioSocketImpl.implWrite(NioSocketImpl.java:411)
    at java.base/sun.nio.ch.NioSocketImpl.write(NioSocketImpl.java:440)
    at java.base/sun.nio.ch.NioSocketImpl$2.write(NioSocketImpl.java:826)
    at java.base/java.net.Socket$SocketOutputStream.write(Socket.java:1045)
    at java.base/sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:242)
    at java.base/sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:321)
    at java.base/sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:325)
    at java.base/sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:159)
    at java.base/java.io.OutputStreamWriter.flush(OutputStreamWriter.java:248)
    at com.thoughtworks.xstream.core.util.QuickWriter.flush(QuickWriter.java:75)
    ... 22 common frames omitted
21:17:11 INFO   sc.networking.clients.XStreamClient - Stopping XStream-Receive id:25 of Client@47124b1a
21:17:11 DEBUG             sc.networking.TcpNetwork - Closing TcpNetwork{socket=Socket[addr=/127.0.0.1,port=59650,localport=13050]}
21:17:11 INFO       sc.server.network.ClientManager - Removing client Client@47124b1a from client manager
21:17:11 WARN   sc.networking.clients.XStreamClient - Attempted to close an already closed stream
21:17:11 DEBUG            sc.server.gaming.GameRoom - Saving replay to /home/replays/replay_swc_2022_ostseeschach_2021-09-17_21-17-11_Spieler_1_Spieler_2.xml
21:17:11 DEBUG            sc.server.gaming.GameRoom - Kicking clients and observers
21:17:11 WARN   sc.networking.clients.XStreamClient - Writing on a closed Stream -> dropped the packet (tried to send package of type RemovedFromGame)
21:17:11 INFO     sc.networking.clients.LobbyClient - Received RemovedFromGame
21:17:11 INFO     sc.networking.clients.LobbyClient - Left 346cf859-52c6-48d3-911a-0c0096bebcf0
21:17:11 WARN   sc.networking.clients.XStreamClient - Writing on a closed Stream -> dropped the packet (tried to send package of type RemovedFromGame)
21:18:10 INFO   sc.server.network.NewClientListener - Shutting down NewClientListener...
21:18:10 DEBUG                        sc.gui.GuiApp - GuiApp stopped, ending program
xeruf commented 3 years ago

Danke für den ausführlichen Report :) tritt das immer auf? Ich kann es nämlich nicht reproduzieren.

0xhtml commented 3 years ago

Ja, dieser Fehler tritt bei mir immer auf. Ich habe das Starten von zwei Beispiel-Computerspielern nochmal ohne die GUI getestet und es passiert der gleiche Fehler.

Logs: server.log client1.log client2.log

Das Issue kann vermutlich in software-challenge/backend verschoben werden, da der Fehler auch ohne GUI auftritt.

0xhtml commented 3 years ago

Ich habe das ganze nochmal mit Java 11 getestet und damit funktioniert es.

openjdk version "11.0.12" 2021-07-20
OpenJDK Runtime Environment (build 11.0.12+7)
OpenJDK 64-Bit Server VM (build 11.0.12+7, mixed mode)
xeruf commented 3 years ago

Interessant, ich habe bei mir mit Java 11 und 16 getestet und alles hat funktioniert - und ich bin auch auf Arch. Vielleicht liegt es daran, dass es mit Java 11 kompiliert und Java 16 ausgeführt wurde...

xeruf commented 3 years ago

Jup, reproduziert. Mal schauen ob man eine generic-version bauen kann...

xeruf commented 3 years ago

Scheint diesem Problem zu entsprechen: https://github.com/x-stream/xstream/issues/253

0xhtml commented 3 years ago

Ok, mit der --illegal-access=permit-Flag kann ich die Server-, Defaultplayer- und GUI-Jar auch mit Java 16 ausführen. Ich verstehe aber nicht warum das so ist.

xeruf commented 3 years ago

Weil Java immer restriktiver wird was package access angeht, und teils sehr nützliche tools unter Zugriffsbeschränkungen versteckt ^^

xeruf commented 3 years ago

Momentchen, bei mir funktioniert die Flag nicht, kannst du mir nochmal genau zeigen wie du es ausführst? :sweat_smile:

0xhtml commented 3 years ago

So führe ich die GUI und Server aus: java --illegal-access=permit -jar socha.jar

xeruf commented 3 years ago

ah, ich hatte die flag ans ende gesetzt, so ergibt das natürlich Sinn. Das kann ich dann allerdings wahrscheinlich ohne ein custom launch-script nicht fest verbauen.

0xhtml commented 3 years ago

EDIT: Bessere Möglichkeit

Die einzige Möglichkeit, die mir bekannt ist, um illegal-access=permit in der jar-Datei selber zu setzen, ist es einen zweiten Prozess zu starten, mit dem richtigen Parameter. z.B.:

if (System.getProperty("java.version").startsWith("16.")) {
    if (!System.getenv().containsKey("_JAVA_OPTIONS")) {
        List<String> cmd = new ArrayList<>();
        cmd.add("java");
        cmd.add("-cp");
        cmd.add(System.getProperty("java.class.path"));
        cmd.add(Application.class.getName());
        cmd.addAll(Arrays.asList(params));

        ProcessBuilder pb = new ProcessBuilder(cmd);
        pb.inheritIO();
        pb.environment().put("_JAVA_OPTIONS", "--illegal-access=permit");

        pb.start().waitFor();

        return;
    }
}

(Wichtig ist die Nutzung der _JAVA_OPTIONS-Enviromnent-Variable statt direkt den Parameter zu übergeben, um überprüfen zu können, ob illegal-access=permit gesetzt ist, und nicht in einer endlosen Schleife zu landen.)

0xhtml commented 3 years ago

Ich habe vielleicht doch eine bessere Möglichkeit gefunden. In den Release Notes zu Java 17 steht folgendes:

With this change, the java launcher option --illegal-access is obsolete. If used on the command line it causes a warning message to be issued, and otherwise has no effect. Existing code that must use internal classes, methods, or fields of the JDK can still be made to work by using the --add-opens launcher option, or the Add-Opens JAR-file manifest attribute, to open specific packages.

Ab Java 17 gibt es also den --illegal-access Parameter nicht mehr, aber es ist wohl (auch in Java 16) möglich das Add-Opens-Attribute in der Manifest der Jar-Datei zu benutzen, um die illegal-access-Probleme zu umgehen. Es wäre also möglich in der Jar-Datei selber dieses Attribute zu setzen.

0xhtml commented 3 years ago

Funktionierender Add-Opens-Parameter: --add-opens java.base/java.util=ALL-UNNAMED Ungetestetes Manifest-Attribute: Add-Opens: java.base/java.util=ALL-UNNAMED

xeruf commented 3 years ago

das mit dem Manifest ist ein guter Hinweis, danke :)