[Dedicated server + Client] [High Prio?] Apply previous saved build crashes UI

[BattleOn]

Hi,

 

This bug involves a dedicated server to be reproduced.

 

Steps to reproduce

• Start the client (Avorion Client Beta 0.15 r9816)
  
• Go to multiplayer -> join via IP
  
• (optional) add a new server with IP 82.95.193.27
  
• Join the server
  
• Found a ship and go into build modus
  
• Modify a few things to get multiple "Saved builds"
  
• Exit build modus
  
• Exit to the drone and found a new ship
  
• Found a new ship and apply a saved build <-- THE BUG IS NOW ACTIVE
  

 

Now, you can't do anything with the UI anymore. The bug involves the whole (or portions) of the UI including the following:

 

• Jumping to other systems by setting a destination (the latter is mainly the problem)
  
• Build or modify your ship
  
• Assign crew or accessing any other features in submenu's like the Player Menu and Ship Menu
  
• Exit the drone
  

 

These are just a few things of the potential many that there are. The game suddenly becomes useless.

 

The work around we use to fix the problem is the following:

 

[*]Exit the game

[*]Exit steam

[*]Start the game

[*]Join the server

[*]Try to move

 

If you can move, the problem is fixed. If not, you need to redo all steps multiple times. Last but not least, if that also does not work (and it happens if the UI is really, REALLY bugged), a server restart mysteriously FIXES the problem. This might (and this is just an assumption) have to relate to the face that it might be related with server cache and/or the location of the user, since the server does not have persisted the data (it does this every 10 minutes I believe). After the server restart, everyone is a few minutes back in time.

 

Feel free to use the previously provided server to test this bug on. The server runs 24/7/365.

 

Client Logs:

2017-11-24 00-22-56| Client started: "G:\Steam\steamapps\common\Avorion\bin\Avorion.exe" "--serverpath=bin/AvorionServer.exe"
2017-11-24 00-22-56| Enabled Traces:
2017-11-24 00-22-56| Client Beta 0.15 r9816, running on Windows 8.1+.
2017-11-24 00-22-56| CPU: AuthenticAMD 32 Cores
2017-11-24 00-22-56| RAM: 32GB
2017-11-24 00-22-56| Init Steamworks...Installed Steam exception handler
2017-11-24 00-22-56| Init Steamworks... ok
2017-11-24 00-22-56| Init Steamworks ok
2017-11-24 00-22-56| Init SDL2... ok
2017-11-24 00-22-56| SDL version (compiled): 2.0.3
2017-11-24 00-22-56| SDL version (linked): 2.0.3
2017-11-24 00-22-56| Getting display mode... ok
2017-11-24 00-22-56| Current display mode: 3440 x 1440
2017-11-24 00-22-56| Creating settings... loading... setting language... ok
2017-11-24 00-22-56| Creating client window...Creating window ...
2017-11-24 00-22-56| Detected 2 displays
2017-11-24 00-22-56| Display 0: x: 0, y: 0, w: 3440, h: 1440
2017-11-24 00-22-56| Display 1: x: -1920, y: 347, w: 1920, h: 1080
2017-11-24 00-22-56| Using display 0
2017-11-24 00-22-56| Trying to create OpenGL 4.1 core window ...
2017-11-24 00-22-56| Creating window, x: 0, y: 0, w: 2560, h: 1080... ok
2017-11-24 00-22-56| Creating GL context... ok
2017-11-24 00-22-57| Setting display mode 2560 x 1080 (Windowed)... ok
2017-11-24 00-22-57| GetDrawableSize: 2560 1080
2017-11-24 00-22-57| GetWindowSize: 2560 1080
2017-11-24 00-22-57| Creating client window ok
2017-11-24 00-22-57| Init rendering... starting rendering... initialize...Init GLEW... ok
2017-11-24 00-22-57| OpenGL Context Information:
2017-11-24 00-22-57| Version: 4.1
2017-11-24 00-22-57| VersionString: 4.1.0 NVIDIA 388.13
2017-11-24 00-22-57| Vendor: NVIDIA Corporation
2017-11-24 00-22-57| Renderer: GeForce GTX 960/PCIe/SSE2
2017-11-24 00-22-57| GLSL Version: 4.10 NVIDIA via Cg compiler
2017-11-24 00-22-57| GL_MAX_CUBE_MAP_TEXTURE_SIZE: 16384
2017-11-24 00-22-57| GL_MAX_ELEMENTS_INDICES: 1048576
2017-11-24 00-22-57| GL_MAX_ELEMENTS_VERTICES: 1048576
2017-11-24 00-22-57| GL_MAX_RENDERBUFFER_SIZE: 16384
2017-11-24 00-22-57| GL_MAX_TEXTURE_SIZE: 16384
2017-11-24 00-22-57| GL_MAX_VERTEX_ATTRIBS: 16
2017-11-24 00-22-57| GL_MAX_VERTEX_TEXTURE_IMAGE_UNITS: 32
2017-11-24 00-22-57| Init Debug Message Callback... ok
2017-11-24 00-22-57| Set VSync... ok
2017-11-24 00-22-57| Secure BackBuffer... ok
2017-11-24 00-22-57| Init Canvas...Create canvas of size 2560 x 1080... ok
2017-11-24 00-22-57| Init Canvas ok
2017-11-24 00-22-57| Init Refraction Texture... ok
2017-11-24 00-22-57| Init Post Processing... ok
2017-11-24 00-22-57| Init Debug Renderers... ok
2017-11-24 00-22-57| DepthTexturesSupported: yes
2017-11-24 00-22-57| IntVertexAttributesSupported: yes
2017-11-24 00-22-57| DeferredSupported: yes
2017-11-24 00-22-57| LowSpecGPUDetected: no
2017-11-24 00-22-57| Rendering initialized
2017-11-24 00-22-57| Init rendering ok
2017-11-24 00-22-57| Check problematic drivers... ok
2017-11-24 00-22-57| Init shader level... ok
2017-11-24 00-22-57| Init loading screen... ok
2017-11-24 00-22-57| Draw first loading screen... draw... ok
2017-11-24 00-22-57| Init SFX... ok
2017-11-24 00-22-57| Init Input... ok
2017-11-24 00-22-57| Init GameInput... ok
2017-11-24 00-22-57| Init WorkerPool... ok
2017-11-24 00-22-57| Init Main Menu... ok
2017-11-24 00-22-59| Init Music... ok
2017-11-24 00-22-59| Apply loaded settings... ok
2017-11-24 00-22-59| Adjust settings to GPU... ok
2017-11-24 00-22-59| Client initialized
2017-11-24 00-22-59| Received stats and achievements from Steam
2017-11-24 00-22-59| STAT_PIRATES_DESTROYED: 57i
2017-11-24 00-22-59| STAT_XSOTAN_DESTROYED: 19i
2017-11-24 00-22-59| STAT_CIVIL_SHIPS_DESTROYED: 0i
2017-11-24 00-22-59| STAT_SHIPS_DESTROYED: 4i
2017-11-24 00-22-59| STAT_STATIONS_DESTROYED: 0i
2017-11-24 00-22-59| STAT_RESOURCES_MINED: 597831i
2017-11-24 00-22-59| STAT_GOODS_TRADED: 5253i
2017-11-24 00-22-59| STAT_GOODS_SOLD: 3300i
2017-11-24 00-22-59| STAT_GOODS_BOUGHT: 1953i
2017-11-24 00-22-59| STAT_GATES_USED: 30i
2017-11-24 00-22-59| STAT_WORMHOLES_USED: 26i
2017-11-24 00-22-59| STAT_JUMPS_USED: 479i
2017-11-24 00-22-59| STAT_SECTORS_DISCOVERED: 310i
2017-11-24 00-22-59| STAT_SECTORS_TRAVELED: 6483.73f
2017-11-24 00-22-59| STAT_METERS_FLOWN: 15349862i
2017-11-24 00-23-00| Startup successful.
2017-11-24 00-23-05| Connecting to 86.91.195.22:27000, query port: 27003
2017-11-24 00-23-06| Waiting for Online polling threads
2017-11-24 00-23-06| UDP closed
2017-11-24 00-23-06| Client UDP: Connection closed
2017-11-24 00-23-06| Online polling threads finished
2017-11-24 00-23-06| Waiting for LAN polling threads
2017-11-24 00-23-06| LAN polling threads finished
2017-11-24 00-23-06| remote address: ip, init: steam
2017-11-24 00-23-06| Connecting to server at 86.91.195.22:27000
2017-11-24 00-23-06| Initiating connection with server ID 90112052227239945
2017-11-24 00-23-10| Querying for an authentication session ticket
2017-11-24 00-23-10| Authentication successful!
2017-11-24 00-23-14| <Server> Player Nick joined the galaxy
2017-11-24 00-24-20| periodic payments: true
2017-11-24 00-24-41| UDP closed
2017-11-24 00-24-41| Client UDP: Connection closed
2017-11-24 00-24-41| Startup successful.
2017-11-24 00-26-57| Exited client main loop.
2017-11-24 00-26-57| Waiting for Online polling threads
2017-11-24 00-26-57| Online polling threads finished
2017-11-24 00-26-57| Waiting for LAN polling threads
2017-11-24 00-26-57| LAN polling threads finished
2017-11-24 00-26-57| Stopping local server ...

 

Server logs:

24-11-2017 00:29:48 Redirecting stderr to '/root/Steam/logs/stderr.txt'
24-11-2017 00:29:48 [  0%] Checking for available updates...
24-11-2017 00:29:49 [----] Verifying installation...
24-11-2017 00:29:49 Steam Console Client (c) Valve Corporation
24-11-2017 00:29:49 -- type 'quit' to exit --
24-11-2017 00:29:49 Loading Steam API...OK.
24-11-2017 00:29:49
24-11-2017 00:29:51 Connecting anonymously to Steam Public...Logged in OK
24-11-2017 00:29:51 Waiting for user info...OK
24-11-2017 00:29:52 Update state (0x5) validating, progress: 4.50 (4194304 / 93199001)
24-11-2017 00:29:53 Success! App '565060' fully installed.
24-11-2017 00:29:53 Enabled Traces:
24-11-2017 00:29:53 Avorion server Beta 0.15 r9816 running on Ubuntu 14.04.5 LTS starting up in "/root/.avorion/galaxies/avorion_galaxy"
24-11-2017 00:29:53 CPU: AMD FX(tm)-8350 Eight-Core Processor 8 Cores
24-11-2017 00:29:53 RAM: 15GB
24-11-2017 00:29:53 name: Alfa Swek - Dedicated Server
24-11-2017 00:29:53 seed: l8Z4s0hDzxT
24-11-2017 00:29:53 port: 27000
24-11-2017 00:29:53 max online players: 10
24-11-2017 00:29:53 save interval: 120
24-11-2017 00:29:53 broadcast interval: 2
24-11-2017 00:29:53 max loaded sector time: 600
24-11-2017 00:29:53 weak update: yes
24-11-2017 00:29:53 worker threads: 4
24-11-2017 00:29:53 generator threads: 4
24-11-2017 00:29:53 script background threads: 4
24-11-2017 00:29:53 difficulty: Easy
24-11-2017 00:29:53 infiniteResources: no
24-11-2017 00:29:53 collision: 0.25
24-11-2017 00:29:53 access list: Blacklist
24-11-2017 00:29:53 public: yes
24-11-2017 00:29:53 authentication: yes
24-11-2017 00:29:53 listed: no
24-11-2017 00:29:53 steam networking: yes
24-11-2017 00:29:53 administrators: 'nobody' 'STEAM_0:1:28073575' 'admin'
24-11-2017 00:29:53 Initializing sector database...
24-11-2017 00:29:53 Initializing faction database...
24-11-2017 00:29:53 Starting up 4 worker threads...
24-11-2017 00:29:53 Starting up 4 script background threads...
24-11-2017 00:29:53 Loading jumping entities...
24-11-2017 00:29:53 Loading groups...
24-11-2017 00:29:53 Galaxy initialized.
24-11-2017 00:29:53 Listed server version: 0.15.0.9816
24-11-2017 00:29:53 [s_API FAIL] SteamAPI_Init() failed; SteamAPI_IsSteamRunning() failed.
24-11-2017 00:29:53 Setting breakpad minidump AppID = 445220
24-11-2017 00:29:53 Game Port: 27000
24-11-2017 00:29:53 Steam Port: 27021
24-11-2017 00:29:53 Steam Query Port: 27020
24-11-2017 00:29:53 Query Port: 27003
24-11-2017 00:29:53
24-11-2017 00:29:53 Warning: No RCON password set. RCON disabled.
24-11-2017 00:29:53 Server startup complete.
24-11-2017 00:29:54 Server connected to Steam successfully
24-11-2017 00:29:54 Server is VAC Secure!
24-11-2017 00:29:54 Game Server Steam ID: 90112064841872393
24-11-2017 00:30:18 OnP2PSessionRequest from 76561198016412879
24-11-2017 00:30:22 Steam authentication confirmed for 76561198016412879
24-11-2017 00:30:22 Authentication successful for 76561198016412879
24-11-2017 00:30:26 <Server> Player Nick joined the galaxy
24-11-2017 00:30:26 Player logged in: Nick, index: 1
24-11-2017 00:30:26 player events roughly every 11.25 minutes
24-11-2017 00:31:11 Authentication failed for user 76561198016412879. Reason: Authentication ticket was canceled.
24-11-2017 00:31:11 Authentication error for 76561198016412879: Authentication ticket was canceled.
24-11-2017 00:31:12 Ending authentication session of 76561198016412879

[BattleOn]

Just tested this issue on the beta branch and the problem exists here as well. For more details on how I setted up the server can be found here: https://github.com/NickvdMeij/avorion-docker

[BattleOn]

Just tried out the bug on a new server v0.15.2 beta branch. Problem still exists. However, it works for the first 10-20 minutes of playing, and then the bug happens again. It's an improvement, but sadly not a fix just yet

[BattleOn]

Issue still persists in the latest beta..

[Hammelpilaw]

I never had this issue. Also your logs does not fit together, the time is different. Until 00:26 for client, but server is starting at 0:29.

 

24-11-2017 00:31:11 Authentication failed for user 76561198016412879. Reason: Authentication ticket was canceled.
24-11-2017 00:31:11 Authentication error for 76561198016412879: Authentication ticket was canceled.
24-11-2017 00:31:12 Ending authentication session of 76561198016412879

 

This looks like an authentification problem, maybe a blocked port at your server? However, this causes your issue.

Try to connect to the official server, it should not happen there. At lest servers work at all so the problem is either your client or your server.

 

Maybe this will help you to solve the problem at your server:

https://avorion.gamepedia.com/Setting_up_a_server#Requirements

 

Be sure required ports are open.

The UDP and TCP ports that will be used for the game must be forwarded to the machine that runs the game. Default ports are 27000, TCP and UDP for game traffic 27003 (UDP) for queries, 27020 and 27021.

[BattleOn]

I will upload a new log tonight. The server is still online and all ports are correctly forwarded and the problem still exists.

Furthermore, the authentication error does not occur anymore, and the server does meet the requirements.

 

The server IP is 82.95.193.27, can you check if the problem exists for you?

[Hammelpilaw]

The server IP is 82.95.193.27, can you check if the problem exists for you?

 

You have to update the server to 0.16.3.

[koonschi]

If this is what I think it is, then it will be persistent over all servers, no matter the version - the build you're trying to apply is simply too complex (ie. too many blocks). How many blocks does it have, and do you have a link to the build in the steam forum?

 

You should be able to just wait it out in theory, the server might just take some time. And you can't use anything any more because the server doesn't respond for you because it's currently processing the build you've tried to upload (all builds you apply have to be uploaded first).

 

We'll add a few more warnings and safeguards in order to make this behavior clearer.

[Hammelpilaw]

If this is what I think it is, then it will be persistent over all servers, no matter the version - the build you're trying to apply is simply too complex (ie. too many blocks). How many blocks does it have, and do you have a link to the build in the steam forum?

 

You should be able to just wait it out in theory, the server might just take some time. And you can't use anything any more because the server doesn't respond for you because it's currently processing the build you've tried to upload (all builds you apply have to be uploaded first).

 

We'll add a few more warnings and safeguards in order to make this behavior clearer.

Hmm the editor lag? Did not think about it in his case.

@BattleOn, how many blocks and mass does your ship have that you try to apply?

 

[BattleOn]

If this is what I think it is, then it will be persistent over all servers, no matter the version - the build you're trying to apply is simply too complex (ie. too many blocks). How many blocks does it have, and do you have a link to the build in the steam forum?

 

You should be able to just wait it out in theory, the server might just take some time. And you can't use anything any more because the server doesn't respond for you because it's currently processing the build you've tried to upload (all builds you apply have to be uploaded first).

 

We'll add a few more warnings and safeguards in order to make this behavior clearer.

Hmm the editor lag? Did not think about it in his case.

@BattleOn, how many blocks and mass does your ship have that you try to apply?

 

 

I don't believe its server lag. Just tried to build a small ship of 8 blocks total and waited for 30 minutes, nothing. Same as before, the bug "activates" and I can't do anything.

 

Furthermore, I've kept a close eye to the server's monitoring (CPU, RAM, Network and Storage) and none of them spiked when I clicked "Apply Plan". The same thing for the client, no spikes what so ever and no details of any kind in the logs...

 

[BattleOn]

Btw, i setted the server to "Infinite Resources = true" so you guys can test. The server IP is same as before, 82.95.193.27.

 

Also tried with the following ships from the steam workspace to see if they all show the same behaviour:

 

http://steamcommunity.com/sharedfiles/filedetails/?id=1309949029

http://steamcommunity.com/sharedfiles/filedetails/?id=1296046712

http://steamcommunity.com/sharedfiles/filedetails/?id=1294372757

http://steamcommunity.com/sharedfiles/filedetails/?id=1205305955

http://steamcommunity.com/sharedfiles/filedetails/?id=1205343378

http://steamcommunity.com/sharedfiles/filedetails/?id=1227008929

http://steamcommunity.com/sharedfiles/filedetails/?id=1083421069

http://steamcommunity.com/sharedfiles/filedetails/?id=953160372

http://steamcommunity.com/sharedfiles/filedetails/?id=951708087

 

 

[koonschi]

Do you have a server log from when this happened? Applying an 8 blocks build should be done immediately, there's definitely something else going on then. Does it work when you start a different server?

[Hammelpilaw]

Just joined the server. It is not the ship-editor-lag I know... It looks like the client partially loses connection. You stay logged in, but can not do anything, the ping freezes at any number (wich means it is infinite). But still you can see npc controlled ships fly around, dock to stations or warp out. Not sure if you see new ships spawning, was not too long there.

The issue happens exactly in that moment, when you click the apply button in ship editor, does not matter if you do other stuff before or so.

 

Is it a root server? Wich specs?

 

You should provide latest logs.

[BattleOn]

I added the whole server log as attachment.

log.txt

[BattleOn]

The server spec is an old PC of mine:

 

CPU: AMD FX-8350 Eight-Core Processor

RAM: 16GB

Storage: 250GB Samsung SSD

Host OS: Ubuntu 16.04.3 LTS

Container OS: Ubuntu 14.04.3 LTS

 

Doubt that this machine is the problem, since it runs other game servers (7 days to die, Minecraft, etc) as well as Webservers (Nginx, NodeJS, PHP), Databases (Redis, MySQL, Elasticsearch) and other applications perfectly. It's just the avorion server that gives strange behaviour.

[BattleOn]

Do you have a server log from when this happened? Applying an 8 blocks build should be done immediately, there's definitely something else going on then. Does it work when you start a different server?

 

I've created the server multiple times (with and without the saved world), and i get the same result every time

[koonschi]

What you've attached is the console output, I need the logfile from your ~/.avorion/galaxies/[your galaxy] folder.

[BattleOn]

What you've attached is the console output, I need the logfile from your ~/.avorion/galaxies/[your galaxy] folder.

 

I added it as attachment ;-)

serverlog_2018-03-16_14-14-07.txt

[Hammelpilaw]

What you've attached is the console output, I need the logfile from your ~/.avorion/galaxies/[your galaxy] folder.

 

I added it as attachment ;-)

Attached is my client log file while being on the server, it looks.... interesting. The 1 hour difference should be caused by timezone settings. Had to zip it cause of size restrictions.

clientlog_2018-03-16_15-50-14.zip

[koonschi]

How large is your upstream? This looks a lot like network connectivity issues.

[BattleOn]

Here are the logs about the network usage. You can see the usage of the host itself in the attachment, and this is similar to what I saw on the modem. It doesn't seem to be that the upstream is not big enough, cause it should easily handle this load.

[koonschi]

Can you still write chat messages when this happens? Do you see your chat messages after sending them?

[BattleOn]

I tried it and i cannot send any messages. However, a friend of mine was logged in at the same time and he could chat and I saw the chat messages appear (yet i could still not send any messages)

[BattleOn]

Got the same errors in 0.16.6. In the client logs have appeared several network related errors..... 4MB of it  ::)

 

download link (since everywhere you can upload there is a size limit...): https://file.pizza/chili-olives-cumin-mozzarella (will keep the p2p open for a few hours, just tell me when you got it :))

[koonschi]

Got it, can you tell me exactly what happens again? What do you see? Are you in game or are you still on the loading screen when you try to connect?

 

There's definitely networking connectivity issues involved, you should check if your server isn't behind a firewall or in a DMZ or something like that. Because for some reason, the client thinks it's not properly connected to the server, resulting in those messages.