alliedmodders / sourcemod

SourceMod - Source Engine Scripting and Administration
http://www.sourcemod.net/
974 stars 422 forks source link

Crash on valve profiler start #1162

Closed dragokas closed 3 years ago

dragokas commented 4 years ago

Environment

Description

Instant crash on profiler start

Problematic Code (or Steps to Reproduce)

sm prof start

Logs

https://crash.limetech.org/iegfnbd63krb

Related topics: https://forums.alliedmods.net/showpost.php?p=2424898&postcount=8

peace-maker commented 4 years ago

I don't see anything related to profiling in that stack trace. Are you entering sm prof start directly in the server console or use some plugin/command like sm_rcon? There were issues when starting profiling while a plugin was executing code before. https://github.com/alliedmodders/sourcepawn/pull/316

dragokas commented 4 years ago

Executed directly in RCON console.

More crash logs from SilverShot:

Win L4D2: Hibernating: https://crash.limetech.org/mhbu6vw4dhdt Active bots: https://crash.limetech.org/gi5p4kqyxn6d

Win L4D1: Hibernating: https://crash.limetech.org/wlo435mwz2x4 Active bots: https://crash.limetech.org/zs3zuzc6vjvu

dragokas commented 4 years ago

L4D2 linux: https://crash.limetech.org/ns7gkon2wlfz https://www.dropbox.com/s/33d354sgipk8kjg/rcon.jpg?dl=0

CSGO windows - no crash

dragokas commented 3 years ago

Managed to find a reason.

Write in RCON:

vprof_on

Now

sm prof start vprof

will no longer crash in L4d1/2 games.

Can it be implemented in sm?

asherkin commented 3 years ago

vprof_on uses the same mechanism to start profiling as sm prof start vprof, g_VProfCurrentProfile.Start().

However, it looks like vprof_on (and a bunch of the other vprof_* commands) use a hack to defer executing the command callback to an engine function called PreUpdateProfile. I suspect the root issue here is that VProf in L4D(2) is particularly allergic to being started in the middle of a node (hence the crash in CVProfNode::ExitScope).

It would probably make sense for SM to call the vprof console commands rather than using g_VProfCurrentProfile (apart from possibly the dump output, where I believe there is no equivalent console command for the full report we emit) - we don't actually care when it is started or not I don't think, so the exact timing doesn't matter, we only have our own commands to avoid paying the cost in SourcePawn execution.

dragokas commented 3 years ago

Please, also pay attention, that according to my test:

ServerCommand("vprof_on; sm prof start vprof");

is not enough to prevent the crash.

It requires 1 frame delay at least:

{
...
    ServerCommand("vprof_on");
    ServerExecute();
    RequestFrame(OnFrameDelay);
}
public void OnFrameDelay()
{
    ServerCommand("sm prof start vprof");
    ServerExecute();
}

works ok for me.

asherkin commented 3 years ago

It requires 1 frame delay at least:

Yes, because otherwise you're not waiting for vprof_on's deferred execution in PreUpdateProfile.

dragokas commented 3 years ago

Just trapped to another crash "Alarm clock" because engine sometimes requires too many time to dump all the huge stack info to the file. Is there a way to increase that watchdog timer?

peace-maker commented 3 years ago

You can disable it using -nowatchdogon the srcds command line. You'll need an extension to increase the time.