I can't access my dedicated server

Started by Cybermind, July 08, 2015, 09:49:08 AM

Cybermind

I tried setting up a dedicated server. I can access it locally but not through my WAN IP. I portforwarded, I tried setting my server as DMZ host in my router, I tried disabling all firewalls, nothing worked :-(

ai_enabled

#1
Hello!
Could anybody from Internet access your game server? I've noticed on my home PC that the game server is inaccessible by some reason if I connect to it from the same PC using my ISP IP address, but for other players it works fine.
If still no luck, maybe the router cannot properly port forward UDP port 5000 or ISP blocking UDP traffic (however, it will affect a lot of games using UDP)...
There may be errors on the server side also. Could you post the server log please?
Regards!

Cybermind

9.7.15 09:49:11.8686 [IMP] Log file opened. Time UTC offset is: 02:00:00
9.7.15 09:49:11.8696 [IMP] Console logging enabled
9.7.15 09:49:11.8736 [INF] VoidExpanse Game Server Runtime v1.4.8 (running on Windows)
AtomicTorch Studio (c) 2013-2015 | atomictorch.com
All rights reserved.
9.7.15 09:49:11.8746 [IMP] The server is now launched as a non-dedicated server. All server data will be loaded and processed from the user Documents folder.
If you want to start the server in a dedicated mode, please run it with "--dedicated" command line argument.
9.7.15 09:49:11.8776 [IMP] Data folders locations:
   * Static data root path:  C:\
   * Dynamic data root path: C:\Users\MegaPixel One\Documents\AtomicTorchStudio\VoidExpanse
   * Settings file location: C:\Users\MegaPixel One\Documents\AtomicTorchStudio\VoidExpanse\SettingsServer.xml
9.7.15 09:49:11.8776 [INF] Enter additional arguments line
("new" for new world, "load <Number>" to load world #<Number>, "check" to check mods)
9.7.15 09:49:14.9996 [IMP] Operations timed using the system's high-resolution performance counter.
  Timer is accurate within 69 nanoseconds
  Timer frequency in ticks per second = 14318180
9.7.15 09:49:15.0206 [IMP] Current log severity: Important
9.7.15 09:49:15.0186 [IMP] Settings parsing error: unknown setting: networksetting_buffer_size
9.7.15 09:49:15.0186 [IMP] Settings parsing error: unknown setting: networksetting_max_data_packet_size
9.7.15 09:49:15.0186 [IMP] The settings file loaded successfully
9.7.15 09:49:15.1406 [IMP] Command binding completed successfully. Total binded commands count: 281.
9.7.15 09:49:15.2176 [IMP] Server icon size: 1539 bytes. Hash: 1bdljnq1uydmjyhbosowvfnendptg0wf/lgma3uqqtg=
9.7.15 09:49:15.2196 [IMP] Starting network server...
9.7.15 09:49:15.2436 [IMP] MasterServerClient: SocketClient: Socket-client trying to connect to: 69.162.166.150:4003 (UDP)
Connecting timeout: 5s | Connection timeout: 25s
9.7.15 09:49:15.3656 [IMP] SocketServerUDP: Socket-server listening on 0.0.0.0:5000 (UDP)
Connection timeout: 60s | Maximum network connections (with extra slots): 32
9.7.15 09:49:15.3656 [IMP] Network server params: compression is disabled
9.7.15 09:49:15.3696 [IMP] Core folder: "C:\Core"
Mods folder: "C:\Users\MegaPixel One\Documents\AtomicTorchStudio\VoidExpanse\Mods"
9.7.15 09:49:15.4236 [IMP] Active Mods list:
  * core - ClientServer v1.0.0 - Core Mod
9.7.15 09:49:15.4276 [IMP] Virtual file system init with core mod file path:
C:\Core\core.cpk
Mods file paths:
(none)
9.7.15 09:49:15.4466 [IMP] MasterServerClient: SocketClient: Socket-client connected to: 69.162.166.150:4003 (UDP)
9.7.15 09:49:15.4466 [IMP] MasterServerClient: Connection to Master Server atomictorch.com:4003 established successfully
9.7.15 09:49:15.4596 [IMP] Virtual file system initialized successfully:
Core mod: core
Mods list:
   --no mods--
Total files count: 2558
9.7.15 09:49:15.5546 [IMP] Cache root path: C:\Users\MegaPixel One\AppData\Local\Temp\AtomicTorchStudio\VoidExpanse
9.7.15 09:49:15.5546 [IMP] Reloading XML data for XmlLanguagesProvider. Data validation is: disabled
9.7.15 09:49:15.5656 [IMP] Xml data loading result: success
Loaded objects types:
languagedefinitions: 2

9.7.15 09:49:15.5686 [IMP] Stopwatch Init virtual file system: 143.95ms
9.7.15 09:49:15.7066 [IMP] Current language: en_us
9.7.15 09:49:15.7586 [IMP] Stopwatch localize xmls: 51.36ms
9.7.15 09:49:15.7596 [IMP] Localization: total 93 XML files localized
9.7.15 09:49:15.7746 [IMP] Reloading XML data for XmlDataProvider. Data validation is: disabled
9.7.15 09:49:15.9546 [IMP] Stopwatch loading xmls: 170.83ms
9.7.15 09:49:15.9586 [IMP] Xml data loading result: success
Loaded objects types:
asteroids: 6
characters: 9
skills: 111
itemboosters: 15
itemconsumables: 8
itemdevices: 14
itemengines: 8
itemfueltanks: 6
itemgenerators: 7
itemgrapplers: 5
itemhulls: 35
itemstatics: 18
itemresources: 12
itemradars: 6
itemrcss: 6
itemshields: 12
itemweapons: 62
spacestations: 5
jumpgates: 1
trails: 14
spaceobjects: 9
topics: 72
npctypes: 75
crates: 3
visualeffects: 7
decorations: 4
itemlists: 23
factions: 6
playlists: 24
specialobjects: 5

9.7.15 09:49:16.0076 [IMP] Initializing ScriptManager
9.7.15 09:49:18.4336 [IMP] Stopwatch ScriptManager [parallel] Init AI scripts: 2423.39ms
9.7.15 09:49:18.4566 [IMP] data/scripts/global/calculateship.js: -- IMCache lib initialized
9.7.15 09:49:18.6906 [IMP] Stopwatch ScriptManager [parallel] load scripts global: 1683.79ms
9.7.15 09:49:18.8356 [IMP] Stopwatch ScriptManager [parallel] init Internal scripts: 401.98ms
9.7.15 09:49:19.4556 [IMP] Stopwatch ScriptManager [parallel] load scripts topics: 764.37ms
9.7.15 09:49:19.5036 [IMP] Stopwatch ScriptManager init (total): 3545.75ms
9.7.15 09:49:19.6156 [IMP] Stopwatch Devices & special objects scripts init (total): 112.09ms
9.7.15 09:49:19.6356 [IMP] Creating new world with params:
   seed = 883839358
   difficulty = 0
   galaxy_size = 127
   death_money_loss = 10
   inventory_loss = 1
   ship_loss = 0
   permadeath = 0
   exp_bonus = 0
9.7.15 09:49:19.6426 [IMP] Stopwatch Server re-init scripts (total): 0.39ms
9.7.15 09:49:19.6646 [IMP] data/scripts/internal/generategalaxy.js: Creating galaxy with 74 systems. Seed is: 883839358
9.7.15 09:49:19.6676 [IMP] World building phase: Generating systems
9.7.15 09:49:19.7136 [IMP] World building phase: Generating links
9.7.15 09:49:19.7546 [IMP] World building phase: Generating factions
9.7.15 09:49:19.7746 [IMP] data/scripts/internal/generategalaxy.js: Faction aliens must have num of stars 30
9.7.15 09:49:19.7746 [IMP] data/scripts/internal/generategalaxy.js: Faction fanatics must have num of stars 3
9.7.15 09:49:19.7746 [IMP] data/scripts/internal/generategalaxy.js: Faction freedom must have num of stars 4
9.7.15 09:49:19.7746 [IMP] data/scripts/internal/generategalaxy.js: Faction order must have num of stars 4
9.7.15 09:49:19.7746 [IMP] data/scripts/internal/generategalaxy.js: Faction pirates must have num of stars 2
9.7.15 09:49:19.7746 [IMP] data/scripts/internal/generategalaxy.js: GenerateFactions: Try 0
9.7.15 09:49:19.8146 [IMP] data/scripts/internal/generategalaxy.js: At the beginning all factions has their capitals:
9.7.15 09:49:19.8146 [IMP] data/scripts/internal/generategalaxy.js: aliens capital is 54
9.7.15 09:49:19.8146 [IMP] data/scripts/internal/generategalaxy.js: fanatics capital is 52
9.7.15 09:49:19.8146 [IMP] data/scripts/internal/generategalaxy.js: freedom capital is 56
9.7.15 09:49:19.8146 [IMP] data/scripts/internal/generategalaxy.js: order capital is 81
9.7.15 09:49:19.8146 [IMP] data/scripts/internal/generategalaxy.js: pirates capital is 43
9.7.15 09:49:19.8206 [IMP] data/scripts/internal/generategalaxy.js: GenerateFactions: Try 0 was successful
9.7.15 09:49:19.8356 [IMP] data/scripts/internal/generategalaxy.js: Start opening blocked by alies systems
9.7.15 09:49:19.8366 [ERR] data/scripts/internal/generategalaxy.js: Set system Meraren faction to none
9.7.15 09:49:19.8376 [IMP] data/scripts/internal/generategalaxy.js: End opening blocked by alies systems
9.7.15 09:49:19.8376 [IMP] World building phase: Calculating levels
9.7.15 09:49:19.8656 [IMP] World building phase: Generating system objects
9.7.15 09:49:22.6056 [IMP] World building phase: Final preparations
9.7.15 09:49:22.6096 [IMP] Scope distance set to 33.00
9.7.15 09:49:22.7736 [IMP] New world created successfully
9.7.15 09:49:22.7776 [IMP] Stopwatch Server re-init scripts (total): 2.75ms
9.7.15 09:49:22.7786 [IMP] World initialized with 0 players, 74 star systems, 8444 asteroids, 1122 ships, 31 bases, 185 jumpgates, 7058 spaceObjects, 191 specialObjects, 263 containers, 74 stars, 224 planets.
Difficulty: Normal
9.7.15 09:49:22.7836 [IMP] Saving...
9.7.15 09:49:23.6546 [IMP] Saving: world snapshot ready. Writing it on the disk...
9.7.15 09:49:23.6576 [IMP] Server FPS set to 40
Ship params update fps is 7, so it called every 5 frame(s)
Network physics updates to clients fps is 20, so it called every 2 frame(s)
9.7.15 09:49:23.6906 [IMP] MasterServerClient: Received Command MasterSetupEncryption (ID=34023)
9.7.15 09:49:23.6936 [IMP] MasterServerClient: Sending Command MasterSetupEncryptionResult (ID=3)
9.7.15 09:49:24.2056 [IMP] World successfully saved to slot_0 (path "C:\Users\MegaPixel One\Documents\AtomicTorchStudio\VoidExpanse\Saves_Multiplayer\slot_0")
9.7.15 09:49:24.7276 [IMP] MasterServerClient: Received Command MasterReady (ID=34028)
9.7.15 09:49:24.7276 [IMP] MasterServerClient: MasterServer client ready to work
9.7.15 09:49:24.7286 [IMP] SocketServerUDP: UPnP is unavailable for port forwarding
9.7.15 09:49:54.3956 [IMP] Server performance stats:
frame_length_ms=25
frame_length_worse_ms=25.19
network_processing_ms=0.01
network_rate_receive=0
pathfinder=0.01
total_memory_gc_mb=120.04
total_memory_process_mb=155.39
total_ms=0.09
9.7.15 09:50:01.0916 [IMP] SocketServerUDP: ++ Opened connection. Total connections: 1
192.168.1.53:64011; 1
9.7.15 09:50:01.1086 [IMP] Connection established
192.168.1.53:64011; 1
9.7.15 09:50:01.7466 [IMP] SocketServerUDP: -- Closed connection. Total connections: 0
192.168.1.53:64011; 1
9.7.15 09:50:01.7536 [IMP]  left the game (disconnected).
192.168.1.53:64011; 1
9.7.15 09:50:24.1086 [IMP] Server performance stats:
frame_length_ms=24.75
frame_length_worse_ms=25.06
network_processing_ms=0.02
network_rate_receive=0
pathfinder=0.01
total_memory_gc_mb=120.12
total_memory_process_mb=155.39
total_ms=0.1

Cybermind

I cut out some not important stuff from the log or else I could not post. My friend can't connect from other IP address either :-(

ai_enabled

Thanks for the log. It looks normal except the "Connection established" part - somebody connected and instantly disconnected.
Could you please launch the server, connect to it by WAN IP-adress (two times to be sure and collect enough log information) and post the log there?
You could skip beginning of the log until "World successfully saved to slot_0 (path "C:\Users\MegaPixel One\Documents\AtomicTorchStudio\VoidExpanse\Saves_Multiplayer\slot_0")").

Cybermind

10.7.15 11:00:20.0086 [IMP] World successfully saved to slot_0 (path "C:\Users\MegaPixel One\Documents\AtomicTorchStudio\VoidExpanse\Saves_Multiplayer\slot_0")
10.7.15 11:00:20.5476 [IMP] MasterServerClient: Received Command MasterReady (ID=47048)
10.7.15 11:00:20.5476 [IMP] MasterServerClient: MasterServer client ready to work
10.7.15 11:00:20.5486 [IMP] SocketServerUDP: UPnP is unavailable for port forwarding
10.7.15 11:00:50.1466 [IMP] Server performance stats:
frame_length_ms=24.65
frame_length_worse_ms=25.04
network_processing_ms=0.01
network_rate_receive=0
pathfinder=0
total_memory_gc_mb=119.65
total_memory_process_mb=151.39
total_ms=0.07
10.7.15 11:01:19.8186 [IMP] Server performance stats:
frame_length_ms=24.6
frame_length_worse_ms=25.05
network_processing_ms=0.01
network_rate_receive=0
pathfinder=0
total_memory_gc_mb=119.7
total_memory_process_mb=151.39
total_ms=0.08
10.7.15 11:01:20.0846 [IMP] TradeSystem: prices updated
10.7.15 11:01:49.5296 [IMP] Server performance stats:
frame_length_ms=24.62
frame_length_worse_ms=25.09
network_processing_ms=0.01
network_rate_receive=0
pathfinder=0.01
total_memory_gc_mb=119.79
total_memory_process_mb=151.39
total_ms=0.05
10.7.15 11:02:08.5846 [IMP] SocketServerUDP: ++ Opened connection. Total connections: 1
192.168.1.53:58442; 1
10.7.15 11:02:08.5976 [IMP] Connection established
192.168.1.53:58442; 1
10.7.15 11:02:09.2916 [IMP] SocketServerUDP: -- Closed connection. Total connections: 0
192.168.1.53:58442; 1
10.7.15 11:02:09.3136 [IMP]  left the game (disconnected).
192.168.1.53:58442; 1
10.7.15 11:02:19.1996 [IMP] Server performance stats:
frame_length_ms=24.87
frame_length_worse_ms=25.7
network_processing_ms=0.01
network_rate_receive=0
pathfinder=0.01
total_memory_gc_mb=119.76
total_memory_process_mb=151.39
total_ms=0.05
10.7.15 11:02:20.0596 [IMP] TradeSystem: prices updated
10.7.15 11:02:48.8176 [IMP] Server performance stats:
frame_length_ms=24.72
frame_length_worse_ms=25.48
network_processing_ms=0.01
network_rate_receive=0
pathfinder=0.01
total_memory_gc_mb=119.69
total_memory_process_mb=151.39
total_ms=0.07
10.7.15 11:03:18.5176 [IMP] Server performance stats:
frame_length_ms=24.7
frame_length_worse_ms=25.18
network_processing_ms=0.01
network_rate_receive=0
pathfinder=0.01
total_memory_gc_mb=119.74
total_memory_process_mb=151.39
total_ms=0.07
10.7.15 11:03:20.0736 [IMP] TradeSystem: prices updated
10.7.15 11:03:42.8136 [IMP] SocketServerUDP: ++ Opened connection. Total connections: 1
192.168.1.53:56282; 2
10.7.15 11:03:42.8336 [IMP] Connection established
192.168.1.53:56282; 2
10.7.15 11:03:43.4776 [IMP] SocketServerUDP: -- Closed connection. Total connections: 0
192.168.1.53:56282; 2
10.7.15 11:03:43.4786 [IMP]  left the game (disconnected).
192.168.1.53:56282; 2
10.7.15 11:03:48.2046 [IMP] Server performance stats:
frame_length_ms=24.63
frame_length_worse_ms=25.41
network_processing_ms=0.01
network_rate_receive=0
pathfinder=0.01
total_memory_gc_mb=120.61
total_memory_process_mb=151.39
total_ms=0.08
10.7.15 11:04:17.8796 [IMP] Server performance stats:
frame_length_ms=24.67
frame_length_worse_ms=25.04
network_processing_ms=0.01
network_rate_receive=0
pathfinder=0
total_memory_gc_mb=87.51
total_memory_process_mb=151.39
total_ms=0.04

Cybermind

I posted the log. It seems as the connection attempt is when the game is retrieving information about the server and not an actual log-in attempt.

Cybermind

I just tried starting the dedicated server with my batch file instead of the dedicated server executeable and then I could connect through my WAN IP :-) My batch is like this: VoidExpanse.Server.exe --dedicated -load 0

ai_enabled

Cybermind, I'm glad it works now. We're going to improve our Wiki to make it clear that it's better to host dedicated server and you need to run it with "--dedicated" flag.
Regards!