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

Use CLOCK_BOOTTIME to calculate BootTime on linux #67589

Merged
merged 9 commits into from
Sep 8, 2022

Conversation

am11
Copy link
Member

@am11 am11 commented Apr 5, 2022

Fixes #67583.

@ghost ghost added the community-contribution Indicates that the PR has been added by a community member label Apr 5, 2022
@ghost
Copy link

ghost commented Apr 5, 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

Fixes #67583.

Author: am11
Assignees: -
Labels:

area-System.Diagnostics.Process

Milestone: -

@stephentoub stephentoub added the NO-MERGE The PR is not ready for merge yet (see discussion for detailed reasons) label Apr 5, 2022
@danmoseley
Copy link
Member

Just looked at SystemNative_GetTimestamp:

Should this be CLOCK_MONOTONIC_RAW, since CLOCK_UPTIME_RAW is a "clock that increments monotonically, in the same manner as CLOCK_MONOTONIC_RAW, but that does not increment while the system is asleep". Yet we are adding it to the time the process was running to get a real world time.

return clock_gettime_nsec_np(CLOCK_UPTIME_RAW);

As for this one, the man page says "CLOCK_MONOTONIC Clock that cannot be set and represents monotonic time since some unspecified starting point." which seems a little ill defined.

int result = clock_gettime(CLOCK_MONOTONIC, &ts);

@am11
Copy link
Member Author

am11 commented Apr 5, 2022

I have restructured SystemNative_GetTimestamp and renamed it to SystemNative_GetUptimeInNanoseconds. It is now using CLOCK_BOOTTIME (linux), CLOCK_MONOTONIC_RAW (macOS) and CLOCK_MONOTONIC (other POSIX-y OS) in a fallback manner based on their availability (at build time).

The precision was required in ProcessStartTime_Deterministic_Across_Instances test with this approach. In the current implementation, we are using precise point in time (UnixEpoch) and incrementing it by fixed value (btime; uptime in seconds since epoch); while the new implementation subtracts the (since-uptime) delta in ticks from UtcNow. Due to the usage of UtcNow, DateTime.ToString("o") (which xunit is using to compare datetime objects) shows difference of +/- couple of ticks between get_StartTime calls but it stays in that short range (I have used 10ms TimeSpan, it can be smaller).

@danmoseley
Copy link
Member

I see you removed clock_gettime_ns_p -- is clock_gettime as good? Looks like the original change was following guidance in https://developer.apple.com/documentation/kernel/1462446-mach_absolute_time.

Complicated! Do you have access to Windows and Mac to verify they give reasonable outputs, or are we relying on tests?

@danmoseley
Copy link
Member

Ack, we have the tests disabled on mac - could you enable these ?

   92  
   93          [Fact]
   94:         [PlatformSpecific(TestPlatforms.OSX|TestPlatforms.FreeBSD)] // OSX and FreeBSD throw PNSE from StartTime
   95          public void TestStartTimeProperty_OSX()
   96          {
   ..
  109  
  110          [Fact]
  111:         [PlatformSpecific(TestPlatforms.Linux|TestPlatforms.Windows)] // OSX and FreeBSD throw PNSE from StartTime
  112          public async Task TestStartTimeProperty()
  113          {

@am11
Copy link
Member Author

am11 commented Apr 5, 2022

The conditional tests are related to ProcessThread.StartTime. Linux and Windows support per thread start time, while other platforms do not provide mechanism to obtain it.

The test ProcessStartTime_Deterministic_Across_Instances runs on macOS. However, BSD and macOS have different implementation of StartTimeCore, which Process.StartTime property uses. I tested it on M1 pro; macOS (since 10.11) has clock_gettime and CLOCK_MONOTONIC_RAW. The value CLOCK_MONOTONIC_RAW returns on macOS is sometime in future (4 years) and with CLOCK_UPTIME_RAW, it returns 6 years in past. i.e. it is not giving us 'uptime' of system. I have reverted the name change as it is really meant to obtain some (arbitrary) timestamp, it seems. But I think we should revisit its usage in other places to make sure those are correct. A usage in SystemNative_GetCpuUtilization consider it as current system time and another in System.Diagnostics.StopWatch.QueryPerformanceCounter() in Stopwatch.Unix.cs considers it as a counterpart of win32 API.

@am11 am11 closed this Apr 11, 2022
@am11 am11 reopened this Apr 11, 2022
@am11
Copy link
Member Author

am11 commented Apr 11, 2022

Failing leg appears to be infra issue (exit code is 0 from test runs but helix is reporting failure for some reason).

@stephentoub, could you please take another look? 🙂
In other places, we have surrounded the procfs accesses with try-catch (since procfs can be unavailable or inaccessible in certain environments) but I saw this as opportunity to remove reliance on procfs for calculating the boot time.

@am11 am11 removed the NO-MERGE The PR is not ready for merge yet (see discussion for detailed reasons) label Apr 23, 2022
@adamsitnik adamsitnik self-assigned this May 9, 2022
Copy link
Member

@adamsitnik adamsitnik left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@am11 big thanks for your contribution! PTAL at my comments

@am11 am11 changed the title Use SystemNative_GetTimestamp to calculate BootTime Use CLOCK_BOOTTIME to calculate BootTime on linux May 10, 2022
Copy link
Member

@adamsitnik adamsitnik left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It LGTM, thanks a lot @am11 !

@adamsitnik adamsitnik added this to the 7.0.0 milestone May 10, 2022
@jkotas
Copy link
Member

jkotas commented May 11, 2022

Do we need to add or enable any tests that validate Process.StartTime works on Android now?

@adamsitnik
Copy link
Member

/azp run runtime-extra-platforms

@azure-pipelines
Copy link

Azure Pipelines successfully started running 1 pipeline(s).

@am11
Copy link
Member Author

am11 commented May 18, 2022

Still failing on Android.
The new test assertion also failed on Windoows x64 mono (windows implementation is not changed by the PR):

    System.Diagnostics.Tests.ProcessTests.GetProcessesByName_ProcessName_ReturnsExpected [FAIL]
     Assert.All() Failure: 1 out of 2 items in the collection did not pass.
     [0]: Item: System.Diagnostics.Process (dotnet)
          Xunit.Sdk.EqualException: Assert.Equal() Failure
          Expected: 2022-05-18T17:19:52.4765438+00:00
          Actual:   2022-05-18T16:42:36.1263514+00:00
             at Xunit.Assert.Equal[DateTime](DateTime expected, DateTime actual, IEqualityComparer`1 comparer) in /_/src/xunit.assert/Asserts/EqualityAsserts.cs:line 101
             at Xunit.Assert.Equal[DateTime](DateTime expected, DateTime actual) in /_/src/xunit.assert/Asserts/EqualityAsserts.cs:line 63
             at System.Diagnostics.Tests.ProcessTests.<>c__DisplayClass89_0.<GetProcessesByName_ProcessName_ReturnsExpected>b__3(Process process) in /_/src/libraries/System.Diagnostics.Process/tests/ProcessTests.cs:line 1246
             at Xunit.Assert.<>c__DisplayClass11_0`1[[System.Diagnostics.Process, System.Diagnostics.Process, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].<All>b__0(Process item, Int32 index) in /_/src/xunit.assert/Asserts/CollectionAsserts.cs:line 34
             at Xunit.Assert.All[Process](IEnumerable`1 collection, Action`2 action) in /_/src/xunit.assert/Asserts/CollectionAsserts.cs:line 61

@danmoseley
Copy link
Member

If this is blocked by the linked issue, let's mark this as draft meantime?

@am11 am11 marked this pull request as draft September 6, 2022 02:32
src/native/libs/System.Native/pal_time.c Outdated Show resolved Hide resolved
long bootTimeTicks = Interlocked.Read(ref s_bootTimeTicks);
if (bootTimeTicks == 0)
{
bootTimeTicks = Interop.Sys.GetBootTimeTicks();
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think we should check if the value is -1 and throw PlatformNotSupportedException in that case.

Co-authored-by: Simon Rozsival <simon@rozsival.com>
@am11
Copy link
Member Author

am11 commented Sep 7, 2022

Thanks a lot @simonrozsival! Could you please run runtime-extra-platforms pipeline?

@am11 am11 marked this pull request as ready for review September 7, 2022 14:11
@simonrozsival
Copy link
Member

/azp run runtime-extra-platforms

@azure-pipelines
Copy link

Azure Pipelines successfully started running 1 pipeline(s).

@am11
Copy link
Member Author

am11 commented Sep 7, 2022

Android legs are green. Remaining failures are unrelated.

Copy link
Member

@adamsitnik adamsitnik left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@lgtm, thank you again for your another great contribution @am11 !

@adamsitnik adamsitnik merged commit 129a4f5 into dotnet:main Sep 8, 2022
@adamsitnik adamsitnik modified the milestones: 7.0.0, 8.0.0 Sep 8, 2022
@MichalStrehovsky
Copy link
Member

I'm seeing a failure in #75055 that looks related:

https://helixre107v0xdeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-75055-merge-2e29b37a972e4e899f/System.Diagnostics.Process.Tests/1/console.852c083b.log?helixlogtype=result

      Assert.All() Failure: 1 out of 2 items in the collection did not pass.
      [1]: Item: System.Diagnostics.Process (dotnet)
           Xunit.Sdk.EqualException: Assert.Equal() Failure
           Expected: 2022-09-09T05:51:41.0956069+00:00
           Actual:   2022-09-09T05:51:54.8911051+00:00
              at Xunit.Assert.Equal[T](T expected, T actual, IEqualityComparer`1 comparer) in /_/src/xunit.assert/Asserts/EqualityAsserts.cs:line 96
              at Xunit.Assert.Equal[T](T expected, T actual) in /_/src/xunit.assert/Asserts/EqualityAsserts.cs:line 63
              at System.Diagnostics.Tests.ProcessTests.<>c__DisplayClass90_0.<GetProcessesByName_ProcessName_ReturnsExpected>b__3(Process process) in /_/src/libraries/System.Diagnostics.Process/tests/ProcessTests.cs:line 1251
              at Xunit.Assert.All[T](IEnumerable`1 collection, Action`2 action) in /_/src/xunit.assert/Asserts/CollectionAsserts.cs:line 77
      Stack Trace:
        /_/src/libraries/System.Diagnostics.Process/tests/ProcessTests.cs(1251,0): at System.Diagnostics.Tests.ProcessTests.GetProcessesByName_ProcessName_ReturnsExpected()
           at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
        /_/src/libraries/System.Private.CoreLib/src/System/Reflection/MethodInvoker.cs(69,0): at System.Reflection.MethodInvoker.Invoke(Object obj, IntPtr* args, BindingFlags invokeAttr)

@MichalStrehovsky
Copy link
Member

Filed as #75329 so that I can refer to it.

@am11
Copy link
Member Author

am11 commented Sep 9, 2022

Thanks and yes, it's related. The failure is happening on Windows 11 in a modified test (on Linux, it cannot fail because we calculate time difference from fixed point). Seems like we would need to bring back precision argument for slow Windows machine though 30eae7f#diff-f756f37255fb9daf54bb56c6b6653e2dd6b5acb1103d60844ab08433e8053fe5.

Strange thing is the difference on Windows 11 is 13 seconds, which is quite big (and we have only changed Linux implementation in this PR). Unless someone object, I'll add 30 seconds precision to be on the safe side.

@uweigand
Copy link
Contributor

uweigand commented Sep 9, 2022

I've also seen this test failure on linux-s390x (see #75329 (comment)) with a much larger time difference - it looks to me it might be picking up the wrong process?

@am11
Copy link
Member Author

am11 commented Sep 9, 2022

Yes, this assertion is not valid in GetProcessByName test when there are multiple dotnet processes running. We should just delete it from the test. Posted #75334.

@ghost ghost locked as resolved and limited conversation to collaborators Oct 9, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
area-System.Diagnostics.Process community-contribution Indicates that the PR has been added by a community member
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Bad Process.StartTime in .NET 6 on Android
9 participants