Steam Client Timeout auf Server

Ich habe die logs mit docker compose logs --since ... > umgeleitet um auch die start und end echos vom entrypoint.sh script mit zu haben.

Das angehängte log hat 3 Sessions, eine kurze eine lange, beide mit SIGSEGV und eine "normale" danach die wegen fehlendem freien port beendet wurde.

An diesem log sieht man sehr schön das es komplett random erscheint wann der prozess abschmiert.

Ich weiss nicht obs relevant ist aber eben habe ich eine Blaupause machen wollen und genau dann ist er abgeschmiert. Ist zumindest mal was anderes.

Gestern wars ganz schlimm, gefühlt gibt es mehr SIGSEGV seit ich das extra JNI logging aktiviert habe. Ich habe das 26MB log von gestern gesplittet und alle sessions mit SIGSEGV lade ich hier mal hoch. Auffällig war nur das ein Spieler auch sagte er habe vorher mit einer Blaupause hantiert direkt vor dem crash.

session6 war übrigens mit einer neuen Discord Plugin version, ich habe bei dem Plugin die veraltete JavaCord lib gegen JDA ausgetauscht in der Hoffnung auf Besserung aber ich war nur kurz da und hab ein paar Steine gehauen als er wieder abgeschmiert ist.

Vielen Dank für die neuen Logs! Die Crashes treten an der selben Stelle auf, da liegt also offensichtlich die selbe Ursache zugrunde... ich vermute stark es hängt mit der Ausgabe Create new JNIEnv zusammen, was einfach auffallend häufig vorkommt. Verdächtig ist, dass es meist kurz nach der Ausgabe [Java] [OZ.AdminUtils] chunk xx xx updated kommt. AdminUtils erzeugt aber keine neuen Threads, oder? Welche Methoden ruft diese Stelle auf? Ist das evtl. die Screenshot Funktion? Kannst du mir diesen Code sonst evtl. mal senden (gerne auch per PN)?

Das mit den Blueprints könnte reiner Zufall sein (oder lauscht du zufällig auf die entsprechenden Events und machst da etwas spezielles)?

Wenn im Plugin sonst aber wirklich keine neuen Threads erstellt werden, vermute ich, dass es wohl irgendwie mit den Callbacks zusammenhängt, dass immer neue JNIEnvs erzeugt werden. Ich gehe auch stark davon aus, dass das für die Crashes verantwortlich ist, denn JNIEnvs werden nicht automatisch aufgeräumt oder detached. Sie werden aber trotzdem vom GC geprüft. Wenn sie nun von OS-Seite sterben und implizit aufgeräumt werden, könnte das unter Umständen den Crash erklären (da JNI weiterhin die Referenz hält).

Eine potenzielle Lösung für das Problem: Einen anderen Garbage Collector verwenden. Das Concurrent-Marking verursacht das Problem, d.h. ein anderer GC ohne SATB-Buffer würde wahrscheinlich keinen Crash verursachen. Du könntest testweise die server.properties Datei öffnen und unter Plugins_VMOptions mal -XX:+UseParallelGC eintragen, also:

Plugins_VMOptions=-XX:+UseParallelGC

Das sollte einen anderen GC verwenden, der keine SATB Buffer benutzt. Ist natürlich keine richtige Lösung für das Problem (da es möglicherweise etwas die Performance schmälert), wäre aber testweise mal interessant zu wissen, ob die Crashes dann weiterhin auftreten. Falls es dann sauber läuft, würde es höchstwahrscheinlich wirklich an obiger Theorie liegen.

AdminUtils aktualisiert die chunk Oberflächen für die map, allerdings habe ich das erst kürzlich aktiviert, die crashes gab es schon vorher. Ich kann es aber Zeitweise mal wieder deaktivieren und dann noch mal logs generieren.

Die KI hatte mir auch vorgeschlagen UseParallelGC oder UseSerialGC zu verwenden, aktuell hab ich letzteres aktiviert seit 9:48 heute. Bisher gab es noch keinen crash. Sollte es einen weiteren geben werde ich die Mapping Funktion aus AdminUtils deaktivieren.

Bisher habe ich noch kein Plugin das auf blueprints lauscht.

Die chunk x z Ausgabe findet hier statt: https://github.com/Devidian/rw…dMapChunkCapture.java#L30

Hier mal aus der aktuellen log session, die noch nicht abgestürzt ist:

[Java] [OZ.ThreadDiagnostics] Thread summary: current=59, peak=69, totalStarted=429, names={Cleaner-0=1, Common-Cleaner=1, FileSystemWatchService=1, Finalizer=1, JDA Gateway-Worker 1=1, JDA MainWS-ReadThread=1, JDA MainWS-WriteThread=1, JDA RateLimit-Elastic-Worker 2=1, JDA RateLimit-Scheduler-Worker 1=1, JDA RateLimit-Scheduler-Worker 2=1, Notification Thread=1, OZ-ThreadDiagnostics=1, OZAdminUtils-MapSource=1, OZDiscordConnect-ActivityTimer=1, OZDiscordConnect-RestartTimer=1, OZDiscordConnect-Transport=1, PluginFileWatcher-Thread=1, ReadingThread=1, Reference Handler=1, Signal Dispatcher=1, Thread-26=1, Thread-27=1, Thread-28=1, Thread-29=1, Thread-30=1, Thread-31=1, Thread-37=1, Thread-38=1, Thread-39=1, Thread-40=1, Thread-41=1, Thread-42=1, Thread-43=1, Thread-44=1, Thread-50=1, Thread-51=1, Thread-52=1, Thread-53=1, Thread-8=1, WebSocket-Reconnect=1, WritingThread=1, httpclient-dispatch-1=1, httpclient-dispatch-10=1, httpclient-dispatch-11=1, httpclient-dispatch-12=1, httpclient-dispatch-13=1, httpclient-dispatch-14=1, httpclient-dispatch-15=1, httpclient-dispatch-16=1, httpclient-dispatch-2=1, httpclient-dispatch-3=1, httpclient-dispatch-4=1, httpclient-dispatch-5=1, httpclient-dispatch-6=1, httpclient-dispatch-7=1, httpclient-dispatch-8=1, httpclient-dispatch-9=1, httpclient-main-1=1, main=1}

Die Session lief bis zum geplanten Neustart einwandfrei durch und es waren einige Spieler aktiv

[Java] [OZ.ThreadDiagnostics] Thread summary: current=65, peak=69, totalStarted=626, names={Cleaner-0=1, Common-Cleaner=1, FileSystemWatchService=1, Finalizer=1, ForkJoinPool.commonPool-worker-80=1, JDA Gateway-Worker 1=1, JDA MainWS-ReadThread=1, JDA MainWS-WriteThread=1, JDA RateLimit-Elastic-Worker 2=1, JDA RateLimit-Scheduler-Worker 1=1, JDA RateLimit-Scheduler-Worker 2=1, Notification Thread=1, OZ-ThreadDiagnostics=1, OZAdminUtils-MapSource=1, OZDiscordConnect-ActivityTimer=1, OZDiscordConnect-RestartTimer=1, OZDiscordConnect-Transport=1, OkHttp TaskRunner=4, Okio Watchdog=1, PluginFileWatcher-Thread=1, ReadingThread=1, Reference Handler=1, Signal Dispatcher=1, Thread-26=1, Thread-27=1, Thread-28=1, Thread-29=1, Thread-30=1, Thread-31=1, Thread-37=1, Thread-38=1, Thread-39=1, Thread-40=1, Thread-41=1, Thread-42=1, Thread-43=1, Thread-44=1, Thread-50=1, Thread-51=1, Thread-52=1, Thread-53=1, Thread-8=1, WebSocket-Reconnect=1, WritingThread=1, httpclient-dispatch-1=1, httpclient-dispatch-10=1, httpclient-dispatch-11=1, httpclient-dispatch-12=1, httpclient-dispatch-13=1, httpclient-dispatch-14=1, httpclient-dispatch-15=1, httpclient-dispatch-16=1, httpclient-dispatch-2=1, httpclient-dispatch-3=1, httpclient-dispatch-4=1, httpclient-dispatch-5=1, httpclient-dispatch-6=1, httpclient-dispatch-7=1, httpclient-dispatch-8=1, httpclient-dispatch-9=1, httpclient-main-1=1, main=1}
...
Invoke shutdown via command...
[WARNING] [17:02:22] Exit (0)
[WARNING] [17:02:22] Q U I T   R I S I N G   W O R L D   S E R V E R
Stopping Webserver...
STEAM SERVER SHUTDOWN
...
JNI: DESTROY JAVA VM
Create new JNIEnv  (handle: 93843685619264, thread: 95460)
[Java] [OZLogger] Terminating Log4j framework globally.
NativeMemoryManager: Free 30855 memory pointers (305333707 B)...
[END]

interessant ist hier das er shutdown macht aber danach 5 mal neustarten muss weil er das problem mit dem port hat. Du hattest mal gesagt das man in den settings Server_RestartEnabled=False verwenden soll, aber geholfen hat es nicht

Da kommt dann immer das hier:

Create Public Webserver IP: 0.0.0.0 Port: 4254
Add Prefix: /
Add Prefix: /info
Add Prefix: /playerlist
Add Prefix: /images/header
Add Prefix: /game/maptile
Add Prefix: /game/image
Add Prefix: /game/asset
Add Prefix: /game/chunkmultirequest
[ERROR] [17:04:05]  !!! UNCAUGHT EXCEPTION !!! 
    UnityEngine.DebugLogHandler:Internal_Log(LogType, LogOption, String, Object)
    RisingWorld.Server.Main:HandleError(Exception)
    RisingWorld.Common.JIWApplication:Update()


[ERROR] SocketException: Address already in use
    System.Net.Sockets.Socket.Bind (System.Net.EndPoint localEP) (at <00000000000000000000000000000000>:0)
    NetCoreServer.TcpServer.Start () (at <00000000000000000000000000000000>:0)
    RisingWorld.Server.Main.InitWebserver () (at <00000000000000000000000000000000>:0)
    RisingWorld.Server.Main.OnPostInitialize () (at <00000000000000000000000000000000>:0)
    RisingWorld.Common.JIWApplication.Update () (at <00000000000000000000000000000000>:0)
    ExceptionExtensions:PrintStackTrace(Exception)
    RisingWorld.Server.Main:HandleError(Exception)
    RisingWorld.Common.JIWApplication:Update()


[WARNING] [17:04:05] Exit (1)
[WARNING] [17:04:05] Q U I T   R I S I N G   W O R L D   S E R V E R
Stopping Webserver...
STEAM SERVER SHUTDOWN

Und im Discord sieht das so aus:

kann ich den Xms wert eigentlich auch über eine server property steuern oder muss ich den mit Plugins_VMOptions überschreiben? Die KI meint der Wert wäre etwas niedrig gewählt

PS: Die Nachtsession lief auch durch. Wenn der heutige Tag auch ohne SIGSEGV oder anderem Absturz läuft schalte ich morgen früh mal auf ParallelGC