Skip to content

Conversation

@thaJeztah
Copy link
Member

Commit 92bf0a5 (#38541) added a logrus hook for ETW logging, but we still had the old Eventlog hook as well.

This patch removes the old Eventlog hook; a simmilar patch was merged in
containerd, which describes:

EventLog is very old and provides a poor experience. We have supported
ETW for logging for a while, which is much better. We have also
observed an issue where EventLog keeps containerd.exe open, preventing
containerd from being upgraded to a new version. Due to all of this,
it makes sense to remove the old EventLog hook in favor of using ETW
logging on Windows as the primary diagnostic experience.

- Description for the changelog

remove Windows EventLog logging hook

- A picture of a cute animal (not mandatory but encouraged)

thaJeztah and others added 4 commits October 12, 2022 10:26
golang.org/x/sys/windows now implements this, so we can use that
instead of a local implementation.

Signed-off-by: Sebastiaan van Stijn <github@gone.nl>
This is the equivalent of the local implementation.

Signed-off-by: Sebastiaan van Stijn <github@gone.nl>
Previously we waited for 60 seconds after the service faults to restart
it. However, there isn't much benefit to waiting this long. We expect
15 seconds to be a more reasonable delay.

Co-Authored-by: Kevin Parsons <kevpar@microsoft.com>
Signed-off-by: Sebastiaan van Stijn <github@gone.nl>
Commit 92bf0a5 added a logrus hook for ETW
logging, but we still had the old Eventlog hook as well.

This patch removes the old Eventlog hook; a simmilar patch was merged in
containerd, which describes:

> EventLog is very old and provides a poor experience. We have supported
> ETW for logging for a while, which is much better. We have also
> observed an issue where EventLog keeps containerd.exe open, preventing
> containerd from being upgraded to a new version. Due to all of this,
> it makes sense to remove the old EventLog hook in favor of using ETW
> logging on Windows as the primary diagnostic experience.

Co-Authored-By: Kevin Parsons <kevpar@microsoft.com>
Signed-off-by: Sebastiaan van Stijn <github@gone.nl>
@thaJeztah
Copy link
Member Author

This PR may also be interesting to see if we can take a similar approach;

@thaJeztah
Copy link
Member Author

Looks like the tests pass, but the test script fails. Looks like it may be unable to read the daemon logs, so either this patch broke that, or it's looking for the "old" logs, and we need to update the script to get the etwlogs.
https://learn.microsoft.com/en-us/powershell/module/microsoft.powershell.diagnostics/get-winevent?view=powershell-7.2

Get-WinEvent -ea SilentlyContinue `
    -FilterHashtable @{ProviderName= "docker"; LogName = "application"} |
      Sort-Object @{Expression="TimeCreated";Descending=$false} |
      ForEach-Object {"$($_.TimeCreated.ToUniversalTime().ToString("o")) [$($_.LevelDisplayName)] $($_.Message)"} |
      Tee-Object -file ".\bundles\daemon.log"
  shell: C:\Program Files\PowerShell\7\pwsh.EXE -command ". '{0}'"
  env:
    GO_VERSION: 1.19.2
    GOTESTLIST_VERSION: v0.2.0
    TESTSTAT_VERSION: v0.1.3
    WINDOWS_BASE_IMAGE: mcr.microsoft.com/windows/servercore
    WINDOWS_BASE_TAG_2019: ltsc2019
    WINDOWS_BASE_TAG_2022: ltsc2022
    TEST_IMAGE_NAME: moby:test
    TEST_CTN_NAME: moby
    DOCKER_BUILDKIT: 0
    ITG_CLI_MATRIX_SIZE: 6
    GOPATH: D:\a\moby\moby\go
    GOBIN: D:\a\moby\moby\go\bin
    BIN_OUT: D:\a\moby\moby\out
    WINDOWS_BASE_IMAGE_TAG: ltsc2022
Get-WinEvent: D:\a\_temp\a8a23134-77fd-419c-be87-c091e38ce0cc.ps1:2
Line |
   2 |  Get-WinEvent -ea SilentlyContinue `
     |  ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
     | The parameter is incorrect.

@thaJeztah
Copy link
Member Author

So the etwhook uses Moby as provider ({6996f090-c5de-5082-a81e-5841acc3a635} when converted to provider-ID (GUID));

// Provider ID: {6996f090-c5de-5082-a81e-5841acc3a635}
// Hook isn't closed explicitly, as it will exist until process exit.
// GUID is generated based on name - see Microsoft/go-winio/tools/etw-provider-gen.
if hook, err := etwlogrus.NewHook("Moby"); err == nil {
logrus.AddHook(hook)
}

Signed-off-by: Sebastiaan van Stijn <github@gone.nl>
Signed-off-by: Sebastiaan van Stijn <github@gone.nl>
@thaJeztah
Copy link
Member Author

@jterry75 made a good comment on the containerd PR, and probably describes the problem I see in our CI scripts trying to read the logs (so I guess we can't remove this after all).

You may not want to for Moby. ETW is superior 100% agree, but you need to have a session for listening to the provider guid. I'm not sure that everyone will set this up so default logs in event log may be better?

It felt a bit odd to send every log twice (once to ETW, and once to EventLog - wondering if that has an impact on "heavy logging" (e.g. "debug" enabled)) 🤔

containerd/containerd#3550 (comment)

@jterry75
Copy link
Contributor

It's not really all that "heavy" as it doesnt actually do anything other than the function invocation to send it to both listeners. But basically ETW just drops it if there is no listener. So its "doing work" but not a lot of work.

@rumpl rumpl modified the milestones: 24.0.0, v-future Apr 24, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants