Skip to content

[mono][ios] Eventpipe gcdump test failing on apple mobile platforms #90012

Closed
#91785
Closed
[mono][ios] Eventpipe gcdump test failing on apple mobile platforms#90012
#91785
Assignees
lateralusX
Labels
Known Build ErrorUse this to report build issues in the .NET Helix tabarea-VM-meta-monodisabled-testThe test is disabled in source code against the issue
Milestone
9.0.0

Description

@kotlarmilos
kotlarmilos
opened on Aug 4, 2023

Build Information

Build: https://dev.azure.com/dnceng-public/cbb18261-c48f-4abb-8651-8cdcb5474649/_build/results?buildId=363106
Build error leg or test failing: tracing/eventpipe/gcdump.dll
Pull request: #89726

Error Message

Fill the error message using step by step known issues guidance.

{
  "ErrorMessage": "Application has finished with exit code 255 but 100 was expected",
  "ErrorPattern": "",
  "BuildRetry": false,
  "ExcludeConsoleLog": false
}

Test log:

[03:12:26.0256760] Launched application 'net.dot.tracing_eventpipe' on 'DNCENGOSX117' with pid 14378
[03:12:26.1444880] 2023-08-04 03:12:26.185 tracing_eventpipe[14378:13727264]   0.0s: ==TEST STARTING==
[03:12:26.1548200] 2023-08-04 03:12:26.198 tracing_eventpipe[14378:13727274]   0.0s: Started sending sentinel events...
[03:12:26.1581380] 2023-08-04 03:12:26.201 tracing_eventpipe[14378:13727276]   0.0s: Connecting to EventPipe...
[03:12:26.2010550] 2023-08-04 03:12:26.244 tracing_eventpipe[14378:13727276]   0.1s: Creating EventPipeEventSource...
[03:12:26.2053600] 2023-08-04 03:12:26.248 tracing_eventpipe[14378:13727276]   0.1s: EventPipeEventSource created
[03:12:26.2137250] 2023-08-04 03:12:26.257 tracing_eventpipe[14378:13727276]   0.1s: Dynamic.All callback registered
[03:12:26.2137700] 2023-08-04 03:12:26.257 tracing_eventpipe[14378:13727276]   0.1s: Running optional trace validator
[03:12:26.2221300] 2023-08-04 03:12:26.264 tracing_eventpipe[14378:13727276]   0.1s: Finished running optional trace validator
[03:12:26.2221690] 2023-08-04 03:12:26.265 tracing_eventpipe[14378:13727276]   0.1s: Starting stream processing...
[03:12:26.3359410] 2023-08-04 03:12:26.379 tracing_eventpipe[14378:13727276]   0.2s: Saw sentinel event
[03:12:26.3359870] 2023-08-04 03:12:26.379 tracing_eventpipe[14378:13727274]   0.2s: Stopped sending sentinel events
[03:12:26.3371410] 2023-08-04 03:12:26.380 tracing_eventpipe[14378:13727264]   0.2s: Starting event generating action...
[03:12:36.3443740] 2023-08-04 03:12:36.387 tracing_eventpipe[14378:13727264]  10.2s: Stopping event generating action
[03:12:36.3456970] 2023-08-04 03:12:36.389 tracing_eventpipe[14378:13727274]  10.2s: Sending StopTracing command...
[03:12:36.4805540] 2023-08-04 03:12:36.524 tracing_eventpipe[14378:13727276]  10.4s: Saw new provider 'Microsoft-DotNETCore-EventPipe'
[03:12:36.4967410] 2023-08-04 03:12:36.540 tracing_eventpipe[14378:13727276]  10.4s: Saw new provider 'Microsoft-Windows-DotNETRuntimeRundown'
[03:12:36.5134950] 2023-08-04 03:12:36.557 tracing_eventpipe[14378:13727274]  10.4s: Finished StopTracing command
[03:12:36.5411160] 2023-08-04 03:12:36.584 tracing_eventpipe[14378:13727276]  10.4s: Stopping stream processing
[03:12:36.5412890] 2023-08-04 03:12:36.585 tracing_eventpipe[14378:13727276]  10.4s: Dropped 0 events
[03:12:36.5414080] 2023-08-04 03:12:36.585 tracing_eventpipe[14378:13727264]  10.4s: Reader task finished
[03:12:36.5415490] 2023-08-04 03:12:36.585 tracing_eventpipe[14378:13727264]  10.4s: Validating optional callback...
[03:12:36.5416170] 2023-08-04 03:12:36.585 tracing_eventpipe[14378:13727264] Test failed due to missing GC heap events.
[03:12:36.5417250] 2023-08-04 03:12:36.585 tracing_eventpipe[14378:13727264] _seenGCStart =            False
[03:12:36.5417550] 2023-08-04 03:12:36.586 tracing_eventpipe[14378:13727264] _seenGCStop =             False
[03:12:36.5417610] 2023-08-04 03:12:36.586 tracing_eventpipe[14378:13727264] _bulkTypeCount =          0
[03:12:36.5419840] 2023-08-04 03:12:36.586 tracing_eventpipe[14378:13727264] _bulkNodeCount =          0
[03:12:36.5420020] 2023-08-04 03:12:36.586 tracing_eventpipe[14378:13727264] _bulkEdgeCount =          0
[03:12:36.5420080] 2023-08-04 03:12:36.586 tracing_eventpipe[14378:13727264] _bulkRootEdgeCount =      0
[03:12:36.5420130] 2023-08-04 03:12:36.586 tracing_eventpipe[14378:13727264] _bulkRootStaticVarCount = 0
[03:12:36.5420220] 2023-08-04 03:12:36.586 tracing_eventpipe[14378:13727264]  10.4s: ==TEST FINISHED: FAILED!==
[03:12:36.5473960] Xamarin.Hosting: Process '14378' exited with exit code 255 or crashing signal .
[03:12:36.5478560] Application 'net.dot.tracing_eventpipe' terminated (with exit code '255' and/or crashing signal ').

Repro steps

  1. Build the runtime
./build.sh -ci -arch x64 -os tvossimulator  -s mono+libs -c Release
  1. Build and AOT compile the tests
./src/tests/build.sh  ci os tvossimulator x64 Release -mono tree tracing/eventpipe /p:ArchiveTests=true /p:DevTeamProvisioning=- /p:RunAOTCompilation=true /p:MonoForceInterpreter=true /p:LibrariesConfiguration=Release
  1. Run the app bundle using Xcode using the following environment variables
MONO_APPLE_APP_ENTRY_POINT_LIB_NAME = 'testdir-gcdump/gcdump.dll'
MONO_APPLE_APP_ASSEMBLY_LOAD_PREFIX = 'testdir-gcdump'

Note: You may need to provide a correct path to the cross compiler in the AppleBuild.targets.

Known issue validation

Build: 🔎 https://dev.azure.com/dnceng-public/public/_build/results?buildId=363106
Error message validated: Application has finished with exit code 255 but 100 was expected
Result validation: ✅ Known issue matched with the provided build.
Validation performed at: 8/4/2023 11:24:17 AM UTC

Report

Summary

24-Hour Hit Count 7-Day Hit Count 1-Month Count
0 0 0

Activity

  1. kotlarmilos
    added
    area-VM-meta-mono
    Known Build ErrorUse this to report build issues in the .NET Helix tab
    on Aug 4, 2023
  2. kotlarmilos
    added this to the 9.0.0 milestone on Aug 4, 2023
  3. kotlarmilos
    assigned
    lateralusX
    on Aug 4, 2023
  4. kotlarmilos
    added
    disabled-testThe test is disabled in source code against the issue
    on Aug 4, 2023

  5. lateralusX commented on Aug 4, 2023

    @lateralusX
    lateralusX
    on Aug 4, 2023
    Member

    Just following the steps above will leave the diagnostic tracing component disabled as well as not setting the needed env variable to startup the diagnostic server.

    Making sure we link libmono-component-diagnostics_tracing-static.a as well as setting env DOTNET_DiagnosticPorts=127.0.0.1:9000,nosuspend,listen made the test at least pass on tvossimulator arm64.

    @kotlarmilos could you retry your repro making sure we got the needed pre-reqs in place (linking to the none stub version of the diagnostics_tracing component as well as setting up the diagnostic server) and see if it still repros.

  6. lateralusX commented on Aug 29, 2023

    @lateralusX
    lateralusX
    on Aug 29, 2023
    Member

    @kotlarmilos, did you have a chance to try this test with the above?

  7. kotlarmilos commented on Sep 4, 2023

    @kotlarmilos
    kotlarmilos
    on Sep 4, 2023
    MemberAuthor

    Thanks for the heads up, I didn't have capacity before the RC1 snap, but I will follow-up this week. I think the components are not properly initialized locally. I will try to reproduce it without stubs.

  8. kotlarmilos commented on Sep 6, 2023

    @kotlarmilos
    kotlarmilos
    on Sep 6, 2023
    MemberAuthor

    I managed to reproduce it on a device.

    Try to add snippet below to the target in /src/tests/build.proj.

    runtime/src/tests/build.proj

    Lines 348 to 351 in a3a0f5c

    <UpdateRunScriptToHandleMultipleEntryPoints EntryPoints="@(EntryPoints)" RunScriptCommand="$(RunScriptCommand)" AppName="$(Category)" Condition="'$(BuildTestsOnHelix)' == 'true'">
    <Output TaskParameter="OutputScript" PropertyName="RunScriptCommand" />
    </UpdateRunScriptToHandleMultipleEntryPoints>
    </Target> 

        <PropertyGroup>
      <RuntimeComponents>diagnostics_tracing;marshal-ilgen</RuntimeComponents>
      <DiagnosticPorts>127.0.0.1:9000,nosuspend,listen</DiagnosticPorts>
    </PropertyGroup>

    The app fails with the following log:

    023-09-06 19:30:51.588443+0200 tracing_eventpipe[13232:2222710]   0.0s: ==TEST STARTING==
2023-09-06 19:30:51.588581+0200 tracing_eventpipe[13232:2222710] assembly_preload_hook: System.Collections.Concurrent  /private/var/containers/Bundle/Application/760C8B04-003C-4102-982F-EE8ACFFD6718/tracing_eventpipe.app
2023-09-06 19:30:51.589748+0200 tracing_eventpipe[13232:2222710] assembly_preload_hook: System.Diagnostics.Process  /private/var/containers/Bundle/Application/760C8B04-003C-4102-982F-EE8ACFFD6718/tracing_eventpipe.app
2023-09-06 19:30:51.590791+0200 tracing_eventpipe[13232:2222710] assembly_preload_hook: System.ComponentModel.Primitives  /private/var/containers/Bundle/Application/760C8B04-003C-4102-982F-EE8ACFFD6718/tracing_eventpipe.app
2023-09-06 19:30:51.591279+0200 tracing_eventpipe[13232:2222710] assembly_preload_hook: System.ComponentModel  /private/var/containers/Bundle/Application/760C8B04-003C-4102-982F-EE8ACFFD6718/tracing_eventpipe.app
2023-09-06 19:30:51.591735+0200 tracing_eventpipe[13232:2222710] assembly_preload_hook: System.Collections.NonGeneric  /private/var/containers/Bundle/Application/760C8B04-003C-4102-982F-EE8ACFFD6718/tracing_eventpipe.app
2023-09-06 19:30:51.592449+0200 tracing_eventpipe[13232:2222710] assembly_preload_hook: System.Threading.ThreadPool  /private/var/containers/Bundle/Application/760C8B04-003C-4102-982F-EE8ACFFD6718/tracing_eventpipe.app
2023-09-06 19:30:51.595890+0200 tracing_eventpipe[13232:2222710] assembly_preload_hook: System.Linq  /private/var/containers/Bundle/Application/760C8B04-003C-4102-982F-EE8ACFFD6718/tracing_eventpipe.app
2023-09-06 19:30:51.602684+0200 tracing_eventpipe[13232:2222716]   0.0s: Started sending sentinel events...
2023-09-06 19:30:51.604979+0200 tracing_eventpipe[13232:2222718]   0.0s: Connecting to EventPipe...
2023-09-06 19:30:51.607233+0200 tracing_eventpipe[13232:2222718] assembly_preload_hook: System.IO.Pipes  /private/var/containers/Bundle/Application/760C8B04-003C-4102-982F-EE8ACFFD6718/tracing_eventpipe.app
2023-09-06 19:30:51.608137+0200 tracing_eventpipe[13232:2222718] assembly_preload_hook: System.Net.Sockets  /private/var/containers/Bundle/Application/760C8B04-003C-4102-982F-EE8ACFFD6718/tracing_eventpipe.app
2023-09-06 19:30:51.609637+0200 tracing_eventpipe[13232:2222718] assembly_preload_hook: System.Net.Primitives  /private/var/containers/Bundle/Application/760C8B04-003C-4102-982F-EE8ACFFD6718/tracing_eventpipe.app
2023-09-06 19:30:51.614050+0200 tracing_eventpipe[13232:2222718] assembly_preload_hook: System.Runtime.Intrinsics  /private/var/containers/Bundle/Application/760C8B04-003C-4102-982F-EE8ACFFD6718/tracing_eventpipe.app
2023-09-06 19:30:51.615104+0200 tracing_eventpipe[13232:2222718] assembly_preload_hook: Microsoft.Win32.Primitives  /private/var/containers/Bundle/Application/760C8B04-003C-4102-982F-EE8ACFFD6718/tracing_eventpipe.app
2023-09-06 19:30:51.616050+0200 tracing_eventpipe[13232:2222718] assembly_preload_hook: System.Threading.Thread  /private/var/containers/Bundle/Application/760C8B04-003C-4102-982F-EE8ACFFD6718/tracing_eventpipe.app
2023-09-06 19:30:51.617431+0200 tracing_eventpipe[13232:2222718] assembly_preload_hook: System.Private.Uri  /private/var/containers/Bundle/Application/760C8B04-003C-4102-982F-EE8ACFFD6718/tracing_eventpipe.app
2023-09-06 19:30:51.622956+0200 tracing_eventpipe[13232:2222718] assembly_preload_hook: System.Net.NameResolution  /private/var/containers/Bundle/Application/760C8B04-003C-4102-982F-EE8ACFFD6718/tracing_eventpipe.app
2023-09-06 19:30:51.649999+0200 tracing_eventpipe[13232:2222718]   0.1s: Creating EventPipeEventSource...
2023-09-06 19:30:51.650751+0200 tracing_eventpipe[13232:2222718] assembly_preload_hook: System.IO  /private/var/containers/Bundle/Application/760C8B04-003C-4102-982F-EE8ACFFD6718/tracing_eventpipe.app
2023-09-06 19:30:51.654388+0200 tracing_eventpipe[13232:2222718]   0.1s: EventPipeEventSource created
2023-09-06 19:30:51.657134+0200 tracing_eventpipe[13232:2222718] assembly_preload_hook: System.Xml.ReaderWriter  /private/var/containers/Bundle/Application/760C8B04-003C-4102-982F-EE8ACFFD6718/tracing_eventpipe.app
2023-09-06 19:30:51.657663+0200 tracing_eventpipe[13232:2222718] assembly_preload_hook: System.Private.Xml  /private/var/containers/Bundle/Application/760C8B04-003C-4102-982F-EE8ACFFD6718/tracing_eventpipe.app
2023-09-06 19:30:51.661600+0200 tracing_eventpipe[13232:2222718] assembly_preload_hook: System.Text.RegularExpressions  /private/var/containers/Bundle/Application/760C8B04-003C-4102-982F-EE8ACFFD6718/tracing_eventpipe.app
2023-09-06 19:30:51.663418+0200 tracing_eventpipe[13232:2222718]   0.1s: Dynamic.All callback registered
2023-09-06 19:30:51.663515+0200 tracing_eventpipe[13232:2222718]   0.1s: Running optional trace validator
2023-09-06 19:30:51.672573+0200 tracing_eventpipe[13232:2222718]   0.1s: Finished running optional trace validator
2023-09-06 19:30:51.672673+0200 tracing_eventpipe[13232:2222718]   0.1s: Starting stream processing...
2023-09-06 19:30:51.672896+0200 tracing_eventpipe[13232:2222718] assembly_preload_hook: System.Runtime.Extensions  /private/var/containers/Bundle/Application/760C8B04-003C-4102-982F-EE8ACFFD6718/tracing_eventpipe.app
2023-09-06 19:30:51.757710+0200 tracing_eventpipe[13232:2222718] assembly_preload_hook: System.Security.Cryptography  /private/var/containers/Bundle/Application/760C8B04-003C-4102-982F-EE8ACFFD6718/tracing_eventpipe.app
2023-09-06 19:30:51.784283+0200 tracing_eventpipe[13232:2222718]   0.2s: Saw sentinel event
2023-09-06 19:30:51.784642+0200 tracing_eventpipe[13232:2222716]   0.2s: Stopped sending sentinel events
2023-09-06 19:30:51.786039+0200 tracing_eventpipe[13232:2222710]   0.2s: Starting event generating action...
2023-09-06 19:31:01.792366+0200 tracing_eventpipe[13232:2222710]  10.2s: Stopping event generating action
2023-09-06 19:31:01.794321+0200 tracing_eventpipe[13232:2222716]  10.2s: Sending StopTracing command...
2023-09-06 19:31:01.929064+0200 tracing_eventpipe[13232:2222718]  10.4s: Saw new provider 'Microsoft-DotNETCore-EventPipe'
2023-09-06 19:31:01.947496+0200 tracing_eventpipe[13232:2222718]  10.4s: Saw new provider 'Microsoft-Windows-DotNETRuntimeRundown'
2023-09-06 19:31:01.964881+0200 tracing_eventpipe[13232:2222716]  10.4s: Finished StopTracing command
2023-09-06 19:31:01.992815+0200 tracing_eventpipe[13232:2222718]  10.4s: Stopping stream processing
2023-09-06 19:31:01.992999+0200 tracing_eventpipe[13232:2222718]  10.4s: Dropped 0 events
2023-09-06 19:31:01.993395+0200 tracing_eventpipe[13232:2222710]  10.4s: Reader task finished
2023-09-06 19:31:01.993593+0200 tracing_eventpipe[13232:2222710]  10.4s: Validating optional callback...
2023-09-06 19:31:01.993767+0200 tracing_eventpipe[13232:2222710] Test failed due to missing GC heap events.
2023-09-06 19:31:01.993969+0200 tracing_eventpipe[13232:2222710] _seenGCStart =            False
2023-09-06 19:31:01.994015+0200 tracing_eventpipe[13232:2222710] _seenGCStop =             False
2023-09-06 19:31:01.994053+0200 tracing_eventpipe[13232:2222710] _bulkTypeCount =          0
2023-09-06 19:31:01.994091+0200 tracing_eventpipe[13232:2222710] _bulkNodeCount =          0
2023-09-06 19:31:01.994127+0200 tracing_eventpipe[13232:2222710] _bulkEdgeCount =          0
2023-09-06 19:31:01.994164+0200 tracing_eventpipe[13232:2222710] _bulkRootEdgeCount =      0
2023-09-06 19:31:01.994201+0200 tracing_eventpipe[13232:2222710] _bulkRootStaticVarCount = 0
2023-09-06 19:31:01.994263+0200 tracing_eventpipe[13232:2222710]  10.4s: ==TEST FINISHED: FAILED!==
  9. ghost added
    in-prThere is an active PR which will close this issue when it is merged
    on Sep 8, 2023
  10. kotlarmilos
    closed this as completedin #91785on Sep 8, 2023
  11. ghost removed
    in-prThere is an active PR which will close this issue when it is merged
    on Sep 8, 2023
  12. ghost locked as resolved and limited conversation to collaborators on Oct 8, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

Known Build ErrorUse this to report build issues in the .NET Helix tabarea-VM-meta-monodisabled-testThe test is disabled in source code against the issue

Type

No type

Projects

No projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions