View Issue Details
ID | Project | Category | Date Submitted | Last Update | |
---|---|---|---|---|---|
0024241 | AI War 2 | Crash/Exception | Dec 17, 2020 3:03 am | Dec 21, 2020 11:55 am | |
Reporter | Arides | Assigned To | Chris_McElligottPark | ||
Status | resolved | Resolution | fixed | ||
Product Version | 2.705 Clarity, Refinement, and Performance | ||||
Fixed in Version | 2.708 Mapgen For Multiplayer | ||||
Summary | 0024241: Multiplayer: Client freezes completely every 5 minutes | ||||
Description | After playing for about 10 minutes, client starts to freeze every 5 minutes or so. The only solution seems to be quitting the seesion and rejoin. Since this happens every 5 minutes, the game is unplayable. Details: - The client usually selects a planet to view, but sees only an empty planet, then everything freezes and the only way out is quitting the session. Save games attached, I can re-run them with some logging options enabled if that helps. | ||||
Tags | No tags attached. | ||||
related to | 0024207 | resolved | Chris_McElligottPark | Go to build turrets to beachhead in multiplayer... game freezes up. |
|
|
|
Any error messages, in either the ArcenDebugLog or the unity log? |
|
No messages of any kind in ArcenDebugLog, or any other log in the same folder. I tryed the save with some debugging options but same result, plus the client freezes within seconds from start. Host gets "Player X is lagging behind" message and that's it. |
|
Same result - nothing - after running the same thing with multiple debug options from the NETWORK tab (Network debugging mode + Network Logging Includes FrameAuths, Command batches, synch checks). ArcenDebugLog contains nothing except the usualy player connected ... player disconnected (after I manually quit the game). Where can I find the unity log? |
|
Correction, there are many "Thread X started, thread X finished" entries. But nothing odd - at least for someone who doesn't know the code inside. |
|
Does the client entirely lock up (as in program is not responding), or does the client just stop processing more frames and sit there? That determines what kind of lockup this is, and what sort of tooling I might be able to do to help. I am aware that this is a general problem with multiplayer at least with some factions right now, but once I find it, it should be a quick fix. |
|
To clarify, I think this has been a problem for under a week. |
|
I can provide a snippet of information, my playgroup ran into this on December 15th, which means it predates the December 16th build. Normally not very helpful, but the only other recent pushes were the 12th and 14th. I can't help there, we played on the 14th (after the patch) for the first time this month. It's not consistent either, in my group of three, one person got it thrice and the other just once. That instance of once coincided with one of the other instances or happened while the other client was "locked up". Important: The client doesn't actually freeze in any way. The host just says it's waiting on the clients and they don't seem to ever return from that state. Exiting to the menu is fine and easy, and the host does not need to rehost to fix it. The client just need to re-connect. Other random, potentially unrelated bits: The guy who got it thrice had his client pull the FATAL ERROR shenanigans for the Ai Instigators and zombies, but that was part of stage3DoPerSecond logic which you've since disabled client side. This did not happen to the guy who got it once. |
|
woops, typo. At the very start, December 15th should be December 14th, though that's probably clear from context. |
|
As Paradox said, the client is still responding, but the game is just sitting there. Quit to main menu & reconnect to host makes it run for a while again, however quickly leads to the same result. One maybe unrelated note - I've noticed in single player that recently viewing a planet seems to load the planet image itself first, then after a fraction of second the ships and everything else appear. In multiplayer client, I always got this issue doing just that - view a planet, the planet image loaded and that's it. Nothing but the image ever loads. Host gets "waiting for client X" message, client seems to wait for something indefinitely. |
|
For 2.707: * Completely reworked the way we track long-running background threads. It's no longer just the faction planning threads, but instead is ALL of the background threads, even those that are only supposed to run for part of a second at a time. ** These all now will start showing on the interface as slow-running background threads after some warning interval (varies by thread), and then the main thread will forcibly kill them after a certain longer interval. *** For the short-term threads, it generally warns you after 2 seconds and kills it after 10 seconds. For the longer-term stuff, it generally warns you after 10 seconds and kills them after 30 seconds. ** This provides a hopefully-foolproof way for us to find threads that are stuck in infinite loops, which is something we're aware some mutiplayer clients are experiencing at the moment. The only thread it can't detect this on is the main thread itself, but if in those instances the game program would appear entirely unresponsive (white screen, nothing displays, OS is worried, etc), and that's not what we're having reports of. *** If you are having one of these slow background threads happen and it's causing an issue in multiplayer, please wait until it counts all the way up and actually throws an error. The error handling is designed to give us as close a view as possible of where the error actually is. Please then give us the error log that contains several detailed errors (usally between one and three) rather than a screenshot. ** We should then be able to fix whatever is going on, or if the problem is in a modder's code (in this instance it does not seem that is the case), then the modder can also find out and solve that. ** It's worth noting that the "main simulation thread" is actually on a background thread, and so that's a thread that we can indeed (and do) track. |
|
I'm afraid I bear bad news. It seems the stuck thread is 'executionContext'. Logs and new save attached. Will try next game without civilian industries to see if it's somehow related to factions in mods. ArcenDebugLog.txt (10,203 bytes)
12/21/2020 8:43:17 AM Current directory used: C:/Games/steamapps/common/AI War 2/ Process Count = 0 so PlayerDataDirectory used: C:/Games/steamapps/common/AI War 2/PlayerData/ 12/21/2020 8:43:17 AM Boot up FleetOS (0.2919s) 12/21/2020 8:43:17 AM graphicsDeviceType in use: Direct3D11 graphicsDeviceVersion in use: Direct3D 11.0 [level 11.1] graphicsMultiThreaded: True graphicsShaderLevel: 50 operatingSystem: Windows 10 (10.0.0) 64bit graphicsDeviceName: NVIDIA GeForce GTX 950 graphicsDeviceID: 5122 graphicsDeviceVendor: NVIDIA graphicsDeviceVendorID: 4318 graphicsDeviceVersion: Direct3D 11.0 [level 11.1] graphicsMemorySize: 2007 maxTextureSize: 16384 npotSupport: Full processorType: Intel(R) Core(TM) i7-4790 CPU @ 3.60GHz processorCount: 8 processorFrequency: 3592 systemMemorySize: 8130 supportedRenderTargetCount: 8 supportsComputeShaders: True supportsShadows: True usesReversedZBuffer: True 12/21/2020 8:43:18 AM Check System Logs For Rogue Intelligence (0.3046s) 12/21/2020 8:43:18 AM Inspect Aft Hatches (0.0350s) 12/21/2020 8:43:18 AM Found 277 xml files in 86 folders in 22ms 12/21/2020 8:43:18 AM Check For Extra Modules (0.3249s) 12/21/2020 8:43:18 AM 277 Xml Files Parsed in 301ms 12/21/2020 8:43:18 AM Gather Ancient Lifeforms (0.0060s) 12/21/2020 8:43:18 AM Game Version: 2.707 12/21/2020 8:43:18 AM Eject Trash Into Hyperspace (0.0120s) 12/21/2020 8:43:18 AM Bring Cloaking Systems Online (0.0070s) 12/21/2020 8:43:18 AM Recalculate Speed Of Light (0.0220s) 12/21/2020 8:43:18 AM Optimize Comfort On Command Decks (0.0200s) 12/21/2020 8:43:18 AM Generating Framerates (0.0050s) 12/21/2020 8:43:18 AM Update mod and expansion statuses! 12/21/2020 8:43:18 AM Expansions: The Spire Rises (Installed And Enabled!) Zenith Onslaught (NOT INSTALLED) The Neinzul Abyss (NOT INSTALLED) 12/21/2020 8:43:18 AM Mods: AMU (Disabled) ExtendedShipVariants (Disabled) KaizersMarauders (Disabled) MicroModCollection (Disabled) MoreStartingOptions (Enabled!) MoreSystemDefenders (Disabled) SKCivilianIndustry (Enabled!) SpireRailgunShop (Disabled) 12/21/2020 8:43:18 AM Check Nearby Stellar Masses (0.0380s) 12/21/2020 8:43:18 AM 277 Xml Files Checked For Exp/Mod Status in 12ms 12/21/2020 8:43:18 AM Pruning Excess Brain Cells (0.0330s) 12/21/2020 8:43:18 AM Remembering Alamo (0.0200s) 12/21/2020 8:43:18 AM Boot Audio Comms (0.0080s) 12/21/2020 8:43:18 AM Establish Individual Audio Links (0.0200s) 12/21/2020 8:43:18 AM No resolution change was required. 12/21/2020 8:43:18 AM Applied graphics settings: AntialiasingMode:x2 UseSoftParticles:False BillboardsFaceCameraPosition:False AnisotropicMode:ForceEnable TextureQuality:Full 12/21/2020 8:43:18 AM Applied Framerate Type: 144 FPS (vsync: 0 targetFPS:144) 12/21/2020 8:43:18 AM Refresh Optical Lensing (0.0100s) 12/21/2020 8:43:18 AM Revise Fundamental Physical Laws (0.0210s) 12/21/2020 8:43:18 AM Calculate Odds Of Success (0.0260s) 12/21/2020 8:43:19 AM Briefly Panic (0.5340s) 12/21/2020 8:43:19 AM Install Confidence Routines (0.3458s) 12/21/2020 8:43:19 AM Bring Commander Interface Online (0.0700s) 12/21/2020 8:43:19 AM Motivate All Crews (0.0490s) 12/21/2020 8:43:19 AM Locating Available Networks (0.0230s) 12/21/2020 8:43:19 AM Externalizing Patterns (0.0230s) 12/21/2020 8:43:19 AM Hooking Externals (0.0050s) 12/21/2020 8:43:19 AM Handlizing Hooks (0.0070s) 12/21/2020 8:43:19 AM Disengaging Constants (0.0210s) 12/21/2020 8:43:19 AM Late Axionic Computations (0.1221s) 12/21/2020 8:43:19 AM Suppressing Bad Thoughts (0.0060s) 12/21/2020 8:43:19 AM Sentinel Alertness Diagnostic (0.0070s) 12/21/2020 8:43:19 AM Connecting to Fleet Command (0.0070s) 12/21/2020 8:43:19 AM Thinking Of Advice (0.0060s) 12/21/2020 8:43:19 AM Degaussing Advice (0.0080s) 12/21/2020 8:43:19 AM Reading Alien Diaries (0.0090s) 12/21/2020 8:43:19 AM Naming All Known Planets (0.0080s) 12/21/2020 8:43:19 AM Remembering Speeds (0.0110s) 12/21/2020 8:43:19 AM Prioritizing Targets (0.0080s) 12/21/2020 8:43:19 AM Rebooting Sensor Arrays (0.0100s) 12/21/2020 8:43:19 AM Unloading Prismatic Grid (0.0080s) 12/21/2020 8:43:19 AM Thinking Of Objectives (0.0110s) 12/21/2020 8:43:19 AM Inhibiting Visual Scans (0.0150s) 12/21/2020 8:43:19 AM Synthesizing Vocals (0.0060s) 12/21/2020 8:43:19 AM Investigating Map Signatures (0.0120s) 12/21/2020 8:43:19 AM Ventilating Scenarios (0.0070s) 12/21/2020 8:43:19 AM Decontaminating Targeting Systems (0.0080s) 12/21/2020 8:43:20 AM Ejecting Tactical Core (0.0080s) 12/21/2020 8:43:20 AM Calibrating Formations (0.0100s) 12/21/2020 8:43:20 AM Intercepting Galactic Maps (0.0100s) 12/21/2020 8:43:20 AM Discharging Colored Ions (0.0170s) 12/21/2020 8:43:20 AM Replicating Ion Colors (0.0060s) 12/21/2020 8:43:20 AM Faction Diagnostics (0.0110s) 12/21/2020 8:43:20 AM Buffering Hackers (0.0130s) 12/21/2020 8:43:20 AM Inverting Death (0.0080s) 12/21/2020 8:43:20 AM Linear Field Variance (0.0130s) 12/21/2020 8:43:20 AM Charging Marks (0.0090s) 12/21/2020 8:43:20 AM Guarding The Posts (0.1449s) 12/21/2020 8:43:20 AM Range Manifolds (0.0050s) 12/21/2020 8:43:20 AM Purging ROFs (0.0060s) 12/21/2020 8:43:20 AM Manipulating Speeds (0.0080s) 12/21/2020 8:43:20 AM Detecting Projectiles (0.0060s) 12/21/2020 8:43:20 AM Grouping Flow Fields (0.0080s) 12/21/2020 8:43:20 AM Modulating Flow Field Groups (0.0110s) 12/21/2020 8:43:20 AM Designing Fleets (0.0100s) 12/21/2020 8:43:20 AM Thinking Of Technologies (0.0060s) 12/21/2020 8:43:20 AM Categorizing Starboard Sensors (0.0060s) 12/21/2020 8:43:20 AM Injecting Galactic Variables (0.0120s) 12/21/2020 8:43:20 AM Viewing Starfields (0.0150s) 12/21/2020 8:43:20 AM Pillaging Distant Planets (0.0230s) 12/21/2020 8:43:20 AM Categorizing All Planets (0.0060s) 12/21/2020 8:43:20 AM Organizing Commands (0.0150s) 12/21/2020 8:43:20 AM Calculating Firing Cones (0.0060s) 12/21/2020 8:43:20 AM Remembering Lost Ship Parts (0.1099s) 12/21/2020 8:43:20 AM Re-Aligning Objectives (0.0110s) 12/21/2020 8:43:20 AM Sterilizing Test Chamber (0.0060s) 12/21/2020 8:43:20 AM Issuing Orders (0.0060s) 12/21/2020 8:43:20 AM Augmenting Infusers (0.0060s) 12/21/2020 8:43:20 AM Infusing (0.0160s) 12/21/2020 8:43:20 AM Load Surrogates (0.0340s) 12/21/2020 8:43:30 AM Eject And Reinsert Warp Cores (9.4384s) 12/21/2020 8:43:30 AM Post-Proton Surge (0.0200s) 12/21/2020 8:43:30 AM Background Radiation Taste Test (0.0280s) 12/21/2020 8:43:30 AM Shuffling Chairs On Command Deck (0.0160s) 12/21/2020 8:43:30 AM Windshield Wiping (0.0060s) 12/21/2020 8:43:30 AM Last Organizational Modeling (0.0710s) 12/21/2020 8:43:30 AM Stimulate Modulation (0.0290s) 12/21/2020 8:43:30 AM Tip Servos (0.0060s) 12/21/2020 8:43:30 AM Sort Buildings Into Uneven Piles (0.0070s) 12/21/2020 8:43:30 AM Design New Fleet Logo (0.0080s) 12/21/2020 8:43:30 AM Order Cores By Seniority (0.0060s) 12/21/2020 8:43:30 AM ArcenAssetBundleCache.InstantiatedObjects: 1067 12/21/2020 8:43:30 AM Make Factions That Extra Bit Special (0.0110s) 12/21/2020 8:43:30 AM Final Checks (0.0989s) 12/21/2020 8:43:30 AM Load Historical Documents (0.0040s) 12/21/2020 8:43:30 AM 12.9 seconds total load time. Boot up FleetOS (0.3s) Check System Logs For Rogue Intelligence (0.3s) Check For Extra Modules (0.3s) Briefly Panic (0.5s) Install Confidence Routines (0.3s) Eject And Reinsert Warp Cores (9.4s) 12/21/2020 8:43:31 AM Hello Steam user 'ScArides' 12/21/2020 8:44:32 AM Attempting Steam P2P connection to Lord Mekton. 12/21/2020 8:44:32 AM STEAM NETWORKING: P2P connection attempt with Lord Mekton 12/21/2020 8:44:33 AM STEAM NETWORKING: P2P connection success to Lord Mekton 12/21/2020 8:44:33 AM Asking to join hosted game with the name 'Arides' 12/21/2020 8:44:36 AM Start loading the world (client PlayerAccount ID will be 2) 12/21/2020 8:44:36 AM Accounts in this MP game: <color=#784f64>Willy (Host - Faction #1, Unknown Player)</color> <color=#faca16>Arides (You)</color> 12/21/2020 8:44:36 AM Loaded the world in charge of a faction. Letting the host know that worked. 12/21/2020 8:44:36 AM Multiplayer Connection Time Taken: Establishing_Connection - 1.2s 12/21/2020 8:44:36 AM Multiplayer Connection Time Taken: Sending_Profile_Name_Expansions_And_Mods - 2.8s 12/21/2020 8:46:53 AM Thread 'executionContext' is in state Running after 10 seconds, so killing it now 12/21/2020 8:46:53 AM In PerSecond_UpdateFleetData, debugCode 601 System.Threading.ThreadAbortException at Arcen.AIW2.Core.Fleet+Membership.GetCanBuildAnother (System.Boolean IncludeCrippledConsiderations, System.Int32 OverridingCapToUse, Arcen.AIW2.Core.ExtraFromStacks StackStyle) [0x000b3] in <ead8e4d2435e443ab39fc5f8a755394a>:0 at Arcen.AIW2.Core.Fleet.PerSecond_UpdateFleetData (Arcen.AIW2.Core.ArcenSimContext Context) [0x00164] in <ead8e4d2435e443ab39fc5f8a755394a>:0 12/21/2020 8:46:53 AM Thread executionContext was killed from running over time: System.Threading.ThreadAbortException at Arcen.AIW2.Core.Fleet.PerSecond_UpdateFleetData (Arcen.AIW2.Core.ArcenSimContext Context) [0x00241] in <ead8e4d2435e443ab39fc5f8a755394a>:0 at Arcen.AIW2.External.EntitySimLogicImplementation.DoWorldSecondLogic_FromSimBGThread (Arcen.AIW2.Core.ArcenSimContext Context) [0x00249] in <b18dca08de0d420eaf44874e8c76241f>:0 at Arcen.AIW2.External.EntitySimLogicImplementation.DoWorld_Second_PerSecondLogic (Arcen.AIW2.Core.ArcenSimContext Context) [0x00065] in <b18dca08de0d420eaf44874e8c76241f>:0 at Arcen.AIW2.External.EntitySimLogicImplementation.DoWorldStepLogic_FromSimBGThread (Arcen.AIW2.Core.ArcenSimContext Context) [0x00074] in <b18dca08de0d420eaf44874e8c76241f>:0 at Arcen.AIW2.External.SimExecution.Execute () [0x000ba] in <b18dca08de0d420eaf44874e8c76241f>:0 12/21/2020 8:46:53 AM Thread executionContext was killed from running over time: System.Threading.ThreadAbortException at Arcen.AIW2.External.SimExecution.Execute () [0x000d6] in <b18dca08de0d420eaf44874e8c76241f>:0 at Arcen.AIW2.External.ArcenSimPlanningContext.InnerRun () [0x0006a] in <b18dca08de0d420eaf44874e8c76241f>:0 12/21/2020 8:47:54 AM Server just informed us that it shut down. Exiting to main menu... |
|
Attaching ArcenDebugLog with trace 'per-second sim stage debug' and 'thread debug log' (this one is recorded a few seconds after the original save). Not sure if it's relevant, but when I clicked "exit to windows" from the game, it went to main menu, tooltip showed (un)loadding somewhere to 80% and then the application froze completely. After 30s I killed AI War app in the task manager - never exit on its own. Re-tried again and it closed normally, might have been unrelated. |
|
One more time with the actual file.. |
|
Attempted another multiplayer game, leaving out the "Civilian Industries" faction, but keeping the others (macrophage, risk analyzers, 3 AIs, zenith trade & dyson spheres). The threads *don't* get stuck any more, meaning the issue is most likely related / caused by civilian industries faction. That being said, there are still exceptions happening every now and then, seems related to units failing to receive orders. I'm attaching the ArcenDebugLog of this new (civilian-less) game where this shows. I'm not sure how to approach the original issue right now - on one hand it seems it's a mod-specific issue, on the other hand it doesn't seem to crash within the mod code, instead it seems to cause deadlocks. |
|
Both of the original logs you sent had a stack trace from the abort that was in here: at Arcen.AIW2.Core.Fleet.PerSecond_UpdateFleetData (Arcen.AIW2.Core.ArcenSimContext Context) [0x00241] in <ead8e4d2435e443ab39fc5f8a75539 The second one was actually in this sub-function: at Arcen.AIW2.Core.Fleet+Membership.GetCanBuildAnother (System.Boolean IncludeCrippledConsiderations, System.Int32 OverridingCapToUse, Arcen.AIW2.Core.ExtraFromStacks StackStyle) [0x000b3] in <ead8e4d2435e443ab39fc5f8a755394a>:0 Meaning it's highly probable that it's possible to get an infinite loop in this central method on multiplayer clients under certain conditions. I am guessing that civilian industries just happens to be creating the situation that makes this possible, but that's not a bug in civilian industries itself (probably). Should be fixable! This is actually quite good news and good data, it's just what I was hoping for. Thanks! |
|
I can reliably duplicate the issue! Should have an answer on it shortly. Thanks for the savegame! |
|
Got it! * Fixed an infinite loop that would happen on multiplayer clients when certain unit types were used that build more units based on some sort of build points that they accumulate over time. Essentially the Von Neumann type ships, among a few others. Various base game units and mods use these mechanics, and it would be triggered by any of them. This is logic that should never be run on the client or else it leads to an infinite loop since it would never actually add ships on the client. Now it properly ignores that whole bit of logic on the client, just letting the host manage it instead. |
Date Modified | Username | Field | Change |
---|---|---|---|
Dec 17, 2020 3:03 am | Arides | New Issue | |
Dec 17, 2020 3:03 am | Arides | File Added: WEEE.savemet | |
Dec 17, 2020 3:03 am | Arides | File Added: WEEE.save | |
Dec 17, 2020 3:21 am | BadgerBadger | Note Added: 0060021 | |
Dec 17, 2020 3:23 am | Arides | Note Added: 0060022 | |
Dec 17, 2020 3:33 am | Arides | Note Added: 0060023 | |
Dec 17, 2020 3:39 am | Arides | Note Added: 0060024 | |
Dec 17, 2020 2:02 pm | BadgerBadger | Assigned To | => Chris_McElligottPark |
Dec 17, 2020 2:02 pm | BadgerBadger | Status | new => assigned |
Dec 17, 2020 5:07 pm | Chris_McElligottPark | Note Added: 0060049 | |
Dec 17, 2020 5:07 pm | Chris_McElligottPark | Note Added: 0060050 | |
Dec 17, 2020 5:08 pm | Chris_McElligottPark | Relationship added | related to 0024207 |
Dec 17, 2020 7:15 pm | ParadoxSong | Note Added: 0060065 | |
Dec 17, 2020 7:16 pm | ParadoxSong | Note Added: 0060066 | |
Dec 18, 2020 5:07 am | Arides | Note Added: 0060069 | |
Dec 18, 2020 11:36 am | Chris_McElligottPark | Note Added: 0060078 | |
Dec 21, 2020 2:52 am | Arides | File Added: ArcenDebugLog.txt | |
Dec 21, 2020 2:52 am | Arides | File Added: WEEE_be_continued.savemet | |
Dec 21, 2020 2:52 am | Arides | File Added: WEEE_be_continued.save | |
Dec 21, 2020 2:52 am | Arides | Note Added: 0060100 | |
Dec 21, 2020 3:05 am | Arides | Note Added: 0060101 | |
Dec 21, 2020 3:06 am | Arides | File Added: ArcenDebugLog-2.txt | |
Dec 21, 2020 3:06 am | Arides | Note Added: 0060102 | |
Dec 21, 2020 7:24 am | Arides | File Added: ArcenDebugLog-3.txt | |
Dec 21, 2020 7:24 am | Arides | Note Added: 0060103 | |
Dec 21, 2020 10:44 am | Chris_McElligottPark | Note Added: 0060106 | |
Dec 21, 2020 11:46 am | Chris_McElligottPark | Note Added: 0060110 | |
Dec 21, 2020 11:55 am | Chris_McElligottPark | Status | assigned => resolved |
Dec 21, 2020 11:55 am | Chris_McElligottPark | Resolution | open => fixed |
Dec 21, 2020 11:55 am | Chris_McElligottPark | Fixed in Version | => 2.708 Mapgen For Multiplayer |
Dec 21, 2020 11:55 am | Chris_McElligottPark | Note Added: 0060111 |