Rearrange etw packages

pkg/etw/etw.go

@@ -0,0 +1,14 @@
+// Package etw provides support for TraceLogging-based ETW (Event Tracing
+// for Windows). TraceLogging is a format of ETW events that are self-describing
+// (the event contains information on its own schema). This allows them to be
+// decoded without needing a separate manifest with event information. The
+// implementation here is based on the information found in
+// TraceLoggingProvider.h in the Windows SDK, which implements TraceLogging as a
+// set of C macros.
+package etw
+
+//go:generate go run $GOROOT/src/syscall/mksyscall_windows.go -output zsyscall_windows.go etw.go
+
+//sys eventRegister(providerId *windows.GUID, callback uintptr, callbackContext uintptr, providerHandle *providerHandle) (win32err error) = advapi32.EventRegister
+//sys eventUnregister(providerHandle providerHandle) (win32err error) = advapi32.EventUnregister
+//sys eventWriteTransfer(providerHandle providerHandle, descriptor *EventDescriptor, activityID *windows.GUID, relatedActivityID *windows.GUID, dataDescriptorCount uint32, dataDescriptors *eventDataDescriptor) (win32err error) = advapi32.EventWriteTransfer

pkg/etw/event.go

@@ -0,0 +1,89 @@
+package etw
+
+// Channel represents the ETW logging channel that is used. It can be used by
+// event consumers to give an event special treatment.
+type Channel uint8
+
+const (
+	// ChannelTraceLogging is the default channel for TraceLogging events. It is
+	// not required to be used for TraceLogging, but will prevent decoding
+	// issues for these events on older operating systems.
+	ChannelTraceLogging Channel = 11
+)
+
+// Level represents the ETW logging level. There are several predefined levels
+// that are commonly used, but technically anything from 0-255 is allowed.
+// Lower levels indicate more important events, and 0 indicates an event that
+// will always be collected.
+type Level uint8
+
+// Predefined ETW log levels.
+const (
+	LevelAlways Level = iota
+	LevelCritical
+	LevelError
+	LevelWarning
+	LevelInfo
+	LevelVerbose
+)
+
+// Event represents a single ETW event. It can have field metadata and data
+// added to it, and then be logged via a provider to actually send it to ETW.
+type Event struct {
+	Descriptor *EventDescriptor
+	Metadata   *EventMetadata
+	Data       *EventData
+}
+
+// NewEvent returns a new instance of an event object.
+func NewEvent(name string, descriptor *EventDescriptor) *Event {
+	return &Event{
+		Descriptor: descriptor,
+		Metadata:   NewEventMetadata(name),
+		Data:       &EventData{},
+	}
+}
+
+// EventDescriptor represents various metadata for an ETW event.
+type EventDescriptor struct {
+	id      uint16
+	version uint8
+	Channel Channel
+	Level   Level
+	Opcode  uint8
+	Task    uint16
+	Keyword uint64
+}
+
+// NewEventDescriptor returns an EventDescriptor initialized for use with
+// TraceLogging.
+func NewEventDescriptor() *EventDescriptor {
+	// Standard TraceLogging events default to the TraceLogging channel, and
+	// verbose level.
+	return &EventDescriptor{
+		id:      0,
+		version: 0,
+		Channel: ChannelTraceLogging,
+		Level:   LevelVerbose,
+		Opcode:  0,
+		Task:    0,
+		Keyword: 0,
+	}
+}
+
+// Identity returns the identity of the event. If the identity is not 0, it
+// should uniquely identify the other event metadata (contained in
+// EventDescriptor, and field metadata). Only the lower 24 bits of this value
+// are relevant.
+func (ed *EventDescriptor) Identity() uint32 {
+	return (uint32(ed.version) << 16) & uint32(ed.id)
+}
+
+// SetIdentity sets the identity of the event. If the identity is not 0, it
+// should uniquely identify the other event metadata (contained in
+// EventDescriptor, and field metadata). Only the lower 24 bits of this value
+// are relevant.
+func (ed *EventDescriptor) SetIdentity(identity uint32) {
+	ed.id = uint16(identity)
+	ed.version = uint8(identity >> 16)
+}

pkg/etw/eventdata.go

@@ -0,0 +1,23 @@
+package etw
+
+import (
+	"bytes"
+	"encoding/binary"
+)
+
+// EventData maintains a buffer which builds up the data for an ETW event. It
+// needs to be paired with EventMetadata which describes the event.
+type EventData struct {
+	buffer bytes.Buffer
+}
+
+// NewEventData returns a new EventData with an empty buffer.
+func NewEventData() *EventData {
+	return &EventData{}
+}
+
+// AddString appends the data for a string to the end of the buffer.
+func (ed *EventData) AddString(data string) {
+	binary.Write(&ed.buffer, binary.LittleEndian, []byte(data))
+	binary.Write(&ed.buffer, binary.LittleEndian, byte(0))
+}

pkg/etw/eventmetadata.go

@@ -0,0 +1,51 @@
+package etw
+
+import (
+	"bytes"
+	"encoding/binary"
+)
+
+// InType indicates the type of data contained in the ETW event.
+type InType byte
+
+// Various InType definitions for TraceLogging.
+const (
+	InTypeNull InType = iota
+	InTypeUnicodeString
+	InTypeAnsiString
+	InTypeInt8
+	InTypeUint8
+	InTypeInt16
+	InTypeUint16
+	InTypeInt32
+	InTypeUint32
+	InTypeInt64
+	InTypeUint64
+	InTypeFloat
+	InTypeDouble
+	InTypeBool32
+)
+
+// EventMetadata maintains a buffer which builds up the metadatadata for an ETW
+// event. It needs to be paired with EventData which describes the event.
+type EventMetadata struct {
+	buffer bytes.Buffer
+}
+
+// NewEventMetadata returns a new EventMetadata with event name and initial
+// metadata written to the buffer.
+func NewEventMetadata(name string) *EventMetadata {
+	em := EventMetadata{}
+	binary.Write(&em.buffer, binary.LittleEndian, uint16(0))    // Length placeholder
+	binary.Write(&em.buffer, binary.LittleEndian, byte(0))      // Tags
+	binary.Write(&em.buffer, binary.LittleEndian, []byte(name)) // Event name
+	binary.Write(&em.buffer, binary.LittleEndian, byte(0))      // Null terminator for name
+	return &em
+}
+
+// AddField appends a single field to the end of the event metadata buffer.
+func (em *EventMetadata) AddField(name string, inType InType) {
+	binary.Write(&em.buffer, binary.LittleEndian, []byte(name)) // Field name
+	binary.Write(&em.buffer, binary.LittleEndian, byte(0))      // Null terminator for name
+	binary.Write(&em.buffer, binary.LittleEndian, byte(inType)) // In type
+}

pkg/etw/provider.go

@@ -0,0 +1,107 @@
+package etw
+
+import (
+	"bytes"
+	"encoding/binary"
+	"unsafe"
+
+	"golang.org/x/sys/windows"
+)
+
+type eventDataDescriptorType uint8
+
+const (
+	eventDataDescriptorTypeUserData eventDataDescriptorType = iota
+	eventDataDescriptorTypeEventMetadata
+	eventDataDescriptorTypeProviderMetadata
+)
+
+// Provider represents an ETW event provider. It is identified by a provider
+// name and ID (GUID), which should always have a 1:1 mapping to each other
+// (e.g. don't use multiple provider names with the same ID, or vice versa).
+type Provider struct {
+	handle   providerHandle
+	metadata *bytes.Buffer
+}
+
+type providerHandle windows.Handle
+
+// ProviderState informs the provider EnableCallback what action is being
+// performed.
+type ProviderState uint32
+
+const (
+	// ProviderStateDisable indicates the provider is being disabled.
+	ProviderStateDisable ProviderState = iota
+	// ProviderStateEnable indicates the provider is being enabled.
+	ProviderStateEnable
+	// ProviderStateCaptureState indicates the provider is having its current
+	// state snap-shotted.
+	ProviderStateCaptureState
+)
+
+// EnableCallback is the form of the callback function that receives provider
+// enable/disable notifications from ETW.
+type EnableCallback func(*windows.GUID, ProviderState, Level, uint64, uint64, uintptr)
+
+type eventDataDescriptor struct {
+	ptr       uint64
+	size      uint32
+	dataType  eventDataDescriptorType
+	reserved1 uint8
+	reserved2 uint16
+}
+
+func (descriptor *eventDataDescriptor) set(dataType eventDataDescriptorType, buffer *bytes.Buffer) {
+	// Passing a pointer to Go-managed memory as part of a block of memory is
+	// risky since the GC doesn't know about it. If we find a better way to do
+	// this we should use it instead.
+	descriptor.ptr = uint64(uintptr(unsafe.Pointer(&buffer.Bytes()[0])))
+	descriptor.size = uint32(buffer.Len())
+	descriptor.dataType = dataType
+}
+
+// NewProvider creates and registers a new provider.
+func NewProvider(name string, id *windows.GUID, callback EnableCallback) (*Provider, error) {
+	innerCallback := func(sourceID *windows.GUID, state ProviderState, level Level, matchAnyKeyword uint64, matchAllKeyword uint64, filterData uintptr, _ uintptr) uintptr {
+		if callback != nil {
+			callback(sourceID, state, level, matchAnyKeyword, matchAllKeyword, filterData)
+		}
+		return 0
+	}
+
+	var providerHandle providerHandle
+	if err := eventRegister(id, windows.NewCallback(innerCallback), 0, &providerHandle); err != nil {
+		return nil, err
+	}
+
+	var metadataBuffer bytes.Buffer
+	binary.Write(&metadataBuffer, binary.LittleEndian, uint16(0))                       // Write empty size for buffer (to update later)
+	binary.Write(&metadataBuffer, binary.LittleEndian, []byte(name))                    // Provider name
+	binary.Write(&metadataBuffer, binary.LittleEndian, byte(0))                         // Null terminator for name
+	binary.LittleEndian.PutUint16(metadataBuffer.Bytes(), uint16(metadataBuffer.Len())) // Update the size at the beginning of the buffer
+
+	return &Provider{
+		handle:   providerHandle,
+		metadata: &metadataBuffer,
+	}, nil
+}
+
+// Close unregisters the provider.
+func (provider *Provider) Close() error {
+	return eventUnregister(provider.handle)
+}
+
+// WriteEvent writes a single event to ETW, from this provider.
+func (provider *Provider) WriteEvent(event *Event) error {
+	// Finalize the event metadata buffer by filling in the buffer length at the
+	// beginning.
+	binary.LittleEndian.PutUint16(event.Metadata.buffer.Bytes(), uint16(event.Metadata.buffer.Len()))
+
+	var dataDescriptors [3]eventDataDescriptor
+	dataDescriptors[0].set(eventDataDescriptorTypeProviderMetadata, provider.metadata)
+	dataDescriptors[1].set(eventDataDescriptorTypeEventMetadata, &event.Metadata.buffer)
+	dataDescriptors[2].set(eventDataDescriptorTypeUserData, &event.Data.buffer)
+
+	return eventWriteTransfer(provider.handle, event.Descriptor, nil, nil, 3, &dataDescriptors[0])
+}

pkg/etw/sample/sample.go

@@ -0,0 +1,53 @@
+// Shows a sample usage of the ETW logging package.
+package main
+
+import (
+	"bufio"
+	"fmt"
+	"os"
+
+	"github.com/Microsoft/go-winio/pkg/etw"
+	"github.com/sirupsen/logrus"
+
+	"golang.org/x/sys/windows"
+)
+
+func callback(sourceID *windows.GUID, state etw.ProviderState, level etw.Level, matchAnyKeyword uint64, matchAllKeyword uint64, filterData uintptr) {
+	fmt.Printf("Callback: isEnabled=%d, level=%d, matchAnyKeyword=%d\n", state, level, matchAnyKeyword)
+}
+
+func main() {
+	providerID := windows.GUID{0xdd2062c6, 0x5d1b, 0x4a0f, [8]uint8{0xbd, 0xb9, 0x22, 0x28, 0xbc, 0xb1, 0x07, 0x7c}}
+
+	provider, err := etw.NewProvider("TestProvider", &providerID, callback)
+	if err != nil {
+		logrus.Error(err)
+		return
+	}
+	defer func() {
+		if err := provider.Close(); err != nil {
+			logrus.Error(err)
+		}
+	}()
+
+	reader := bufio.NewReader(os.Stdin)
+
+	fmt.Println("Press enter to log an event")
+	reader.ReadString('\n')
+
+	event := etw.NewEvent("TestEvent", etw.NewEventDescriptor())
+	event.Metadata.AddField("TestField", etw.InTypeAnsiString)
+	event.Data.AddString("Foo")
+	event.Metadata.AddField("TestField2", etw.InTypeAnsiString)
+	event.Data.AddString("Bar")
+
+	if err := provider.WriteEvent(event); err != nil {
+		fmt.Println(err)
+		return
+	}
+
+	fmt.Println("Event written")
+
+	fmt.Println("Press enter to exit")
+	reader.ReadString('\n')
+}

pkg/etw/zsyscall_windows.go

@@ -0,0 +1,69 @@
+// Code generated by 'go generate'; DO NOT EDIT.
+
+package etw
+
+import (
+	"syscall"
+	"unsafe"
+
+	"golang.org/x/sys/windows"
+)
+
+var _ unsafe.Pointer
+
+// Do the interface allocations only once for common
+// Errno values.
+const (
+	errnoERROR_IO_PENDING = 997
+)
+
+var (
+	errERROR_IO_PENDING error = syscall.Errno(errnoERROR_IO_PENDING)
+)
+
+// errnoErr returns common boxed Errno values, to prevent
+// allocations at runtime.
+func errnoErr(e syscall.Errno) error {
+	switch e {
+	case 0:
+		return nil
+	case errnoERROR_IO_PENDING:
+		return errERROR_IO_PENDING
+	}
+	// TODO: add more here, after collecting data on the common
+	// error values see on Windows. (perhaps when running
+	// all.bat?)
+	return e
+}
+
+var (
+	modadvapi32 = windows.NewLazySystemDLL("advapi32.dll")
+
+	procEventRegister      = modadvapi32.NewProc("EventRegister")
+	procEventUnregister    = modadvapi32.NewProc("EventUnregister")
+	procEventWriteTransfer = modadvapi32.NewProc("EventWriteTransfer")
+)
+
+func eventRegister(providerId *windows.GUID, callback uintptr, callbackContext uintptr, providerHandle *providerHandle) (win32err error) {
+	r0, _, _ := syscall.Syscall6(procEventRegister.Addr(), 4, uintptr(unsafe.Pointer(providerId)), uintptr(callback), uintptr(callbackContext), uintptr(unsafe.Pointer(providerHandle)), 0, 0)
+	if r0 != 0 {
+		win32err = syscall.Errno(r0)
+	}
+	return
+}
+
+func eventUnregister(providerHandle providerHandle) (win32err error) {
+	r0, _, _ := syscall.Syscall(procEventUnregister.Addr(), 1, uintptr(providerHandle), 0, 0)
+	if r0 != 0 {
+		win32err = syscall.Errno(r0)
+	}
+	return
+}
+
+func eventWriteTransfer(providerHandle providerHandle, descriptor *EventDescriptor, activityID *windows.GUID, relatedActivityID *windows.GUID, dataDescriptorCount uint32, dataDescriptors *eventDataDescriptor) (win32err error) {
+	r0, _, _ := syscall.Syscall6(procEventWriteTransfer.Addr(), 6, uintptr(providerHandle), uintptr(unsafe.Pointer(descriptor)), uintptr(unsafe.Pointer(activityID)), uintptr(unsafe.Pointer(relatedActivityID)), uintptr(dataDescriptorCount), uintptr(unsafe.Pointer(dataDescriptors)))
+	if r0 != 0 {
+		win32err = syscall.Errno(r0)
+	}
+	return
+}

pkg/etwlogrus/hook.go

@@ -0,0 +1,78 @@
+package etwlogrus
+
+import (
+	"fmt"
+	"reflect"
+
+	"github.com/Microsoft/go-winio/pkg/etw"
+	"github.com/sirupsen/logrus"
+
+	"golang.org/x/sys/windows"
+)
+
+// Hook is a Logrus hook which logs received events to ETW.
+type Hook struct {
+	provider *etw.Provider
+}
+
+// NewHook registers a new ETW provider and returns a hook to log from it.
+func NewHook(providerName string, providerID *windows.GUID) (*Hook, error) {
+	hook := Hook{}
+
+	provider, err := etw.NewProvider(providerName, providerID, nil)
+	if err != nil {
+		return nil, err
+	}
+	hook.provider = provider
+
+	return &hook, nil
+}
+
+// Levels returns the set of levels that this hook wants to receive log entries
+// for.
+func (h *Hook) Levels() []logrus.Level {
+	return []logrus.Level{
+		logrus.TraceLevel,
+		logrus.DebugLevel,
+		logrus.InfoLevel,
+		logrus.WarnLevel,
+		logrus.ErrorLevel,
+		logrus.FatalLevel,
+		logrus.PanicLevel,
+	}
+}
+
+// Fire receives each Logrus entry as it is logged, and logs it to ETW.
+func (h *Hook) Fire(e *logrus.Entry) error {
+	descriptor := etw.NewEventDescriptor()
+
+	// We could try to map Logrus levels to ETW levels, but we would lose some
+	// fidelity as there are fewer ETW levels. So instead we use the level
+	// directly.
+	descriptor.Level = etw.Level(e.Level)
+
+	event := etw.NewEvent("LogrusEntry", descriptor)
+
+	event.Metadata.AddField("Message", etw.InTypeAnsiString)
+	event.Data.AddString(e.Message)
+
+	for k, v := range e.Data {
+		switch reflect.TypeOf(v).Kind() {
+		case reflect.String:
+			event.Metadata.AddField(k, etw.InTypeAnsiString)
+			event.Data.AddString(v.(string))
+		default:
+			event.Metadata.AddField(k, etw.InTypeAnsiString)
+			event.Data.AddString(fmt.Sprintf("<unknown type: %v> %v", reflect.TypeOf(v), v))
+		}
+	}
+
+	h.provider.WriteEvent(event)
+
+	return nil
+}
+
+// Close cleans up the hook and closes the ETW provider.
+func (h *Hook) Close() error {
+	return h.provider.Close()
+}