Games get cut off after a certain period.

[TimZaman]

GCP games get cut off around 580~582 dota_time, while local games (Mac) do not. This problem probably was always there, but never caught. Some recent assertions caught this.

Locally I can reproduce (yay!) by setting the dota_time very high. I just got locally 655 and 654 dota_time before we get a 'bad' end state. I think dota times out somehow.

[TimZaman]

Trying to add some flags to the dotaservice. Still times out around 655, 657..

[TimZaman]

Setting the host_timescale to 4 or 5 didn't change the cut-off point strangely enough; it's still ~655 dota_time locally. The walltime of full games (judged by the console) untill cut-off took:
on gcp (10x): ~2m17s
local (10x): ~2m00s
local (5x): ~2m36s
local (4x): ~3m14s

So doesn't seem to relate to the host_timescale or walltime.

[TimZaman]

It does not occur locally (tested two runs that took 16 and 12 mins) running the GUI. And it doesn't matter if i jointeam spec or not.
With 7.21c (doesn't seem to be a coincidence) it happens at 571 and 572s.

[TimZaman]

I tried without the dotaservice:

./dota.sh -dedicated -insecure +sv_lan 1 +sv_cheats 1 -console -fill_with_bots +sv_hibernate_when_empty 0 +dota_auto_surrender_all_disconnected_timeout 700 +map dota -con_timestamp

This played for a walltime of 11-13 mins;

(...)
CDOTAGCServerSystem::MatchSignOut gathering sign out stats. Duration in minutes = 11.665492
(...)
Match signout:  duration = 699 (699.929504) good guys win = 0

The good news is that this confirms that the dedicated server in principle can play for longer than the previous time, at least.

[TimZaman]

I ran this:

./dota.sh -dedicated -insecure +sv_lan 1 +sv_cheats 1 -console -fill_with_bots +sv_hibernate_when_empty 0 +dota_auto_surrender_all_disconnected_timeout 700 +map start gamemode 21 +host_timescale 10 -con_timestamp -con_logfile log.txt

Notable outputs:

(...)
Building: npc_dota_goodguys_fort destroyed at 922.201660.
(...)
CDOTAGCServerSystem::MatchSignOut gathering sign out stats. Duration in minutes = 15.370584
(...)

This means the auto surrender is indeed in walltime, and the gamemode 21 has nothing to do with this.
Starting to suspect the lua code now. Possible hiccup in the worldstates?

[TimZaman]

Confirmed, this is a problem in the dotaservice code. If I disable lua's get_new_actions it goes through fine.

[TimZaman]

I now think it relates to the size of the console logfile:
If i print out a LOT of debugging stuff in lua, it will already stall at dota_time -80. If I log 1 extra sentence per step, it stops around 300 dota_time: which is exactly the amount of 'Think' warnings that are in the log. The log is approx. 300kb.

[TimZaman]

Yep, the whole thing stalls when the logfile exceeds 300kb. E.g. set +think_limit -1 and the whole thing goes bananas, and stalls at 300kb.

[TimZaman]

Yep, when i log 2 lines in lua for every step, the log is 350kb, and the final step is around 244.
I moved from con_logfile to -condebug, but that doesn't seem to help at all. It seems like this stalling is related to the amount of writes from lua to the logfile?

[TimZaman]

The solution here is to (preferably) cut off the spam from the lines;
Script function 'Think' on bot npc_dota_hero_nevermore took 28.665ms
or to make sure the console files can grow longer. But there might be a ~300kb limit per session that's being written. Also it's entirely unclear to me still why the GUI still works past this console file limits.

[Nostrademous]

I remember a way to do this, but need to really dig through old stuff to find it.

[Nostrademous]

A few threads I see in Dota2 Scripting:

1. DOTA crashes if Steam gets disconnected for too long since 7.20ish

2. you can set many things in the autoexec.cfg for dota

log_flags "Entity Load Unserialize" "Networking Reliable" "AnimationSystem: IK" SteamUnifiedMessages NetworkServerService +donotecho
log_flags NetworkClientService EngineServiceManager EngineInitialization SoundSystemLowLevel SoundOperatorSystem modellib +donotecho
log_flags PostProcessPipeline ToolGameSimulation RenderPipelineDota SoundOpGameSystem SchemaSystemUtils NetworkP2PService +donotecho
log_flags "Combat Analyzer" SndEmitterSystem RenderPipelineVr HostStateManager DeveloperVerbose DeveloperConsole GCClient +donotecho
log_flags DOTAHLTVDirector SteamNetSockets GameEventSystem DownloadManager CustomGameCache AnimationSystem WeekendTourney +donotecho
log_flags "Entity System" VScriptScripts ResourceSystem PostProcessing PanoramaScript NetworkService MaterialSystem VProf +donotecho
log_flags DOTAHLTVCamera CustomNetTable ClientMessages AnimationGraph "Entity Dump" "BitBuf Error" WorldRenderer CustomUI +donotecho
log_flags VolumetricFog VguiCallQueue SaveRestoreIO RenderService ModelCombiner InstantReplay "HLTV Server" Server Client +donotecho
log_flags stringtables UserMessages SndOperators SchemaSystem SceneSystem RenderSystem ParticlesLib NetSteamConn Workshop +donotecho
log_flags InputService HangWatchdog AnimResource TypeManager ToneMapping SplitScreen SplitPacket SoundSystem Assert Panel +donotecho
log_flags SignonState SaveRestore InputSystem GlobalState CommandLine VScriptDbg SpawnGroup ScenePrint Networking LOADING +donotecho
log_flags MeshSystem Filesystem ServerLog Particles EmitSound DotaGuide Developer DOTA_CHAT BoneSetup Panorama Console VR +donotecho
log_flags VScript Physics NavMesh General Decals Steam Host Demo Vfx IME +donotecho // All channels muted
// Cherry-pick channels to un-mute from above
log_flags Client Networking NetSteamConn NetworkClientService NetworkService NetworkP2PService "Networking Reliable" -donotecho
log_flags Demo Developer DeveloperConsole DeveloperVerbose VScript VScriptDbg VScriptScripts PanoramaScript Panorama -donotecho
log_flags General InputService Console -donotecho // primary console output
// Some errors are spewed in the General channel, can only be silenced by setting it's verbosity to essential (losing user output)
log_verbosity Panorama Console essential; // stop DispatchAsyncEvent ..

[TimZaman]

buuh +log_verbosity VScript off' works but it supresses everything lua outputs.

[Nostrademous]

yeah, unfortunately I do not know of a way to turn of the default "timing" messages and not our own messages.

[TimZaman]

I tried a bunch and nothing works. The only thing i can think of is that I stub out calls to the `Msg` function using `LD_PRELOAD`

…

On Mon, Mar 18, 2019 at 9:53 PM Nostrademous ***@***.***> wrote: yeah, unfortunately I do not know of a way to turn of the default "timing" messages and not our own messages. — You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub <#45 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AHXSRDhg94T5aoMd5cncfmgeNnAEmJYFks5vYG05gaJpZM4b5BHs> .

[Nostrademous]

You would think they have rotating console file logs after 300k. Perhaps we are not closing the handle properly?

[TimZaman]

Just checked. Using the GUI it is fine and gets ellrl into 600kb

…

On Mon, Mar 18, 2019, 21:57 Nostrademous ***@***.***> wrote: You would think they have rotating console file logs after 300k. Perhaps we are not closing the handle properly? — You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub <#45 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AHXSRJKA0NVTy2kI2SF3Co3VkuC_1YxMks5vYG5OgaJpZM4b5BHs> .