Lack of visibility into crashpad_handler progress

[kristjanvalur]

Description

This is not strictly a bug, but a usability problem. In a docker container, we lack any visibility into the progress of crashpad_handler when uploading a crash.

When does the problem happen

In a linux container, Unreal Engine (our custom plugin using this toolkit), we log a crash handling, log that it is handed over to crashpad_handler, but it never shows up in sentry.

• During build
• During run-time
• When capturing a hard crash

Environment

• OS: Linux
• Compiler: n/a
• CMake version and config: n/a

Steps To Reproduce

In house only.

Log output

This is what we see as stdout from the unreal process:

2025-03-25T15:13:06.234Z	"i-06dcd49c07fe83fca"	"paxdei-server-ue4"	/app/docker-entrypoint.sh: info: Unreal server container exiting.
2025-03-25T15:13:06.234Z	"i-06dcd49c07fe83fca"	"paxdei-server-ue4"	/app/docker-entrypoint.sh: line 268: 22 Segmentation fault "${SERVER_EXE}" PaxDei "${PD_MAP}" -ExecCmds="${PD_CMD_LINE_EXECCMDS}" -LogCmds="${PD_CMD_LINE_LOGCMDS}" ${PD_CMD_LINE_DEFAULT_ARGS} ${PD_CMD_LINE_ARGS}
2025-03-25T15:13:06.234Z	"i-06dcd49c07fe83fca"	"paxdei-server-ue4"	Engine crash handling finished; re-raising signal 11 for the default handler. Good bye.
2025-03-25T15:13:06.234Z	"i-06dcd49c07fe83fca"	"paxdei-server-ue4"	LogExit: Executing StaticShutdownAfterError
2025-03-25T15:13:06.234Z	"i-06dcd49c07fe83fca"	"paxdei-server-ue4"	LogCore: Fatal error!0x000000000ac97960 <nonsensical stack trace>
2025-03-25T15:13:06.234Z	"i-06dcd49c07fe83fca"	"paxdei-server-ue4"	LogCore: === Critical error: ===Unhandled Exception: SIGSEGV: invalid attempt to read memory at address 0x00007f1ca329b65e
2025-03-25T15:13:06.234Z	"i-06dcd49c07fe83fca"	"paxdei-server-ue4"	CommonUnixCrashHandler: Signal=11
2025-03-25T15:13:06.234Z	"i-06dcd49c07fe83fca"	"paxdei-server-ue4"	Malloc Size=262146 LargeMemoryPoolOffset=262162
2025-03-25T15:13:06.234Z	"i-06dcd49c07fe83fca"	"paxdei-server-ue4"	Signal 11 caught.
2025-03-25T15:13:06.234Z	"i-06dcd49c07fe83fca"	"paxdei-server-ue4"	[51:51:20250325,151305.439054:ERROR file_io_posix.cc:145] open /sys/devices/system/cpu/cpu0/cpufreq/scaling_max_freq: No such file or directory (2)
2025-03-25T15:13:06.234Z	"i-06dcd49c07fe83fca"	"paxdei-server-ue4"	[51:51:20250325,151305.439007:ERROR file_io_posix.cc:145] open /sys/devices/system/cpu/cpu0/cpufreq/scaling_cur_freq: No such file or directory (2)
2025-03-25T15:13:06.234Z	"i-06dcd49c07fe83fca"	"paxdei-server-ue4"	Sentry [info] : handing control over to crashpad
2025-03-25T15:13:06.234Z	"i-06dcd49c07fe83fca"	"paxdei-server-ue4"	LogSentryCore: handing control over to crashpad
2025-03-25T15:13:06.234Z	"i-06dcd49c07fe83fca"	"paxdei-server-ue4"	Sentry [debug] : serializing envelope into buffer
2025-03-25T15:13:06.234Z	"i-06dcd49c07fe83fca"	"paxdei-server-ue4"	Sentry [debug] : sending envelope
2025-03-25T15:13:06.234Z	"i-06dcd49c07fe83fca"	"paxdei-server-ue4"	LogSentryCore: Verbose: serializing envelope into buffer
2025-03-25T15:13:06.234Z	"i-06dcd49c07fe83fca"	"paxdei-server-ue4"	LogSentryCore: Verbose: sending envelope
2025-03-25T15:13:06.234Z	"i-06dcd49c07fe83fca"	"paxdei-server-ue4"	LogSentryCore: Verbose: invoking `on_crash` hook
2025-03-25T15:13:06.234Z	"i-06dcd49c07fe83fca"	"paxdei-server-ue4"	LogSentryCore: flushing session and queue before crashpad handler

The lines are in reverse order.

The script docker_entrypoint.sh will wait for any process named crashpad_handler to exit, using the pidof utility to find its PID, before logging the "Unreal server container exiting" line. If it finds a running process it will log that, so at this time, crashpad_handler is not running.

Now, crashpad_handler is likely daemonized and so its standard output is not shared with the main process, but is there any place where it logs its activities, so that we can manually output what it does, and be confident that it actually uploaded the crash?

Secondly: There is a stack trace produced by the UnrealEngine core after handing control over to crashpad_handler, but for this error it is nonsensical. I'd like to ask if there is any chance that the crash handling by sentry has somehow messed up the exception context at this time?

[supervacuus]

The script docker_entrypoint.sh will wait for any process named crashpad_handler to exit, using the pidof utility to find its PID, before logging the "Unreal server container exiting" line. If it finds a running process it will log that, so at this time, crashpad_handler is not running.

The next release will contain an option that lets the crashpad_handler wait until the upload has finished before it signals to the client in your app that it can shut down (#1153). This means that wrapping your application in a loop should no longer be necessary, although it doesn't mean the upload was successful (which is also true for your current setup).

Now, crashpad_handler is likely daemonized and so its standard output is not shared with the main process, but is there any place where it logs its activities, so that we can manually output what it does, and be confident that it actually uploaded the crash?

However, the crashpad_handler logs into the stderr of the running application. In most cases, the application is already terminated when the upload thread logs; thus, you wouldn't see any output. The new option, crashpad_wait_for_upload, instructs the crashpad_handler to wait and should allow them to be visible. So on Linux, you would see curl related errors from the crashpad_handler in your application's output.

[supervacuus]

Secondly: There is a stack trace produced by the UnrealEngine core after handing control over to crashpad_handler, but for this error it is nonsensical. I'd like to ask if there is any chance that the crash handling by sentry has somehow messed up the exception context at this time?

I'm not sure I understand. Do you think there is another crash after the one being processed by the Native SDK and the Native SDK somehow interferes, or do you think it is the previously installed signal handler from Unreal receiving a reraised signal?

I think you are seeing the latter since crashpad restores the previous handler and reraises the signal it received with an unmodified siginfo. So, it depends on what Unreal expects beyond that and what it means to have a "nonsensical stack trace." Maybe the stack is corrupted? It is hard to tell. But we don't change the crash context on the handler side.

[kristjanvalur]

Ok, eagerly waiting for new version.

What I meant for "nonsensical" is that the traceback which was redacted from line 5 above, seems corrupted. Since we don't have any information from sentry at all, it is hard to tell if the stack was corrupted to begin with or if the corruption occurred afterwards.

fyi, this is what it looks like:

0x000000000ac97960 PaxDeiServer-Linux-Test!UImpactFunctionLibrary::PostImpactDataAsset(AActor*, UE::Math::TVector<double> const&, UE::Math::TVector<double> const&, UE::Math::TVector<double> const&, UPhysicalMaterial*, TSoftObjectPtr<UPDAImpactDataAssetInfo>, AActor*, AActor*, USceneComponent*, ENCPoolMethod) [D:/tc_work/f667cdf70eb90d0e/project/Source/PaxDei/Public/Systems/Impact/ImpactFunctionLibrary.cpp:30]
0x000000000864f22c PaxDeiServer-Linux-Test!bool TSQVisitor<Chaos::TImplicitObjectScaled<Chaos::FCapsule, true>, FExternalSpatialAccelerationPayload, ChaosInterface::FOverlapHit, true>::Visit<(TSQVisitor<Chaos::TImplicitObjectScaled<Chaos::FCapsule, true>, FExternalSpatialAccelerationPayload, ChaosInterface::FOverlapHit, true>::ESQType)1>(Chaos::TSpatialVisitorData<FExternalSpatialAccelerationPayload> const&, Chaos::FQueryFastData*) [D:/tc_work/f667cdf70eb90d0e/UE/Engine/Source/Runtime/PhysicsCore/Public/SQVisitor.h:295]
0x00000000092df24a PaxDeiServer-Linux-Test!FCompositeAnimatedVectorFieldUniformParameters::zzAppendMemberGetPrev(FCompositeAnimatedVectorFieldUniformParameters::zzNextMemberIdOp, TArray<FShaderParametersMetadata::FMember, TSizedDefaultAllocator<32> >*) [D:/tc_work/f667cdf70eb90d0e/UE/Engine/Source/./Runtime/Engine/Private/VectorField.cpp:948]
0x00000000092ded3c PaxDeiServer-Linux-Test!FVectorFieldSceneProxy::GetDynamicMeshElements(TArray<FSceneView const*, TSizedDefaultAllocator<32> > const&, FSceneViewFamily const&, unsigned int, FMeshElementCollector&) const [D:/tc_work/f667cdf70eb90d0e/UE/Engine/Source/./Runtime/Engine/Private/VectorField.cpp:765]
0x0000000004aed21e PaxDeiServer-Linux-Test!FConsoleVariableHistory<int>::Log(FOutputDevice&) [D:/tc_work/f667cdf70eb90d0e/UE/Engine/Source/./Runtime/Core/Private/HAL/ConsoleManager.cpp:810]
0x0000000004aebb7f PaxDeiServer-Linux-Test!FConsoleVariableHistory<int>::Track(char16_t const*, EConsoleVariableFlags, FName) [D:/tc_work/f667cdf70eb90d0e/UE/Engine/Source/./Runtime/Core/Private/HAL/ConsoleManager.cpp:710]
0x0000000004aeacd6 PaxDeiServer-Linux-Test!TArray<FCPUTime, TSizedDefaultAllocator<32> >::ResizeGrow(int) [D:/tc_work/f667cdf70eb90d0e/UE/Engine/Source/Runtime/Core/Public/Containers/Array.h:3110]

There is more, but it appears as just random unrelated functions. As if the symbolication were completely off. But this is linux and the symbols are part of the executable, so I'm not sure what is wrong. Maybe it is just Unreal's stack walking code that is of the rails, but without an uploaded report from sentry it is hard to tell.