Test failure: tracing_tracevalidation._jittingstarted_JittingStarted_JittingStarted_/_jittingstarted_JittingStarted_JittingStarted_cmd

[ghost]

Opened on behalf of @Sunny-pu

The test tracing_tracevalidation._jittingstarted_JittingStarted_JittingStarted_/_jittingstarted_JittingStarted_JittingStarted_cmd has failed.

Unhandled Exception: System.Exception: Values for 'matchingEventCount' are not equal! Left='0' Right='1'\r
   at Tracing.Tests.Common.Assert.Equal[T](String name, T left, T right)\r
   at Tracing.Tests.TraceValidationJittingStarted.Main(String[] args)


Return code:      1
Raw output file:      C:\dotnetbuild\work\f070d7c1-b198-49ea-9b94-40eed82fe529\Work\f74d2bfb-4aa1-46cb-b021-b28dc9bb7d12\Unzip\Reports\tracing.tracevalidation\jittingstarted\JittingStarted\JittingStarted.output.txt
Raw output:
BEGIN EXECUTION\r
 "C:\dotnetbuild\work\f070d7c1-b198-49ea-9b94-40eed82fe529\Payload\corerun.exe" JittingStarted.exe \r
\tStart: Enable tracing.\r
\tEnd: Enable tracing.
\r
\tStart: Generate some events.\r
\tEnd: Generate some events.
\r
\tStart: Disable tracing.\r
\tEnd: Disable tracing.
\r
\tStart: Process the trace file.\r
\tEnd: Processing events from file.
\r
Expected: 100\r
Actual: -532462766\r
END EXECUTION - FAILED\r
FAILED\r
Test Harness Exitcode is : 1\r

To run the test:
> set CORE_ROOT=C:\dotnetbuild\work\f070d7c1-b198-49ea-9b94-40eed82fe529\Payload
> C:\dotnetbuild\work\f070d7c1-b198-49ea-9b94-40eed82fe529\Work\f74d2bfb-4aa1-46cb-b021-b28dc9bb7d12\Unzip\jittingstarted\JittingStarted\JittingStarted.cmd
\r
Expected: True\r
Actual:   False

    Stack Trace:

    null

Build : Master - 20180328.02 (Core Tests)
Failing configurations:

• Windows.7.Amd64-x64

Details:
https://mc.dot.net/#/product/netcore/master/source/official~2Fcoreclr~2Fmaster~2F/type/test~2Ffunctional~2Fcli~2F/build/20180328.02/workItem/tracing.tracevalidation.XUnitWrapper/analysis/xunit/tracing_tracevalidation._jittingstarted_JittingStarted_JittingStarted_~2F_jittingstarted_JittingStarted_JittingStarted_cmd

[RussKeldorph]

@brianrob

[brianrob]

Unable to get a repro machine for this until #9902 is fixed.

[RussKeldorph]

@jorive @noahfalk This issue was hiding in the UWP6.1 milestone; I've moved to 3.0. The last occurrence with the failure mode above occurred on 2019-02-07, but the most recent failure of the test occurred on 2019-03-29 and looked like:

Assert failure(PID 2449 [0x00000991], Thread: 2458 [0x099a]): !\"Heap contamination detected! HeapFree was called on a heap other than the one that memory was allocated from.\\n\" \"Possible cause: you used new (executable) to allocate the memory, but didn't use DeleteExecutable() to free it.\"\n    File: /__w/3/s/src/vm/hosting.cpp Line: 273\n    Image: /home/helixbot/work/fb27e246-a405-4780-885f-18646d0e7f68/Payload/corerun\n\n/home/helixbot/work/fb27e246-a405-4780-885f-18646d0e7f68/Work/11fdd482-3f5f-4594-b17c-7c65ee296752/Exec/jittingstarted/JittingStarted/JittingStarted.sh: line 266:  2449 Aborted                 (core dumped) $LAUNCHER $ExePath \"${CLRTestExecutionArguments[@]}\"\n/n/nReturn code:      1/nRaw output file:      /home/helixbot/work/fb27e246-a405-4780-885f-18646d0e7f68/Work/11fdd482-3f5f-4594-b17c-7c65ee296752/Exec/Reports/tracing.tracevalidation/jittingstarted/JittingStarted/JittingStarted.output.txt/nRaw output:/nBEGIN EXECUTION\n/home/helixbot/work/fb27e246-a405-4780-885f-18646d0e7f68/Payload/corerun JittingStarted.exe ''\n\tStart: Enable tracing.\n\tEnd: Enable tracing.\n\n\tStart: Generate some events.\n\tEnd: Generate some events.\n\n\tStart: Disable tracing.\nExpected: 100\nActual: 134\nEND EXECUTION - FAILED\nTest Harness Exitcode is : 1\n/nTo run the test:/n> set CORE_ROOT=/home/helixbot/work/fb27e246-a405-4780-885f-18646d0e7f68/Payload/n> /home/helixbot/work/fb27e246-a405-4780-885f-18646d0e7f68/Work/11fdd482-3f5f-4594-b17c-7c65ee296752/Exec/jittingstarted/JittingStarted/JittingStarted.sh/n\nExpected: True\nActual:   False

Here's a Kusto query of recent failures if it helps.

Jobs
| where Source contains("dotnet/coreclr")
| join kind=inner TestResults on JobId
| where Method contains ("JittingStarted")
| where Message !contains ("coreclr_initialize")
| where Result != "Pass"
| project Started, QueueName, Duration, Message

[jorive]

I'm closing this old bug, and we can open a new one if there is a new failure. The assertion above is a different issue that was introduced and fixed recently with the EventPipe work.