proposal: x/sys/windows/svc/eventlog: Use generic error message for Windows Event logs

[jkroepke]

Hi,

this is a feature request for golang.org/x/sys. Not sure, if I have to open a proposal.

Sending logs tough golang.org/x/sys/windows/svc/eventlog are every limited. Windows has a builtin translation table based on the event id. The Log messages sent by golang.org/x/sys/windows/svc/eventlog are only viewable by the Details tab, since a translated message will be displayed in front of it.

However, Windows has a generic error message ('%1 %2 %3 %4 %5 %6 %7 %8 %9') defined as event id 3299 which looks suitable for generic log messages.

Ref: https://github.com/microsoft/win32metadata/blob/2f3c5282ce1024a712aeccd90d3aa50bf7a49e27/generation/WinSDK/RecompiledIdlHeaders/um/LMErrlog.h#L824-L845

Other software components like Apache Web Server are using this event id for years:

https://github.com/apache/httpd/blob/7b12bfc7fe4f2b1a074f6818638c77b949d4acd9/server/mpm/winnt/nt_eventlog.c#L94-L95

However, the methods Info, Warn, Error of (golang.org/x/sys/windows/svc/eventlog).Log accepted only one string as argument and
(golang.org/x/sys/windows/svc/eventlog).report force 1 for the numStrings argument.

This results into messages like this:

It would be great, if golang.org/x/sys/windows/svc/eventlog would support sending events with 9 strings.
Using the generic error messages requires numStrings 9 as documented in LMErrlog.h

// The call to NetErrorWrite must set nstrings = 9, and provide 9
// ASCIIZ strings. If the caller does not have 9 insertion strings,
// provide null strings for the empty insertion strings.

[seankhliao]

we won't be able to change the existing signatures.
Do you have a specific API in mind for this?

[jkroepke]

A potential idea would be something with an s suffix, like InfoStrings, WarnStrings, ErrorStrings.

Details

func (l *Log) report(etype uint16, eid uint32, msgs []string) error {
  ss := []*uint16{}

  for _, msg := range msgs {
    ss = append(ss, syscall.StringToUTF16Ptr(msg))
  }
  return windows.ReportEvent(l.Handle, etype, 0, eid, 0, uint16(len(msgs)), 0, &ss[0], nil)
}

func (l *Log) Info(eid uint32, msg string) error {
  return l.report(windows.EVENTLOG_INFORMATION_TYPE, eid, []string{msg})
}

func (l *Log) Warning(eid uint32, msg string) error {
  return l.report(windows.EVENTLOG_WARNING_TYPE, eid, []string{msg})
}

func (l *Log) Error(eid uint32, msg string) error {
  return l.report(windows.EVENTLOG_ERROR_TYPE, eid, []string{msg})
}

func (l *Log) Infos(eid uint32, msgs []string) error {
  return l.report(windows.EVENTLOG_INFORMATION_TYPE, eid, msgs)
}

func (l *Log) Warnings(eid uint32, msgs []string) error {
  return l.report(windows.EVENTLOG_WARNING_TYPE, eid, msgs)
}

func (l *Log) Errors(eid uint32, msgs []string) error {
  return l.report(windows.EVENTLOG_ERROR_TYPE, eid, msgs)
}

Untested

This code does not change any exposed APIs.

[ianlancetaylor]

CC @golang/windows

[alexbrainman]

Sending logs tough golang.org/x/sys/windows/svc/eventlog are every limited.

I did not understand why it is limited.

... Windows has a builtin translation table based on the event id. The Log messages sent by golang.org/x/sys/windows/svc/eventlog are only viewable by the Details tab, since a translated message will be displayed in front of it.

It is unclear to me what you are trying to say here. Can you explain or provide more details? Maybe provide some examples or some steps for me to reproduce your problem.

golang.org/x/sys/windows/svc/eventlog calls ReportEvent Windows API and always pass single element array as lpStrings parameter. What you propose here is to pass multiple element strings instead. But Microsoft documentation says

[in] lpStrings

A pointer to a buffer containing an array of null-terminated strings that are merged into the message before Event Viewer displays the string to the user. ...

So your multiple strings will be merged into one string by Windows anyway. Why do you need to defer work of merging strings to Windows? Why cannot you just merge them into single string in your code and pass it into golang.org/x/sys/windows/svc/eventlog.Log.Info instead?

Alex

[jkroepke]

I did not understand why it is limited.

It's limited, because the numbers of string can't be configured. Some specific event id requires a specific amount of numstrings. For example the event id 3299 requires 9 numstrings.

If there are less then 9 numstrings, then the message on the Windows Event Logs contains place holders.

For example, if you send an messages with event id 3922 to windows event logs, the placeholder from the messages are still visible:

It is unclear to me what you are trying to say here. Can you explain or provide more details? Maybe provide some examples or some steps for me to reproduce your problem.

Sure. Here is the example code for demo purpose:

//go:build windows

package main

import (
	"syscall"

	"golang.org/x/sys/windows"
	"golang.org/x/sys/windows/svc/eventlog"
)

const (
	// NeLogOemCode is a generic error log entry for OEMs to use to
	// elog errors from OEM value added services.
	// See: https://github.com/microsoft/win32metadata/blob/2f3c5282ce1024a712aeccd90d3aa50bf7a49e27/generation/WinSDK/RecompiledIdlHeaders/um/LMErrlog.h#L824-L845
	neLogOemCode = uint32(3299)
)

var (
	nullString, _ = syscall.UTF16PtrFromString("")
)

func main() {
	msg := "This is a Message"

	logger, err := eventlog.Open("demo")
	if err != nil {
		panic(err)
	}

	for i := 1; i <= 10; i++ {
		err = logger.Info(uint32(i), msg)
		if err != nil {
			panic(err)
		}
	}

	err = logger.Info(neLogOemCode, msg)
	if err != nil {
		panic(err)
	}

	logMsg, err := syscall.UTF16PtrFromString(msg)
	if err != nil {
		panic(err)
	}

	ss := []*uint16{logMsg, nullString, nullString, nullString, nullString, nullString, nullString, nullString, nullString}

	err = windows.ReportEvent(logger.Handle, windows.EVENTLOG_INFORMATION_TYPE, 0, neLogOemCode, 0, 9, 0, &ss[0], nil)
	if err != nil {
		panic(err)
	}
}

I sent 12 messages to the windows event log. All messages are the same except the event id. Here are the results:

I got different visible messages on the General Tab. Windows has a builtin message file which bind error messages to specific event ids. The 8th parameter of the syscall ReportEventW holds the strings which can be merged into a message, if the message has place holders.

But Microsoft documentation says

[in] lpStrings
A pointer to a buffer containing an array of null-terminated strings that are merged into the message before Event Viewer displays the string to the user. ...

So your multiple strings will be merged into one string by Windows anyway. Why do you need to defer work of merging strings to Windows?

This is incorrect. The strings are not merged into one string. The strings are merged into one message and this messages are coming from a different source. First of all, each string will be saved separately in the entry. Here is an XML representation of entry with numStrings 9

The merge happens on the UI only, but its different as you might think. If you open the event viewer, the event viewer will load a registered message file (indicated by the EventMessageFile registry value for the source). Since go will NOT register a dedicated message file, the builtin message from Windows will be used. The message file can be localized and contains messages that are always reference a Event ID. Thats is the reason, why Incorrect function. is displayed for Event ID 1 and The storage control block address is invalid. for Event ID 9.

At the end, the Event Viewer will merge the message from the message file with the strings from the entry, if the messages insertion parameters. See wsprintfA about how the merging of strings and entry data works.

Reference: https://learn.microsoft.com/en-us/windows/win32/eventlog/viewing-the-event-log

The message for Event ID 3299 is %1 %2 %3 %4 %5 %6 %7 %8 %9. Microsoft has created a generic error log entry for OEMs to use to log errors from OEM value added services. The event code 3299 can be used by 3rd party application to report events without register an dedicated message file. For example, web servers Apache httpd and nginx are using this pattern to send readable log messages to Windows Event Log. In both cases, they sent 9 strings.

Thats the reason, why

	logger, _ := eventlog.Open("demo")
	logger.Info(2399, "This is a Message")

Results into a message like this This is a Message %2 %3 %4 %5 %6 %7 %8 %9. If logger.Info would sent 9 strings (1 message, 8 empty strings), it would result to this:

.

From my point of view, the number of strings should be configurable and not always be one.

[jkroepke]

@alexbrainman do you agree here?

[jkroepke]

@alexbrainman How to continue here?

[alexbrainman]

@jkroepke

All your examples are trying to use message file that is referred at https://github.com/microsoft/win32metadata/blob/2f3c5282ce1024a712aeccd90d3aa50bf7a49e27/generation/WinSDK/RecompiledIdlHeaders/um/LMErrlog.h#L824-L845 . But I say that the same functionality can be achieved by using %SystemRoot%\\System32\\EventCreate.exe (see https://github.com/golang/sys/blob/a1a9c4b846b3a485ba94fede5b50579c7f432759/windows/svc/eventlog/install.go#L70C23-L70C62 ) message file instead. Try to run this code https://github.com/golang/sys/blob/a1a9c4b846b3a485ba94fede5b50579c7f432759/windows/svc/eventlog/log_test.go#L21-L43 and tell me what the code cannot do that can be achieved by using message file that you referre.

Thank you.

Alex

[jkroepke]

@alexbrainman

I tried you code you mentioned and transfor it into a main package

Details

// Copyright 2012 The Go Authors. All rights reserved.
// Use of this source code is governed by a BSD-style
// license that can be found in the LICENSE file.

//go:build windows
// +build windows

package main

import (
	"golang.org/x/sys/windows/svc/eventlog"
	"log"
)

func main() {
	const name = "mylog"
	const supports = eventlog.Error | eventlog.Warning | eventlog.Info
	err := eventlog.InstallAsEventCreate(name, supports)
	if err != nil {
		log.Fatalf("Install failed: %s", err)
	}
	defer func() {
		err = eventlog.Remove(name)
		if err != nil {
			log.Fatalf("Remove failed: %s", err)
		}
	}()

	l, err := eventlog.Open(name)
	if err != nil {
		log.Fatalf("Open failed: %s", err)
	}
	defer l.Close()

	err = l.Info(1, "info")
	if err != nil {
		log.Fatalf("Info failed: %s", err)
	}
	err = l.Warning(2, "warning")
	if err != nil {
		log.Fatalf("Warning failed: %s", err)
	}
	err = l.Error(3, "error")
	if err != nil {
		log.Fatalf("Error failed: %s", err)
	}
}

But it failed on my system with the message:

2023/07/11 21:00:35 Install failed: Access denied

Calling the process %SystemRoot%\\System32\\EventCreate.exe requires admin permissions. If the Windows system has UAC enabled, the go programm is not able to sent event to Windows Event log, unless it runs with Admin permissions.

I also wants to quote the Windows documentation:

Enables an administrator to create a custom event in a specified event log.

---

Using the message based approch does not require any high priviliged permissions.

Details

//go:build windows

package main

import (
	"syscall"

	"golang.org/x/sys/windows"
	"golang.org/x/sys/windows/svc/eventlog"
)

const (
	// NeLogOemCode is a generic error log entry for OEMs to use to
	// elog errors from OEM value added services.
	// See: https://github.com/microsoft/win32metadata/blob/2f3c5282ce1024a712aeccd90d3aa50bf7a49e27/generation/WinSDK/RecompiledIdlHeaders/um/LMErrlog.h#L824-L845
	neLogOemCode = uint32(3299)
)

var (
	nullString, _ = syscall.UTF16PtrFromString("")
)

func main() {
	msg := "This is a Message"

	logger, err := eventlog.Open("demo")
	if err != nil {
		panic(err)
	}

	for i := 1; i <= 10; i++ {
		err = logger.Info(uint32(i), msg)
		if err != nil {
			panic(err)
		}
	}

	err = logger.Info(neLogOemCode, msg)
	if err != nil {
		panic(err)
	}

	logMsg, err := syscall.UTF16PtrFromString(msg)
	if err != nil {
		panic(err)
	}

	ss := []*uint16{logMsg, nullString, nullString, nullString, nullString, nullString, nullString, nullString, nullString}

	err = windows.ReportEvent(logger.Handle, windows.EVENTLOG_INFORMATION_TYPE, 0, neLogOemCode, 0, 9, 0, &ss[0], nil)
	if err != nil {
		panic(err)
	}
}

In conclusion, it cloud not agree with the statement

But I say that the same functionality can be achieved by using %SystemRoot%\System32\EventCreate.exe

In Windows, there is no such a fine-granted privliged model that we know from Linux. Capabilites doesn't exists on Windows.

Tbh, Microsoft introduced the event id 3299 for this use case. Other programs like nginx and Apache httpd already support this to sent event to the Windows Event Log without having the requirement of admin permissions.

I would really appreciate it, if x/sys would support this use-case, too.

[alexbrainman]

@jkroepke

I tried you code you mentioned and transfor it into a main package

Details
But it failed on my system with the message:

2023/07/11 21:00:35 Install failed: Access denied

Calling the process %SystemRoot%\\System32\\EventCreate.exe requires admin permissions.

Install failed: Access denied error message comes when your program tries to modify your registry and not when running %SystemRoot%\\System32\\EventCreate.exe process.

If the Windows system has UAC enabled, the go programm is not able to sent event to Windows Event log, unless it runs with Admin permissions.

It is expected to call eventlog.InstallAsEventCreate at the same time as you install your windows service. Both of these require you to be an Administrator. I think it is a reasonable expectation.

Tbh, Microsoft introduced the event id 3299 for this use case. Other programs like nginx and Apache httpd already support this to sent event to the Windows Event Log without having the requirement of admin permissions.

I would really appreciate it, if x/sys would support this use-case, too.

I am still unclear what exactly you are proposing. I suggest you prepare a CL with your changes. Perhaps it will clarify things for me. Thank you.

Alex

[jkroepke]

I am still unclear what exactly you are proposing.

As unpriviliged user, I want to sent readable events to Windows Eventlog.

Since EventCreate requries admin permission, it can not be used in this scenario. However, this is possible by create a event with Event ID 3299.

Ref: microsoft/win32metadata@2f3c528/generation/WinSDK/RecompiledIdlHeaders/um/LMErrlog.h#L824-L845

The message of event id 3299 requires 9 strings but x/sys/windows/svc/eventlog does only support 1 string.

[alexbrainman]

@jkroepke

I am still unclear what exactly you are proposing.

As unpriviliged user, I want to sent readable events to Windows Eventlog. ...

I am still unclear what exactly you are proposing.

Will your proposal require changing of code? If yes, please, prepare your change now as a CL, so we can see it now.

Thank you.

Alex

[jkroepke]

@alexbrainman Sure. here is the PR: golang/sys#168

[alexbrainman]

@alexbrainman Sure. here is the PR: golang/sys#168

I wanted to try to use your CL to log 3 event messages of info, warning and error types - similar to what golang.org/x/sys/windows/svc/eventlog.TestLog does.

I adjusted your CL this way

diff --git a/windows/svc/eventlog/log_test.go b/windows/svc/eventlog/log_test.go
index a667b8fb..d08581c6 100644
--- a/windows/svc/eventlog/log_test.go
+++ b/windows/svc/eventlog/log_test.go
@@ -19,17 +19,8 @@ func TestLog(t *testing.T) {
 	}
 
 	const name = "mylog"
-	const supports = eventlog.Error | eventlog.Warning | eventlog.Info
-	err := eventlog.InstallAsEventCreate(name, supports)
-	if err != nil {
-		t.Fatalf("Install failed: %s", err)
-	}
-	defer func() {
-		err = eventlog.Remove(name)
-		if err != nil {
-			t.Fatalf("Remove failed: %s", err)
-		}
-	}()
+
+	const neLogOemCode = uint32(3299)
 
 	l, err := eventlog.Open(name)
 	if err != nil {
@@ -37,15 +28,15 @@ func TestLog(t *testing.T) {
 	}
 	defer l.Close()
 
-	err = l.Info(1, "info")
+	err = l.Info(neLogOemCode, "info")
 	if err != nil {
 		t.Fatalf("Info failed: %s", err)
 	}
-	err = l.Warning(2, "warning")
+	err = l.Warning(neLogOemCode, "warning")
 	if err != nil {
 		t.Fatalf("Warning failed: %s", err)
 	}
-	err = l.Error(3, "error")
+	err = l.Error(neLogOemCode, "error")
 	if err != nil {
 		t.Fatalf("Error failed: %s", err)
 	}

And after I run my test, I can see this in the log

I don't want to see %2 %3 %4 %5 %6 %7 %8 %8. at the end of my error message. I just want to see my error message.

How do I do that? Perhaps

I still misunderstand what you are proposing, so correct me.

Thank you.

Alex

[jkroepke]

I don't want to see %2 %3 %4 %5 %6 %7 %8 %8. at the end of my error message.

Correct, that is the root cause of the whole issue here.

Since 3299 requires 9 strings in total, you have to define 9 strings in your message in the same way as the Event Log API require this.

err = l.Error(neLogOemCode, "error", "", "", "", "", "", "", "", "")

It's not possible to add auto-fill up to 9 strings, since different events requires different amounts of message strings.

[alexbrainman]

Correct, that is the root cause of the whole issue here.

I still don't understand what the issue is. What will remain broken if your proposal gets rejected?

Alex

[jkroepke]

The %2 %3 %4 %5 %6 %7 %8 %9 remains visible at the end of error message.

@alexbrainman To understand my proposal, apply golang/sys#168 and execute

err = l.Error(neLogOemCode, "error", "", "", "", "", "", "", "", "")

Then, go to the event log and see the difference on the event log message.

[alexbrainman]

@alexbrainman To understand my proposal, apply golang/sys#168 and execute

err = l.Error(neLogOemCode, "error", "", "", "", "", "", "", "", "")

Then, go to the event log and see the difference on the event log message.

I did. I still don't understand what the issue is. What will remain broken if your proposal gets rejected?

Alex

[jkroepke]

The messages in the event log remains broken, if the proposal gets rejected.

Did you try the mention example and validate the difference on your end?

[alexbrainman]

The messages in the event log remains broken, if the proposal gets rejected.

What message gets broken?

Did you try the mention example

I did.

... and validate the difference on your end?

What am I looking for?

Alex

[jkroepke]

What message gets broken?

The event id 3299 requires 9 message strings. The %2 %3 %4 %5 %6 %7 %8 %9 remains visible, since the messages gets to few message string and the event log entry is broken then.

If my proposal get rejected, you are not able to send more than one message strings. Please show me, how to sent a message to the Windows Event Log without admin permissions, using the Event ID 3299. The even log entry on the Event viewer should not have the %2 %3 %4 %5 %6 %7 %8 %9 placeholders.

[jkroepke]

@alexbrainman

Did you try the mention example

I did.

So, if you run err = l.Error(neLogOemCode, "error", "", "", "", "", "", "", "", "") and look on the event viewer and compare the entry with your screenshot

Did you see any the difference?

[alexbrainman]

If my proposal get rejected, you are not able to send more than one message strings. Please show me, how to sent a message to the Windows Event Log without admin permissions, using the Event ID 3299. The even log entry on the Event viewer should not have the %2 %3 %4 %5 %6 %7 %8 %9 placeholders.

This package is not designed for that. I suggest you copy the code and do what you like with it.

Alex

[jkroepke]

Hi alex,

i'm not happy which the current process here.

Is there an additional golang maintainer for windows who look into this?

Thanks.

[alexbrainman]

i'm not happy which the current process here.

Sorry to hear that.

Is there an additional golang maintainer for windows who look into this?

I do not know that. Hopefully others will comment.

Alex

[jkroepke]

Hi @ianlancetaylor, I would appreciate a review here.

Please let me know, if you need more context here.

Patchset: golang/sys#168

The Windows Event Log based on predefined messages. Each Event ID has a own message.

The windows syscall for the eventlog allows to create an event with an specific ID and multiple strings (or placeholders).

Microsoft has created a special event ID 3299. The event has the message "%1 %2 %3 %4 %5 %6 %7
%8 %9" and is designed for OEMs to create event log entries without having the requirement of pre-register own message tables. The web server apache https and nginx are using this pattern to setup readable log messages.

With my propasal, I want to change the design of x/sys to support this scenario. x/sys only supports one placeholder while the event api syscall supports up to 9.

The change is backwards compatible. Existing code still work after my proposal has been accepted.

Thanks,
Jan

[ianlancetaylor]

Your proposed change is not strictly backward compatible. But I'm not really opposed to something like that. @alexbrainman Do you see any problem with a change along these lines adding new methods? I don't see one. Even if not many people use it.

[alexbrainman]

@alexbrainman Do you see any problem with a change along these lines adding new methods?

@ianlancetaylor

Why should we add any methods?

If we proceed with

https://go-review.googlesource.com/c/sys/+/512315

then people will be confused about how to use Log.Error and others. This example shows that users should use single string that will be displayed in event log as is. If the user adjusts the example above to have 2 or more string parameters, like this

l.Error(3, "error1", "error2", "error3")

then they will discover that only "error1" is output to the log and both "error2" and "error3" are just ignored.

If we are proposing something different from

https://go-review.googlesource.com/c/sys/+/512315

then let's hear it.

And why do we need second way to achieve the same result?

When I created this package I tried to keep design simple - allow user to output a text string as event log error or warning or info.

And if someone needs to support event id 3922 from default event source file, then they can just use Windows API for that - it is one line change. See the line that contains "windows.ReportEvent" in the example code for demo purpose from #59780 (comment) .

Alex