diff --git a/etw/etw.go b/etw/etw.go new file mode 100644 index 0000000..e60a8fa --- /dev/null +++ b/etw/etw.go @@ -0,0 +1,7 @@ +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 diff --git a/etw/event.go b/etw/event.go new file mode 100644 index 0000000..5639d0a --- /dev/null +++ b/etw/event.go @@ -0,0 +1,54 @@ +package etw + +type Channel uint8 + +const ( + ChannelTracelogging Channel = 11 +) + +type Level uint8 + +const ( + LevelAlways Level = iota + LevelCritical + LevelError + LevelWarning + LevelInfo + LevelVerbose +) + +type Event struct { + Descriptor *EventDescriptor + Metadata *EventMetadata + Data *EventData +} + +type EventDescriptor struct { + ID uint16 + Version uint8 + Channel Channel + Level Level + Opcode uint8 + Task uint16 + Keyword uint64 +} + +func NewEventDescriptor() *EventDescriptor { + return &EventDescriptor{ + ID: 0, + Version: 0, + Channel: ChannelTracelogging, + Level: LevelVerbose, + Opcode: 0, + Task: 0, + Keyword: 0, + } +} + +func NewEvent(name string, descriptor *EventDescriptor) *Event { + return &Event{ + Descriptor: descriptor, + Metadata: NewEventMetadata(name), + Data: &EventData{}, + } +} diff --git a/etw/eventdata.go b/etw/eventdata.go new file mode 100644 index 0000000..9fc5c4d --- /dev/null +++ b/etw/eventdata.go @@ -0,0 +1,15 @@ +package etw + +import ( + "bytes" + "encoding/binary" +) + +type EventData struct { + buffer bytes.Buffer +} + +func (ed *EventData) AddString(data string) { + binary.Write(&ed.buffer, binary.LittleEndian, []byte(data)) + binary.Write(&ed.buffer, binary.LittleEndian, byte(0)) +} diff --git a/etw/eventmetadata.go b/etw/eventmetadata.go new file mode 100644 index 0000000..9c480d6 --- /dev/null +++ b/etw/eventmetadata.go @@ -0,0 +1,44 @@ +package etw + +import ( + "bytes" + "encoding/binary" +) + +type InType byte + +const ( + InTypeNull InType = iota + InTypeUnicodeString + InTypeAnsiString + InTypeInt8 + InTypeUint8 + InTypeInt16 + InTypeUint16 + InTypeInt32 + InTypeUint32 + InTypeInt64 + InTypeUint64 + InTypeFloat + InTypeDouble + InTypeBool32 +) + +type EventMetadata struct { + buffer bytes.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 +} + +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 +} diff --git a/etw/logrus/hook.go b/etw/logrus/hook.go new file mode 100644 index 0000000..7fec697 --- /dev/null +++ b/etw/logrus/hook.go @@ -0,0 +1,78 @@ +package hook + +import ( + "fmt" + "reflect" + + "github.com/Microsoft/go-winio/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(" %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() +} diff --git a/etw/provider.go b/etw/provider.go new file mode 100644 index 0000000..47521eb --- /dev/null +++ b/etw/provider.go @@ -0,0 +1,87 @@ +package etw + +import ( + "bytes" + "encoding/binary" + "unsafe" + + "golang.org/x/sys/windows" +) + +type eventDataDescriptorType uint8 + +const ( + eventDataDescriptorTypeUserData eventDataDescriptorType = iota + eventDataDescriptorTypeEventMetadata + eventDataDescriptorTypeProviderMetadata +) + +type Provider struct { + handle providerHandle + metadata *bytes.Buffer +} + +type providerHandle windows.Handle + +type EnableCallback func(*windows.GUID, uint32, byte, 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, isEnabled uint32, level byte, matchAnyKeyword uint64, matchAllKeyword uint64, filterData uintptr, _ uintptr) uintptr { + if callback != nil { + callback(sourceID, isEnabled, 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)) + binary.Write(&metadataBuffer, binary.LittleEndian, []byte(name)) + binary.Write(&metadataBuffer, binary.LittleEndian, byte(0)) + binary.LittleEndian.PutUint16(metadataBuffer.Bytes(), uint16(metadataBuffer.Len())) + + 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]) +} diff --git a/etw/sample/sample.go b/etw/sample/sample.go new file mode 100644 index 0000000..46850dc --- /dev/null +++ b/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/etw" + "github.com/sirupsen/logrus" + + "golang.org/x/sys/windows" +) + +func callback(sourceID *windows.GUID, isEnabled uint32, level byte, matchAnyKeyword uint64, matchAllKeyword uint64, filterData uintptr) { + fmt.Printf("Callback: isEnabled=%d, level=%d, matchAnyKeyword=%d\n", isEnabled, 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') +} diff --git a/etw/zsyscall_windows.go b/etw/zsyscall_windows.go new file mode 100644 index 0000000..5b044ca --- /dev/null +++ b/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 +}