Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Bad Process.StartTime in .NET Core 3.1 on macOS #66170

Closed
mattjohnsonpint opened this issue Mar 3, 2022 · 13 comments
Closed

Bad Process.StartTime in .NET Core 3.1 on macOS #66170

mattjohnsonpint opened this issue Mar 3, 2022 · 13 comments
Labels
area-System.Diagnostics.Process help wanted [up-for-grabs] Good issue for external contributors os-mac-os-x macOS aka OSX
Milestone

Comments

@mattjohnsonpint
Copy link
Contributor

mattjohnsonpint commented Mar 3, 2022

Description

The value returned from System.Diagnostics.Process.StartTime is wildly incorrect when run on .NET Core 3.1 (runtime 3.1.22) on macOS 12.2.1 with M1 (Apple Silicon / arm64) processor. The problem does not occur on .NET 6.0 or 5.0, nor does it occur on .NET Core 3.1 running on macOS with an Intel (x64) processor.

Reproduction Steps

Following this guidance, install the following SDKs on macOS:

  • 6.0.200 arm64
  • 6.0.200 x64
  • 5.0.405 x64
  • 3.1.416 x64

Create a new console app:

test.csproj:

<Project Sdk="Microsoft.NET.Sdk">
  <PropertyGroup>
    <OutputType>Exe</OutputType>
    <TargetFrameworks>net6.0;net5.0;netcoreapp3.1</TargetFrameworks>
  </PropertyGroup>
</Project>

Program.cs:

using System;
using System.Diagnostics;
using System.Runtime.InteropServices;

namespace ConsoleApp1
{
    public static class Program
    {
        public static void Main()
        {
            var processStartTime = Process.GetCurrentProcess().StartTime.ToUniversalTime();
            var utcNow = DateTime.UtcNow;
            var delta = utcNow - processStartTime;

            Console.WriteLine($"OS Architecture: {RuntimeInformation.OSArchitecture}");
            Console.WriteLine($"Framework: {RuntimeInformation.FrameworkDescription}");
            Console.WriteLine($"Process.StartTime: {processStartTime:o}");
            Console.WriteLine($"DateTime.UtcNow: {utcNow:o}");
            Console.WriteLine($"Delta: {delta}");
            Console.WriteLine();
        }
    }
}

Run the program under the various runtimes and observe the results.

Expected behavior

The process start time should be very close to DateTime.UtcNow (delta near zero) in all cases.

Actual behavior

The output is correct on .NET 6 and 5, but wildly incorrect on .NET Core 3.1 (LTS).

% dotnet run -f net6.0
OS Architecture: Arm64
Framework: .NET 6.0.2
Process.StartTime: 2022-03-03T22:26:01.6263462Z
DateTime.UtcNow: 2022-03-03T22:26:01.7393750Z
Delta: 00:00:00.1130288

% dotnet run -f net6.0 -a x64
OS Architecture: X64
Framework: .NET 6.0.2
Process.StartTime: 2022-03-03T22:26:07.7978340Z
DateTime.UtcNow: 2022-03-03T22:26:07.9519200Z
Delta: 00:00:00.1540860

% dotnet run -f net5.0       
OS Architecture: X64
Framework: .NET 5.0.14
Process.StartTime: 2022-03-03T22:26:18.0786000Z
DateTime.UtcNow: 2022-03-03T22:26:18.2399030Z
Delta: 00:00:00.1613030

% dotnet run -f netcoreapp3.1
OS Architecture: X64
Framework: .NET Core 3.1.22
Process.StartTime: 2022-03-03T06:58:55.5796520Z
DateTime.UtcNow: 2022-03-03T22:26:51.5452700Z
Delta: 15:27:55.9656180

Regression?

The symptoms are similar to #19928, but that was resolved very long ago in .NET Core 2.0.

That it is working in .NET 5 and 6, might be related to #30241

@dotnet-issue-labeler dotnet-issue-labeler bot added area-System.Diagnostics.Process untriaged New issue has not been triaged by the area owner labels Mar 3, 2022
@ghost
Copy link

ghost commented Mar 3, 2022

Tagging subscribers to this area: @dotnet/area-system-diagnostics-process
See info in area-owners.md if you want to be subscribed.

Issue Details

Description

The value returned from System.Diagnostics.Process.StartTime is wildly incorrect when run on .NET Core 3.1 (runtime 3.1.22) on macOS 12.2.1 with M1 (Apple Silicon / arm64) processor. The problem does not occur on .NET 6.0 or 5.0.

Reproduction Steps

Following [this guidance](dotnet/sdk#22380 (comment), install the following SDKs on macOS:

  • 6.0.200 arm64
  • 6.0.200 x64
  • 5.0.405 x64
  • 3.1.416 x64

Create a new console app:

test.csproj:

<Project Sdk="Microsoft.NET.Sdk">
  <PropertyGroup>
    <OutputType>Exe</OutputType>
    <TargetFrameworks>net6.0;net5.0;netcoreapp3.1</TargetFrameworks>
  </PropertyGroup>
</Project>

Program.cs:

using System;
using System.Diagnostics;
using System.Runtime.InteropServices;

namespace ConsoleApp1
{
    public static class Program
    {
        public static void Main()
        {
            var processStartTime = Process.GetCurrentProcess().StartTime.ToUniversalTime();
            var utcNow = DateTime.UtcNow;
            var delta = utcNow - processStartTime;

            Console.WriteLine($"OS Architecture: {RuntimeInformation.OSArchitecture}");
            Console.WriteLine($"Framework: {RuntimeInformation.FrameworkDescription}");
            Console.WriteLine($"Process.StartTime: {processStartTime:o}");
            Console.WriteLine($"DateTime.UtcNow: {utcNow:o}");
            Console.WriteLine($"Delta: {delta}");
            Console.WriteLine();
        }
    }
}

Run the program under the various runtimes and observe the results.

Expected behavior

The process start time should be very close to DateTime.UtcNow (delta near zero) in all cases.

Actual behavior

The output is correct on .NET 6 and 5, but wildly incorrect on .NET Core 3.1 (LTS).

% dotnet run -f net6.0
OS Architecture: Arm64
Framework: .NET 6.0.2
Process.StartTime: 2022-03-03T22:26:01.6263462Z
DateTime.UtcNow: 2022-03-03T22:26:01.7393750Z
Delta: 00:00:00.1130288

% dotnet run -f net6.0 -a x64
OS Architecture: X64
Framework: .NET 6.0.2
Process.StartTime: 2022-03-03T22:26:07.7978340Z
DateTime.UtcNow: 2022-03-03T22:26:07.9519200Z
Delta: 00:00:00.1540860

% dotnet run -f net5.0       
OS Architecture: X64
Framework: .NET 5.0.14
Process.StartTime: 2022-03-03T22:26:18.0786000Z
DateTime.UtcNow: 2022-03-03T22:26:18.2399030Z
Delta: 00:00:00.1613030

% dotnet run -f netcoreapp3.1
OS Architecture: X64
Framework: .NET Core 3.1.22
Process.StartTime: 2022-03-03T06:58:55.5796520Z
DateTime.UtcNow: 2022-03-03T22:26:51.5452700Z
Delta: 15:27:55.9656180

Regression?

The symptoms are similar to #19928, but that was resolve very long ago in .NET Core 2.0.

That it is working in .NET 5 and 6 might be related to #30241

Known Workarounds

No response

Configuration

No response

Other information

@tarekgh

Author: mattjohnsonpint
Assignees: -
Labels:

area-System.Diagnostics.Process, untriaged

Milestone: -

@mattjohnsonpint
Copy link
Contributor Author

@mattjohnsonpint
Copy link
Contributor Author

The bad result also occurs on .NET Core 2.1, but since it's unsupported I expect that won't get resolved.

@bruno-garcia
Copy link
Member

I'm running macOS x64 and I get:

➜ dotnet run -f netcoreapp3.1
OS Architecture: X64
Framework: .NET Core 3.1.22
Process.StartTime: 2022-03-03T23:37:39.8810980Z
DateTime.UtcNow: 2022-03-03T23:37:40.9433880Z
Delta: 00:00:01.0622900

➜ dotnet run -f net5.0       
OS Architecture: X64
Framework: .NET 5.0.13
Process.StartTime: 2022-03-03T23:37:51.3093380Z
DateTime.UtcNow: 2022-03-03T23:37:52.1889820Z
Delta: 00:00:00.8796440

➜ dotnet run -f net6.0
OS Architecture: X64
Framework: .NET 6.0.1
Process.StartTime: 2022-03-03T23:37:56.5150970Z
DateTime.UtcNow: 2022-03-03T23:37:56.5868800Z
Delta: 00:00:00.0717830
dotnet --info
.NET SDK (reflecting any global.json):
 Version:   6.0.101
 Commit:    ef49f6213a

Runtime Environment:
 OS Name:     Mac OS X
 OS Version:  11.0
 OS Platform: Darwin
 RID:         osx.10.16-x64
 Base Path:   /usr/local/share/dotnet/sdk/6.0.101/

Host (useful for support):
  Version: 6.0.1
  Commit:  3a25a7f1cc

.NET SDKs installed:
  2.1.818 [/usr/local/share/dotnet/sdk]
  3.1.414 [/usr/local/share/dotnet/sdk]
  3.1.415 [/usr/local/share/dotnet/sdk]
  3.1.416 [/usr/local/share/dotnet/sdk]
  5.0.402 [/usr/local/share/dotnet/sdk]
  5.0.403 [/usr/local/share/dotnet/sdk]
  5.0.404 [/usr/local/share/dotnet/sdk]
  6.0.100-rc.2.21505.57 [/usr/local/share/dotnet/sdk]
  6.0.100 [/usr/local/share/dotnet/sdk]
  6.0.101 [/usr/local/share/dotnet/sdk]

.NET runtimes installed:
  Microsoft.AspNetCore.All 2.1.30 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.App 2.1.30 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 3.1.20 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 3.1.21 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 3.1.22 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 5.0.11 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 5.0.12 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 5.0.13 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 6.0.0-rc.2.21480.10 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 6.0.0 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 6.0.1 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.NETCore.App 2.1.30 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 3.1.20 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 3.1.21 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 3.1.22 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 5.0.11 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 5.0.12 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 5.0.13 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 6.0.0-rc.2.21480.5 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 6.0.0 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 6.0.1 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]

@mattjohnsonpint
Copy link
Contributor Author

Thanks @bruno-garcia. I updated the issue to reflect that it only occurs on M1 hardware, not on Intel.

@jozkee
Copy link
Member

jozkee commented Mar 9, 2022

@danmoseley @jeffhandley before investing time into porting/ensuring that dotnet/corefx#39572 fixes this issue, can you say if this would meet the bar for 3.1 servicing?

@jozkee jozkee added this to the 7.0.0 milestone Mar 9, 2022
@jozkee jozkee removed the untriaged New issue has not been triaged by the area owner label Mar 9, 2022
@tarekgh
Copy link
Member

tarekgh commented Mar 10, 2022

@mattjohnsonpint it is nice to see you around github :-)

I am wondering if this is something really blocking you? or can migrate to .NET 6.0 to work around this issue? telling more about your scenario will be helpful here.

@danmoseley
Copy link
Member

occurs on M1 hardware, not on Intel.

That's curious, it's not obvious to me that dotnet/corefx#39572 is Arm64 specific.

@mattjohnsonpint
Copy link
Contributor Author

mattjohnsonpint commented Mar 10, 2022

Hi @tarekgh! I'm working at Sentry now, on their client SDKs with @bruno-garcia. This came up because Process.StartTime is used in a core path (that our unit tests hit), and we support clients that are building for many versions of .NET. We're working around the test failures for now by skipping, but that's just burying the issue. In reality, we have customers who have built .NET Core 3.1 apps, and may be deploying them to newer hardware, such as the M1 MacBooks. We'll have erroneous data for that subset of customers using Sentry unless this is fixed in the runtime.

@jozkee
Copy link
Member

jozkee commented Mar 10, 2022

Linking similar Linux issue #64742.

@jeffhandley
Copy link
Member

@jozkee This would be a good servicing candidate because of how it can affect data in production scenarios that @mattjohnsonpint described. Before we bring it to tactics, we'll want to make sure we can reliably reproduce the issue and verify the fix. If feasible, getting validation from @mattjohnsonpint or @bruno-garcia against a local build from a branch would help address other hesitations too.

By the way, thanks for the excellent issue submission and minimal repro, @mattjohnsonpint!

@mattjohnsonpint
Copy link
Contributor Author

Just wanted to check in on this. Is it planned to be addressed for 3.1 servicing? Thanks.

@jeffhandley jeffhandley modified the milestones: 7.0.0, 8.0.0 Aug 9, 2022
@adamsitnik adamsitnik modified the milestones: 8.0.0, 9.0.0 Aug 1, 2023
@adamsitnik adamsitnik added os-mac-os-x macOS aka OSX help wanted [up-for-grabs] Good issue for external contributors labels Aug 1, 2023
@adamsitnik
Copy link
Member

adamsitnik commented Jul 18, 2024

I hate to say it, but we have been postponing the fix so long that 3.1 got out of support. Since all supported versions are not affected (thanks to dotnet/corefx#39572 which got included in 5.0), I am going to close the issue.

@adamsitnik adamsitnik closed this as not planned Won't fix, can't repro, duplicate, stale Jul 18, 2024
@github-actions github-actions bot locked and limited conversation to collaborators Aug 18, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
area-System.Diagnostics.Process help wanted [up-for-grabs] Good issue for external contributors os-mac-os-x macOS aka OSX
Projects
None yet
Development

No branches or pull requests

7 participants