Merge pull request #3217 from kevpar/etw-capture-state

Enable dumping Goroutine stacks via ETW capture state
This commit is contained in:
John Howard 2019-04-15 14:19:46 -07:00 committed by GitHub
commit cc73dc3dbd
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
10 changed files with 505 additions and 268 deletions

View File

@ -24,7 +24,9 @@ import (
"unsafe" "unsafe"
winio "github.com/Microsoft/go-winio" winio "github.com/Microsoft/go-winio"
"github.com/Microsoft/go-winio/pkg/etw"
"github.com/Microsoft/go-winio/pkg/etwlogrus" "github.com/Microsoft/go-winio/pkg/etwlogrus"
"github.com/Microsoft/go-winio/pkg/guid"
"github.com/containerd/containerd/log" "github.com/containerd/containerd/log"
"github.com/containerd/containerd/services/server" "github.com/containerd/containerd/services/server"
"github.com/sirupsen/logrus" "github.com/sirupsen/logrus"
@ -91,11 +93,25 @@ func setupDumpStacks() {
}() }()
} }
func init() { func etwCallback(sourceID *guid.GUID, state etw.ProviderState, level etw.Level, matchAnyKeyword uint64, matchAllKeyword uint64, filterData uintptr) {
// Provider ID: {2acb92c0-eb9b-571a-69cf-8f3410f383ad} if state == etw.ProviderStateCaptureState {
// Hook isn't closed explicitly, as it will exist until process exit. dumpStacks()
// GUID is generated based on name - see Microsoft/go-winio/tools/etw-provider-gen. }
if hook, err := etwlogrus.NewHook("ContainerD"); err == nil { }
logrus.AddHook(hook)
func init() {
// Provider ID: 2acb92c0-eb9b-571a-69cf-8f3410f383ad
// Provider and hook aren't closed explicitly, as they will exist until
// process exit. GUID is generated based on name - see
// Microsoft/go-winio/tools/etw-provider-gen.
provider, err := etw.NewProvider("ContainerD", etwCallback)
if err != nil {
logrus.Error(err)
} else {
if hook, err := etwlogrus.NewHookFromProvider(provider); err == nil {
logrus.AddHook(hook)
} else {
logrus.Error(err)
}
} }
} }

View File

@ -33,7 +33,7 @@ github.com/opencontainers/image-spec v1.0.1
golang.org/x/sync 42b317875d0fa942474b76e1b46a6060d720ae6e golang.org/x/sync 42b317875d0fa942474b76e1b46a6060d720ae6e
github.com/BurntSushi/toml v0.3.1 github.com/BurntSushi/toml v0.3.1
github.com/grpc-ecosystem/go-grpc-prometheus 6b7015e65d366bf3f19b2b2a000a831940f0f7e0 github.com/grpc-ecosystem/go-grpc-prometheus 6b7015e65d366bf3f19b2b2a000a831940f0f7e0
github.com/Microsoft/go-winio c599b533b43b1363d7d7c6cfda5ede70ed73ff13 github.com/Microsoft/go-winio 84b4ab48a50763fe7b3abcef38e5205c12027fac
github.com/Microsoft/hcsshim 8abdbb8205e4192c68b5f84c31197156f31be517 github.com/Microsoft/hcsshim 8abdbb8205e4192c68b5f84c31197156f31be517
google.golang.org/genproto d80a6e20e776b0b17a324d0ba1ab50a39c8e8944 google.golang.org/genproto d80a6e20e776b0b17a324d0ba1ab50a39c8e8944
golang.org/x/text 19e51611da83d6be54ddafce4a4af510cb3e9ea4 golang.org/x/text 19e51611da83d6be54ddafce4a4af510cb3e9ea4

View File

@ -3,10 +3,13 @@
package winio package winio
import ( import (
"context"
"errors" "errors"
"fmt"
"io" "io"
"net" "net"
"os" "os"
"runtime"
"syscall" "syscall"
"time" "time"
"unsafe" "unsafe"
@ -18,6 +21,48 @@ import (
//sys getNamedPipeInfo(pipe syscall.Handle, flags *uint32, outSize *uint32, inSize *uint32, maxInstances *uint32) (err error) = GetNamedPipeInfo //sys getNamedPipeInfo(pipe syscall.Handle, flags *uint32, outSize *uint32, inSize *uint32, maxInstances *uint32) (err error) = GetNamedPipeInfo
//sys getNamedPipeHandleState(pipe syscall.Handle, state *uint32, curInstances *uint32, maxCollectionCount *uint32, collectDataTimeout *uint32, userName *uint16, maxUserNameSize uint32) (err error) = GetNamedPipeHandleStateW //sys getNamedPipeHandleState(pipe syscall.Handle, state *uint32, curInstances *uint32, maxCollectionCount *uint32, collectDataTimeout *uint32, userName *uint16, maxUserNameSize uint32) (err error) = GetNamedPipeHandleStateW
//sys localAlloc(uFlags uint32, length uint32) (ptr uintptr) = LocalAlloc //sys localAlloc(uFlags uint32, length uint32) (ptr uintptr) = LocalAlloc
//sys ntCreateNamedPipeFile(pipe *syscall.Handle, access uint32, oa *objectAttributes, iosb *ioStatusBlock, share uint32, disposition uint32, options uint32, typ uint32, readMode uint32, completionMode uint32, maxInstances uint32, inboundQuota uint32, outputQuota uint32, timeout *int64) (status ntstatus) = ntdll.NtCreateNamedPipeFile
//sys rtlNtStatusToDosError(status ntstatus) (winerr error) = ntdll.RtlNtStatusToDosErrorNoTeb
//sys rtlDosPathNameToNtPathName(name *uint16, ntName *unicodeString, filePart uintptr, reserved uintptr) (status ntstatus) = ntdll.RtlDosPathNameToNtPathName_U
//sys rtlDefaultNpAcl(dacl *uintptr) (status ntstatus) = ntdll.RtlDefaultNpAcl
type ioStatusBlock struct {
Status, Information uintptr
}
type objectAttributes struct {
Length uintptr
RootDirectory uintptr
ObjectName *unicodeString
Attributes uintptr
SecurityDescriptor *securityDescriptor
SecurityQoS uintptr
}
type unicodeString struct {
Length uint16
MaximumLength uint16
Buffer uintptr
}
type securityDescriptor struct {
Revision byte
Sbz1 byte
Control uint16
Owner uintptr
Group uintptr
Sacl uintptr
Dacl uintptr
}
type ntstatus int32
func (status ntstatus) Err() error {
if status >= 0 {
return nil
}
return rtlNtStatusToDosError(status)
}
const ( const (
cERROR_PIPE_BUSY = syscall.Errno(231) cERROR_PIPE_BUSY = syscall.Errno(231)
@ -25,21 +70,20 @@ const (
cERROR_PIPE_CONNECTED = syscall.Errno(535) cERROR_PIPE_CONNECTED = syscall.Errno(535)
cERROR_SEM_TIMEOUT = syscall.Errno(121) cERROR_SEM_TIMEOUT = syscall.Errno(121)
cPIPE_ACCESS_DUPLEX = 0x3 cSECURITY_SQOS_PRESENT = 0x100000
cFILE_FLAG_FIRST_PIPE_INSTANCE = 0x80000 cSECURITY_ANONYMOUS = 0
cSECURITY_SQOS_PRESENT = 0x100000
cSECURITY_ANONYMOUS = 0
cPIPE_REJECT_REMOTE_CLIENTS = 0x8
cPIPE_UNLIMITED_INSTANCES = 255
cNMPWAIT_USE_DEFAULT_WAIT = 0
cNMPWAIT_NOWAIT = 1
cPIPE_TYPE_MESSAGE = 4 cPIPE_TYPE_MESSAGE = 4
cPIPE_READMODE_MESSAGE = 2 cPIPE_READMODE_MESSAGE = 2
cFILE_OPEN = 1
cFILE_CREATE = 2
cFILE_PIPE_MESSAGE_TYPE = 1
cFILE_PIPE_REJECT_REMOTE_CLIENTS = 2
cSE_DACL_PRESENT = 4
) )
var ( var (
@ -137,9 +181,30 @@ func (s pipeAddress) String() string {
return string(s) return string(s)
} }
// tryDialPipe attempts to dial the pipe at `path` until `ctx` cancellation or timeout.
func tryDialPipe(ctx context.Context, path *string) (syscall.Handle, error) {
for {
select {
case <-ctx.Done():
return syscall.Handle(0), ctx.Err()
default:
h, err := createFile(*path, syscall.GENERIC_READ|syscall.GENERIC_WRITE, 0, nil, syscall.OPEN_EXISTING, syscall.FILE_FLAG_OVERLAPPED|cSECURITY_SQOS_PRESENT|cSECURITY_ANONYMOUS, 0)
if err == nil {
return h, nil
}
if err != cERROR_PIPE_BUSY {
return h, &os.PathError{Err: err, Op: "open", Path: *path}
}
// Wait 10 msec and try again. This is a rather simplistic
// view, as we always try each 10 milliseconds.
time.Sleep(time.Millisecond * 10)
}
}
}
// DialPipe connects to a named pipe by path, timing out if the connection // DialPipe connects to a named pipe by path, timing out if the connection
// takes longer than the specified duration. If timeout is nil, then we use // takes longer than the specified duration. If timeout is nil, then we use
// a default timeout of 5 seconds. (We do not use WaitNamedPipe.) // a default timeout of 2 seconds. (We do not use WaitNamedPipe.)
func DialPipe(path string, timeout *time.Duration) (net.Conn, error) { func DialPipe(path string, timeout *time.Duration) (net.Conn, error) {
var absTimeout time.Time var absTimeout time.Time
if timeout != nil { if timeout != nil {
@ -147,23 +212,22 @@ func DialPipe(path string, timeout *time.Duration) (net.Conn, error) {
} else { } else {
absTimeout = time.Now().Add(time.Second * 2) absTimeout = time.Now().Add(time.Second * 2)
} }
ctx, _ := context.WithDeadline(context.Background(), absTimeout)
conn, err := DialPipeContext(ctx, path)
if err == context.DeadlineExceeded {
return nil, ErrTimeout
}
return conn, err
}
// DialPipeContext attempts to connect to a named pipe by `path` until `ctx`
// cancellation or timeout.
func DialPipeContext(ctx context.Context, path string) (net.Conn, error) {
var err error var err error
var h syscall.Handle var h syscall.Handle
for { h, err = tryDialPipe(ctx, &path)
h, err = createFile(path, syscall.GENERIC_READ|syscall.GENERIC_WRITE, 0, nil, syscall.OPEN_EXISTING, syscall.FILE_FLAG_OVERLAPPED|cSECURITY_SQOS_PRESENT|cSECURITY_ANONYMOUS, 0)
if err != cERROR_PIPE_BUSY {
break
}
if time.Now().After(absTimeout) {
return nil, ErrTimeout
}
// Wait 10 msec and try again. This is a rather simplistic
// view, as we always try each 10 milliseconds.
time.Sleep(time.Millisecond * 10)
}
if err != nil { if err != nil {
return nil, &os.PathError{Op: "open", Path: path, Err: err} return nil, err
} }
var flags uint32 var flags uint32
@ -194,43 +258,87 @@ type acceptResponse struct {
} }
type win32PipeListener struct { type win32PipeListener struct {
firstHandle syscall.Handle firstHandle syscall.Handle
path string path string
securityDescriptor []byte config PipeConfig
config PipeConfig acceptCh chan (chan acceptResponse)
acceptCh chan (chan acceptResponse) closeCh chan int
closeCh chan int doneCh chan int
doneCh chan int
} }
func makeServerPipeHandle(path string, securityDescriptor []byte, c *PipeConfig, first bool) (syscall.Handle, error) { func makeServerPipeHandle(path string, sd []byte, c *PipeConfig, first bool) (syscall.Handle, error) {
var flags uint32 = cPIPE_ACCESS_DUPLEX | syscall.FILE_FLAG_OVERLAPPED path16, err := syscall.UTF16FromString(path)
if first {
flags |= cFILE_FLAG_FIRST_PIPE_INSTANCE
}
var mode uint32 = cPIPE_REJECT_REMOTE_CLIENTS
if c.MessageMode {
mode |= cPIPE_TYPE_MESSAGE
}
sa := &syscall.SecurityAttributes{}
sa.Length = uint32(unsafe.Sizeof(*sa))
if securityDescriptor != nil {
len := uint32(len(securityDescriptor))
sa.SecurityDescriptor = localAlloc(0, len)
defer localFree(sa.SecurityDescriptor)
copy((*[0xffff]byte)(unsafe.Pointer(sa.SecurityDescriptor))[:], securityDescriptor)
}
h, err := createNamedPipe(path, flags, mode, cPIPE_UNLIMITED_INSTANCES, uint32(c.OutputBufferSize), uint32(c.InputBufferSize), 0, sa)
if err != nil { if err != nil {
return 0, &os.PathError{Op: "open", Path: path, Err: err} return 0, &os.PathError{Op: "open", Path: path, Err: err}
} }
var oa objectAttributes
oa.Length = unsafe.Sizeof(oa)
var ntPath unicodeString
if err := rtlDosPathNameToNtPathName(&path16[0], &ntPath, 0, 0).Err(); err != nil {
return 0, &os.PathError{Op: "open", Path: path, Err: err}
}
defer localFree(ntPath.Buffer)
oa.ObjectName = &ntPath
// The security descriptor is only needed for the first pipe.
if first {
if sd != nil {
len := uint32(len(sd))
sdb := localAlloc(0, len)
defer localFree(sdb)
copy((*[0xffff]byte)(unsafe.Pointer(sdb))[:], sd)
oa.SecurityDescriptor = (*securityDescriptor)(unsafe.Pointer(sdb))
} else {
// Construct the default named pipe security descriptor.
var dacl uintptr
if err := rtlDefaultNpAcl(&dacl).Err(); err != nil {
return 0, fmt.Errorf("getting default named pipe ACL: %s", err)
}
defer localFree(dacl)
sdb := &securityDescriptor{
Revision: 1,
Control: cSE_DACL_PRESENT,
Dacl: dacl,
}
oa.SecurityDescriptor = sdb
}
}
typ := uint32(cFILE_PIPE_REJECT_REMOTE_CLIENTS)
if c.MessageMode {
typ |= cFILE_PIPE_MESSAGE_TYPE
}
disposition := uint32(cFILE_OPEN)
access := uint32(syscall.GENERIC_READ | syscall.GENERIC_WRITE | syscall.SYNCHRONIZE)
if first {
disposition = cFILE_CREATE
// By not asking for read or write access, the named pipe file system
// will put this pipe into an initially disconnected state, blocking
// client connections until the next call with first == false.
access = syscall.SYNCHRONIZE
}
timeout := int64(-50 * 10000) // 50ms
var (
h syscall.Handle
iosb ioStatusBlock
)
err = ntCreateNamedPipeFile(&h, access, &oa, &iosb, syscall.FILE_SHARE_READ|syscall.FILE_SHARE_WRITE, disposition, 0, typ, 0, 0, 0xffffffff, uint32(c.InputBufferSize), uint32(c.OutputBufferSize), &timeout).Err()
if err != nil {
return 0, &os.PathError{Op: "open", Path: path, Err: err}
}
runtime.KeepAlive(ntPath)
return h, nil return h, nil
} }
func (l *win32PipeListener) makeServerPipe() (*win32File, error) { func (l *win32PipeListener) makeServerPipe() (*win32File, error) {
h, err := makeServerPipeHandle(l.path, l.securityDescriptor, &l.config, false) h, err := makeServerPipeHandle(l.path, nil, &l.config, false)
if err != nil { if err != nil {
return nil, err return nil, err
} }
@ -341,32 +449,13 @@ func ListenPipe(path string, c *PipeConfig) (net.Listener, error) {
if err != nil { if err != nil {
return nil, err return nil, err
} }
// Create a client handle and connect it. This results in the pipe
// instance always existing, so that clients see ERROR_PIPE_BUSY
// rather than ERROR_FILE_NOT_FOUND. This ties the first instance
// up so that no other instances can be used. This would have been
// cleaner if the Win32 API matched CreateFile with ConnectNamedPipe
// instead of CreateNamedPipe. (Apparently created named pipes are
// considered to be in listening state regardless of whether any
// active calls to ConnectNamedPipe are outstanding.)
h2, err := createFile(path, 0, 0, nil, syscall.OPEN_EXISTING, cSECURITY_SQOS_PRESENT|cSECURITY_ANONYMOUS, 0)
if err != nil {
syscall.Close(h)
return nil, err
}
// Close the client handle. The server side of the instance will
// still be busy, leading to ERROR_PIPE_BUSY instead of
// ERROR_NOT_FOUND, as long as we don't close the server handle,
// or disconnect the client with DisconnectNamedPipe.
syscall.Close(h2)
l := &win32PipeListener{ l := &win32PipeListener{
firstHandle: h, firstHandle: h,
path: path, path: path,
securityDescriptor: sd, config: *c,
config: *c, acceptCh: make(chan (chan acceptResponse)),
acceptCh: make(chan (chan acceptResponse)), closeCh: make(chan int),
closeCh: make(chan int), doneCh: make(chan int),
doneCh: make(chan int),
} }
go l.listenerRoutine() go l.listenerRoutine()
return l, nil return l, nil

View File

@ -17,7 +17,7 @@ const (
// will always be collected. // will always be collected.
type Level uint8 type Level uint8
// Predefined ETW log levels. // Predefined ETW log levels from winmeta.xml in the Windows SDK.
const ( const (
LevelAlways Level = iota LevelAlways Level = iota
LevelCritical LevelCritical
@ -27,13 +27,30 @@ const (
LevelVerbose LevelVerbose
) )
// Opcode represents the operation that the event indicates is being performed.
type Opcode uint8
// Predefined ETW opcodes from winmeta.xml in the Windows SDK.
const (
// OpcodeInfo indicates an informational event.
OpcodeInfo Opcode = iota
// OpcodeStart indicates the start of an operation.
OpcodeStart
// OpcodeStop indicates the end of an operation.
OpcodeStop
// OpcodeDCStart indicates the start of a provider capture state operation.
OpcodeDCStart
// OpcodeDCStop indicates the end of a provider capture state operation.
OpcodeDCStop
)
// EventDescriptor represents various metadata for an ETW event. // EventDescriptor represents various metadata for an ETW event.
type eventDescriptor struct { type eventDescriptor struct {
id uint16 id uint16
version uint8 version uint8
channel Channel channel Channel
level Level level Level
opcode uint8 opcode Opcode
task uint16 task uint16
keyword uint64 keyword uint64
} }

View File

@ -1,13 +1,13 @@
package etw package etw
import ( import (
"golang.org/x/sys/windows" "github.com/Microsoft/go-winio/pkg/guid"
) )
type eventOptions struct { type eventOptions struct {
descriptor *eventDescriptor descriptor *eventDescriptor
activityID *windows.GUID activityID *guid.GUID
relatedActivityID *windows.GUID relatedActivityID *guid.GUID
tags uint32 tags uint32
} }
@ -36,12 +36,20 @@ func WithKeyword(keyword uint64) EventOpt {
} }
} }
// WithChannel specifies the channel of the event to be written.
func WithChannel(channel Channel) EventOpt { func WithChannel(channel Channel) EventOpt {
return func(options *eventOptions) { return func(options *eventOptions) {
options.descriptor.channel = channel options.descriptor.channel = channel
} }
} }
// WithOpcode specifies the opcode of the event to be written.
func WithOpcode(opcode Opcode) EventOpt {
return func(options *eventOptions) {
options.descriptor.opcode = opcode
}
}
// WithTags specifies the tags of the event to be written. Tags is a 28-bit // WithTags specifies the tags of the event to be written. Tags is a 28-bit
// value (top 4 bits are ignored) which are interpreted by the event consumer. // value (top 4 bits are ignored) which are interpreted by the event consumer.
func WithTags(newTags uint32) EventOpt { func WithTags(newTags uint32) EventOpt {
@ -50,13 +58,15 @@ func WithTags(newTags uint32) EventOpt {
} }
} }
func WithActivityID(activityID *windows.GUID) EventOpt { // WithActivityID specifies the activity ID of the event to be written.
func WithActivityID(activityID *guid.GUID) EventOpt {
return func(options *eventOptions) { return func(options *eventOptions) {
options.activityID = activityID options.activityID = activityID
} }
} }
func WithRelatedActivityID(activityID *windows.GUID) EventOpt { // WithRelatedActivityID specifies the parent activity ID of the event to be written.
func WithRelatedActivityID(activityID *guid.GUID) EventOpt {
return func(options *eventOptions) { return func(options *eventOptions) {
options.relatedActivityID = activityID options.relatedActivityID = activityID
} }

View File

@ -1,7 +1,9 @@
package etw package etw
import ( import (
"fmt"
"math" "math"
"reflect"
"unsafe" "unsafe"
) )
@ -377,3 +379,124 @@ func Struct(name string, opts ...FieldOpt) FieldOpt {
} }
} }
} }
// Currently, we support logging basic builtin types (int, string, etc), slices
// of basic builtin types, error, types derived from the basic types (e.g. "type
// foo int"), and structs (recursively logging their fields). We do not support
// slices of derived types (e.g. "[]foo").
//
// For types that we don't support, the value is formatted via fmt.Sprint, and
// we also log a message that the type is unsupported along with the formatted
// type. The intent of this is to make it easier to see which types are not
// supported in traces, so we can evaluate adding support for more types in the
// future.
func SmartField(name string, v interface{}) FieldOpt {
switch v := v.(type) {
case bool:
return BoolField(name, v)
case []bool:
return BoolArray(name, v)
case string:
return StringField(name, v)
case []string:
return StringArray(name, v)
case int:
return IntField(name, v)
case []int:
return IntArray(name, v)
case int8:
return Int8Field(name, v)
case []int8:
return Int8Array(name, v)
case int16:
return Int16Field(name, v)
case []int16:
return Int16Array(name, v)
case int32:
return Int32Field(name, v)
case []int32:
return Int32Array(name, v)
case int64:
return Int64Field(name, v)
case []int64:
return Int64Array(name, v)
case uint:
return UintField(name, v)
case []uint:
return UintArray(name, v)
case uint8:
return Uint8Field(name, v)
case []uint8:
return Uint8Array(name, v)
case uint16:
return Uint16Field(name, v)
case []uint16:
return Uint16Array(name, v)
case uint32:
return Uint32Field(name, v)
case []uint32:
return Uint32Array(name, v)
case uint64:
return Uint64Field(name, v)
case []uint64:
return Uint64Array(name, v)
case uintptr:
return UintptrField(name, v)
case []uintptr:
return UintptrArray(name, v)
case float32:
return Float32Field(name, v)
case []float32:
return Float32Array(name, v)
case float64:
return Float64Field(name, v)
case []float64:
return Float64Array(name, v)
case error:
return StringField(name, v.Error())
default:
switch rv := reflect.ValueOf(v); rv.Kind() {
case reflect.Bool:
return SmartField(name, rv.Bool())
case reflect.Int:
return SmartField(name, int(rv.Int()))
case reflect.Int8:
return SmartField(name, int8(rv.Int()))
case reflect.Int16:
return SmartField(name, int16(rv.Int()))
case reflect.Int32:
return SmartField(name, int32(rv.Int()))
case reflect.Int64:
return SmartField(name, int64(rv.Int()))
case reflect.Uint:
return SmartField(name, uint(rv.Uint()))
case reflect.Uint8:
return SmartField(name, uint8(rv.Uint()))
case reflect.Uint16:
return SmartField(name, uint16(rv.Uint()))
case reflect.Uint32:
return SmartField(name, uint32(rv.Uint()))
case reflect.Uint64:
return SmartField(name, uint64(rv.Uint()))
case reflect.Uintptr:
return SmartField(name, uintptr(rv.Uint()))
case reflect.Float32:
return SmartField(name, float32(rv.Float()))
case reflect.Float64:
return SmartField(name, float64(rv.Float()))
case reflect.String:
return SmartField(name, rv.String())
case reflect.Struct:
fields := make([]FieldOpt, 0, rv.NumField())
for i := 0; i < rv.NumField(); i++ {
field := rv.Field(i)
if field.CanInterface() {
fields = append(fields, SmartField(name, field.Interface()))
}
}
return Struct(name, fields...)
}
}
return StringField(name, fmt.Sprintf("(Unsupported: %T) %v", v, v))
}

View File

@ -4,12 +4,11 @@ import (
"bytes" "bytes"
"crypto/sha1" "crypto/sha1"
"encoding/binary" "encoding/binary"
"encoding/hex"
"fmt"
"strings" "strings"
"unicode/utf16" "unicode/utf16"
"unsafe" "unsafe"
"github.com/Microsoft/go-winio/pkg/guid"
"golang.org/x/sys/windows" "golang.org/x/sys/windows"
) )
@ -17,7 +16,7 @@ import (
// name and ID (GUID), which should always have a 1:1 mapping to each other // 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). // (e.g. don't use multiple provider names with the same ID, or vice versa).
type Provider struct { type Provider struct {
ID *windows.GUID ID *guid.GUID
handle providerHandle handle providerHandle
metadata []byte metadata []byte
callback EnableCallback callback EnableCallback
@ -30,19 +29,7 @@ type Provider struct {
// String returns the `provider`.ID as a string // String returns the `provider`.ID as a string
func (provider *Provider) String() string { func (provider *Provider) String() string {
data1 := make([]byte, 4) return provider.ID.String()
binary.BigEndian.PutUint32(data1, provider.ID.Data1)
data2 := make([]byte, 2)
binary.BigEndian.PutUint16(data2, provider.ID.Data2)
data3 := make([]byte, 2)
binary.BigEndian.PutUint16(data3, provider.ID.Data3)
return fmt.Sprintf(
"%s-%s-%s-%s-%s",
hex.EncodeToString(data1),
hex.EncodeToString(data2),
hex.EncodeToString(data3),
hex.EncodeToString(provider.ID.Data4[:2]),
hex.EncodeToString(provider.ID.Data4[2:]))
} }
type providerHandle windows.Handle type providerHandle windows.Handle
@ -72,9 +59,9 @@ const (
// EnableCallback is the form of the callback function that receives provider // EnableCallback is the form of the callback function that receives provider
// enable/disable notifications from ETW. // enable/disable notifications from ETW.
type EnableCallback func(*windows.GUID, ProviderState, Level, uint64, uint64, uintptr) type EnableCallback func(*guid.GUID, ProviderState, Level, uint64, uint64, uintptr)
func providerCallback(sourceID *windows.GUID, state ProviderState, level Level, matchAnyKeyword uint64, matchAllKeyword uint64, filterData uintptr, i uintptr) { func providerCallback(sourceID *guid.GUID, state ProviderState, level Level, matchAnyKeyword uint64, matchAllKeyword uint64, filterData uintptr, i uintptr) {
provider := providers.getProvider(uint(i)) provider := providers.getProvider(uint(i))
switch state { switch state {
@ -96,7 +83,7 @@ func providerCallback(sourceID *windows.GUID, state ProviderState, level Level,
// for provider notifications. Because Go has trouble with callback arguments of // for provider notifications. Because Go has trouble with callback arguments of
// different size, it has only pointer-sized arguments, which are then cast to // different size, it has only pointer-sized arguments, which are then cast to
// the appropriate types when calling providerCallback. // the appropriate types when calling providerCallback.
func providerCallbackAdapter(sourceID *windows.GUID, state uintptr, level uintptr, matchAnyKeyword uintptr, matchAllKeyword uintptr, filterData uintptr, i uintptr) uintptr { func providerCallbackAdapter(sourceID *guid.GUID, state uintptr, level uintptr, matchAnyKeyword uintptr, matchAllKeyword uintptr, filterData uintptr, i uintptr) uintptr {
providerCallback(sourceID, ProviderState(state), Level(level), uint64(matchAnyKeyword), uint64(matchAllKeyword), filterData, i) providerCallback(sourceID, ProviderState(state), Level(level), uint64(matchAnyKeyword), uint64(matchAllKeyword), filterData, i)
return 0 return 0
} }
@ -108,7 +95,7 @@ func providerCallbackAdapter(sourceID *windows.GUID, state uintptr, level uintpt
// The algorithm is roughly: // The algorithm is roughly:
// Hash = Sha1(namespace + arg.ToUpper().ToUtf16be()) // Hash = Sha1(namespace + arg.ToUpper().ToUtf16be())
// Guid = Hash[0..15], with Hash[7] tweaked according to RFC 4122 // Guid = Hash[0..15], with Hash[7] tweaked according to RFC 4122
func providerIDFromName(name string) *windows.GUID { func providerIDFromName(name string) *guid.GUID {
buffer := sha1.New() buffer := sha1.New()
namespace := []byte{0x48, 0x2C, 0x2D, 0xB2, 0xC3, 0x90, 0x47, 0xC8, 0x87, 0xF8, 0x1A, 0x15, 0xBF, 0xC1, 0x30, 0xFB} namespace := []byte{0x48, 0x2C, 0x2D, 0xB2, 0xC3, 0x90, 0x47, 0xC8, 0x87, 0xF8, 0x1A, 0x15, 0xBF, 0xC1, 0x30, 0xFB}
@ -119,7 +106,7 @@ func providerIDFromName(name string) *windows.GUID {
sum := buffer.Sum(nil) sum := buffer.Sum(nil)
sum[7] = (sum[7] & 0xf) | 0x50 sum[7] = (sum[7] & 0xf) | 0x50
return &windows.GUID{ return &guid.GUID{
Data1: binary.LittleEndian.Uint32(sum[0:4]), Data1: binary.LittleEndian.Uint32(sum[0:4]),
Data2: binary.LittleEndian.Uint16(sum[4:6]), Data2: binary.LittleEndian.Uint16(sum[4:6]),
Data3: binary.LittleEndian.Uint16(sum[6:8]), Data3: binary.LittleEndian.Uint16(sum[6:8]),
@ -137,7 +124,7 @@ func NewProvider(name string, callback EnableCallback) (provider *Provider, err
// provider ID to be manually specified. This is most useful when there is an // provider ID to be manually specified. This is most useful when there is an
// existing provider ID that must be used to conform to existing diagnostic // existing provider ID that must be used to conform to existing diagnostic
// infrastructure. // infrastructure.
func NewProviderWithID(name string, id *windows.GUID, callback EnableCallback) (provider *Provider, err error) { func NewProviderWithID(name string, id *guid.GUID, callback EnableCallback) (provider *Provider, err error) {
providerCallbackOnce.Do(func() { providerCallbackOnce.Do(func() {
globalProviderCallback = windows.NewCallback(providerCallbackAdapter) globalProviderCallback = windows.NewCallback(providerCallbackAdapter)
}) })
@ -151,7 +138,7 @@ func NewProviderWithID(name string, id *windows.GUID, callback EnableCallback) (
provider.ID = id provider.ID = id
provider.callback = callback provider.callback = callback
if err := eventRegister(provider.ID, globalProviderCallback, uintptr(provider.index), &provider.handle); err != nil { if err := eventRegister((*windows.GUID)(provider.ID), globalProviderCallback, uintptr(provider.index), &provider.handle); err != nil {
return nil, err return nil, err
} }
@ -247,7 +234,7 @@ func (provider *Provider) WriteEvent(name string, eventOpts []EventOpt, fieldOpt
dataBlobs = [][]byte{ed.bytes()} dataBlobs = [][]byte{ed.bytes()}
} }
return provider.writeEventRaw(options.descriptor, nil, nil, [][]byte{em.bytes()}, dataBlobs) return provider.writeEventRaw(options.descriptor, options.activityID, options.relatedActivityID, [][]byte{em.bytes()}, dataBlobs)
} }
// writeEventRaw writes a single ETW event from the provider. This function is // writeEventRaw writes a single ETW event from the provider. This function is
@ -259,8 +246,8 @@ func (provider *Provider) WriteEvent(name string, eventOpts []EventOpt, fieldOpt
// the ETW infrastructure. // the ETW infrastructure.
func (provider *Provider) writeEventRaw( func (provider *Provider) writeEventRaw(
descriptor *eventDescriptor, descriptor *eventDescriptor,
activityID *windows.GUID, activityID *guid.GUID,
relatedActivityID *windows.GUID, relatedActivityID *guid.GUID,
metadataBlobs [][]byte, metadataBlobs [][]byte,
dataBlobs [][]byte) error { dataBlobs [][]byte) error {
@ -275,5 +262,5 @@ func (provider *Provider) writeEventRaw(
dataDescriptors = append(dataDescriptors, newEventDataDescriptor(eventDataDescriptorTypeUserData, blob)) dataDescriptors = append(dataDescriptors, newEventDataDescriptor(eventDataDescriptorTypeUserData, blob))
} }
return eventWriteTransfer(provider.handle, descriptor, activityID, relatedActivityID, dataDescriptorCount, &dataDescriptors[0]) return eventWriteTransfer(provider.handle, descriptor, (*windows.GUID)(activityID), (*windows.GUID)(relatedActivityID), dataDescriptorCount, &dataDescriptors[0])
} }

View File

@ -1,9 +1,6 @@
package etwlogrus package etwlogrus
import ( import (
"fmt"
"reflect"
"github.com/Microsoft/go-winio/pkg/etw" "github.com/Microsoft/go-winio/pkg/etw"
"github.com/sirupsen/logrus" "github.com/sirupsen/logrus"
) )
@ -71,7 +68,7 @@ func (h *Hook) Fire(e *logrus.Entry) error {
fields = append(fields, etw.StringField("Message", e.Message)) fields = append(fields, etw.StringField("Message", e.Message))
for k, v := range e.Data { for k, v := range e.Data {
fields = append(fields, getFieldOpt(k, v)) fields = append(fields, etw.SmartField(k, v))
} }
return h.provider.WriteEvent( return h.provider.WriteEvent(
@ -80,127 +77,6 @@ func (h *Hook) Fire(e *logrus.Entry) error {
fields) fields)
} }
// Currently, we support logging basic builtin types (int, string, etc), slices
// of basic builtin types, error, types derived from the basic types (e.g. "type
// foo int"), and structs (recursively logging their fields). We do not support
// slices of derived types (e.g. "[]foo").
//
// For types that we don't support, the value is formatted via fmt.Sprint, and
// we also log a message that the type is unsupported along with the formatted
// type. The intent of this is to make it easier to see which types are not
// supported in traces, so we can evaluate adding support for more types in the
// future.
func getFieldOpt(k string, v interface{}) etw.FieldOpt {
switch v := v.(type) {
case bool:
return etw.BoolField(k, v)
case []bool:
return etw.BoolArray(k, v)
case string:
return etw.StringField(k, v)
case []string:
return etw.StringArray(k, v)
case int:
return etw.IntField(k, v)
case []int:
return etw.IntArray(k, v)
case int8:
return etw.Int8Field(k, v)
case []int8:
return etw.Int8Array(k, v)
case int16:
return etw.Int16Field(k, v)
case []int16:
return etw.Int16Array(k, v)
case int32:
return etw.Int32Field(k, v)
case []int32:
return etw.Int32Array(k, v)
case int64:
return etw.Int64Field(k, v)
case []int64:
return etw.Int64Array(k, v)
case uint:
return etw.UintField(k, v)
case []uint:
return etw.UintArray(k, v)
case uint8:
return etw.Uint8Field(k, v)
case []uint8:
return etw.Uint8Array(k, v)
case uint16:
return etw.Uint16Field(k, v)
case []uint16:
return etw.Uint16Array(k, v)
case uint32:
return etw.Uint32Field(k, v)
case []uint32:
return etw.Uint32Array(k, v)
case uint64:
return etw.Uint64Field(k, v)
case []uint64:
return etw.Uint64Array(k, v)
case uintptr:
return etw.UintptrField(k, v)
case []uintptr:
return etw.UintptrArray(k, v)
case float32:
return etw.Float32Field(k, v)
case []float32:
return etw.Float32Array(k, v)
case float64:
return etw.Float64Field(k, v)
case []float64:
return etw.Float64Array(k, v)
case error:
return etw.StringField(k, v.Error())
default:
switch rv := reflect.ValueOf(v); rv.Kind() {
case reflect.Bool:
return getFieldOpt(k, rv.Bool())
case reflect.Int:
return getFieldOpt(k, int(rv.Int()))
case reflect.Int8:
return getFieldOpt(k, int8(rv.Int()))
case reflect.Int16:
return getFieldOpt(k, int16(rv.Int()))
case reflect.Int32:
return getFieldOpt(k, int32(rv.Int()))
case reflect.Int64:
return getFieldOpt(k, int64(rv.Int()))
case reflect.Uint:
return getFieldOpt(k, uint(rv.Uint()))
case reflect.Uint8:
return getFieldOpt(k, uint8(rv.Uint()))
case reflect.Uint16:
return getFieldOpt(k, uint16(rv.Uint()))
case reflect.Uint32:
return getFieldOpt(k, uint32(rv.Uint()))
case reflect.Uint64:
return getFieldOpt(k, uint64(rv.Uint()))
case reflect.Uintptr:
return getFieldOpt(k, uintptr(rv.Uint()))
case reflect.Float32:
return getFieldOpt(k, float32(rv.Float()))
case reflect.Float64:
return getFieldOpt(k, float64(rv.Float()))
case reflect.String:
return getFieldOpt(k, rv.String())
case reflect.Struct:
fields := make([]etw.FieldOpt, 0, rv.NumField())
for i := 0; i < rv.NumField(); i++ {
field := rv.Field(i)
if field.CanInterface() {
fields = append(fields, getFieldOpt(k, field.Interface()))
}
}
return etw.Struct(k, fields...)
}
}
return etw.StringField(k, fmt.Sprintf("(Unsupported: %T) %v", v, v))
}
// Close cleans up the hook and closes the ETW provider. If the provder was // Close cleans up the hook and closes the ETW provider. If the provder was
// registered by etwlogrus, it will be closed as part of `Close`. If the // registered by etwlogrus, it will be closed as part of `Close`. If the
// provider was passed in, it will not be closed. // provider was passed in, it will not be closed.

110
vendor/github.com/Microsoft/go-winio/pkg/guid/guid.go generated vendored Normal file
View File

@ -0,0 +1,110 @@
package guid
import (
"crypto/rand"
"encoding/binary"
"encoding/json"
"fmt"
"strconv"
"strings"
"github.com/pkg/errors"
"golang.org/x/sys/windows"
)
var _ = (json.Marshaler)(&GUID{})
var _ = (json.Unmarshaler)(&GUID{})
// GUID represents a GUID/UUID. It has the same structure as
// golang.org/x/sys/windows.GUID so that it can be used with functions expecting
// that type. It is defined as its own type so that stringification and
// marshaling can be supported. The representation matches that used by native
// Windows code.
type GUID windows.GUID
// NewV4 returns a new version 4 (pseudorandom) GUID, as defined by RFC 4122.
func NewV4() (*GUID, error) {
var b [16]byte
if _, err := rand.Read(b[:]); err != nil {
return nil, err
}
var g GUID
g.Data1 = binary.LittleEndian.Uint32(b[0:4])
g.Data2 = binary.LittleEndian.Uint16(b[4:6])
g.Data3 = binary.LittleEndian.Uint16(b[6:8])
copy(g.Data4[:], b[8:16])
g.Data3 = (g.Data3 & 0x0fff) | 0x4000 // Version 4 (randomly generated)
g.Data4[0] = (g.Data4[0] & 0x3f) | 0x80 // RFC4122 variant
return &g, nil
}
func (g *GUID) String() string {
return fmt.Sprintf(
"%08x-%04x-%04x-%04x-%012x",
g.Data1,
g.Data2,
g.Data3,
g.Data4[:2],
g.Data4[2:])
}
// FromString parses a string containing a GUID and returns the GUID. The only
// format currently supported is the `xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx`
// format.
func FromString(s string) (*GUID, error) {
if len(s) != 36 {
return nil, errors.New("invalid GUID format (length)")
}
if s[8] != '-' || s[13] != '-' || s[18] != '-' || s[23] != '-' {
return nil, errors.New("invalid GUID format (dashes)")
}
var g GUID
data1, err := strconv.ParseUint(s[0:8], 16, 32)
if err != nil {
return nil, errors.Wrap(err, "invalid GUID format (Data1)")
}
g.Data1 = uint32(data1)
data2, err := strconv.ParseUint(s[9:13], 16, 16)
if err != nil {
return nil, errors.Wrap(err, "invalid GUID format (Data2)")
}
g.Data2 = uint16(data2)
data3, err := strconv.ParseUint(s[14:18], 16, 16)
if err != nil {
return nil, errors.Wrap(err, "invalid GUID format (Data3)")
}
g.Data3 = uint16(data3)
for i, x := range []int{19, 21, 24, 26, 28, 30, 32, 34} {
v, err := strconv.ParseUint(s[x:x+2], 16, 8)
if err != nil {
return nil, errors.Wrap(err, "invalid GUID format (Data4)")
}
g.Data4[i] = uint8(v)
}
return &g, nil
}
// MarshalJSON marshals the GUID to JSON representation and returns it as a
// slice of bytes.
func (g *GUID) MarshalJSON() ([]byte, error) {
return json.Marshal(g.String())
}
// UnmarshalJSON unmarshals a GUID from JSON representation and sets itself to
// the unmarshaled GUID.
func (g *GUID) UnmarshalJSON(data []byte) error {
g2, err := FromString(strings.Trim(string(data), "\""))
if err != nil {
return err
}
*g = *g2
return nil
}

View File

@ -1,4 +1,4 @@
// MACHINE GENERATED BY 'go generate' COMMAND; DO NOT EDIT // Code generated by 'go generate'; DO NOT EDIT.
package winio package winio
@ -38,6 +38,7 @@ func errnoErr(e syscall.Errno) error {
var ( var (
modkernel32 = windows.NewLazySystemDLL("kernel32.dll") modkernel32 = windows.NewLazySystemDLL("kernel32.dll")
modntdll = windows.NewLazySystemDLL("ntdll.dll")
modadvapi32 = windows.NewLazySystemDLL("advapi32.dll") modadvapi32 = windows.NewLazySystemDLL("advapi32.dll")
procCancelIoEx = modkernel32.NewProc("CancelIoEx") procCancelIoEx = modkernel32.NewProc("CancelIoEx")
@ -47,10 +48,13 @@ var (
procConnectNamedPipe = modkernel32.NewProc("ConnectNamedPipe") procConnectNamedPipe = modkernel32.NewProc("ConnectNamedPipe")
procCreateNamedPipeW = modkernel32.NewProc("CreateNamedPipeW") procCreateNamedPipeW = modkernel32.NewProc("CreateNamedPipeW")
procCreateFileW = modkernel32.NewProc("CreateFileW") procCreateFileW = modkernel32.NewProc("CreateFileW")
procWaitNamedPipeW = modkernel32.NewProc("WaitNamedPipeW")
procGetNamedPipeInfo = modkernel32.NewProc("GetNamedPipeInfo") procGetNamedPipeInfo = modkernel32.NewProc("GetNamedPipeInfo")
procGetNamedPipeHandleStateW = modkernel32.NewProc("GetNamedPipeHandleStateW") procGetNamedPipeHandleStateW = modkernel32.NewProc("GetNamedPipeHandleStateW")
procLocalAlloc = modkernel32.NewProc("LocalAlloc") procLocalAlloc = modkernel32.NewProc("LocalAlloc")
procNtCreateNamedPipeFile = modntdll.NewProc("NtCreateNamedPipeFile")
procRtlNtStatusToDosErrorNoTeb = modntdll.NewProc("RtlNtStatusToDosErrorNoTeb")
procRtlDosPathNameToNtPathName_U = modntdll.NewProc("RtlDosPathNameToNtPathName_U")
procRtlDefaultNpAcl = modntdll.NewProc("RtlDefaultNpAcl")
procLookupAccountNameW = modadvapi32.NewProc("LookupAccountNameW") procLookupAccountNameW = modadvapi32.NewProc("LookupAccountNameW")
procConvertSidToStringSidW = modadvapi32.NewProc("ConvertSidToStringSidW") procConvertSidToStringSidW = modadvapi32.NewProc("ConvertSidToStringSidW")
procConvertStringSecurityDescriptorToSecurityDescriptorW = modadvapi32.NewProc("ConvertStringSecurityDescriptorToSecurityDescriptorW") procConvertStringSecurityDescriptorToSecurityDescriptorW = modadvapi32.NewProc("ConvertStringSecurityDescriptorToSecurityDescriptorW")
@ -176,27 +180,6 @@ func _createFile(name *uint16, access uint32, mode uint32, sa *syscall.SecurityA
return return
} }
func waitNamedPipe(name string, timeout uint32) (err error) {
var _p0 *uint16
_p0, err = syscall.UTF16PtrFromString(name)
if err != nil {
return
}
return _waitNamedPipe(_p0, timeout)
}
func _waitNamedPipe(name *uint16, timeout uint32) (err error) {
r1, _, e1 := syscall.Syscall(procWaitNamedPipeW.Addr(), 2, uintptr(unsafe.Pointer(name)), uintptr(timeout), 0)
if r1 == 0 {
if e1 != 0 {
err = errnoErr(e1)
} else {
err = syscall.EINVAL
}
}
return
}
func getNamedPipeInfo(pipe syscall.Handle, flags *uint32, outSize *uint32, inSize *uint32, maxInstances *uint32) (err error) { func getNamedPipeInfo(pipe syscall.Handle, flags *uint32, outSize *uint32, inSize *uint32, maxInstances *uint32) (err error) {
r1, _, e1 := syscall.Syscall6(procGetNamedPipeInfo.Addr(), 5, uintptr(pipe), uintptr(unsafe.Pointer(flags)), uintptr(unsafe.Pointer(outSize)), uintptr(unsafe.Pointer(inSize)), uintptr(unsafe.Pointer(maxInstances)), 0) r1, _, e1 := syscall.Syscall6(procGetNamedPipeInfo.Addr(), 5, uintptr(pipe), uintptr(unsafe.Pointer(flags)), uintptr(unsafe.Pointer(outSize)), uintptr(unsafe.Pointer(inSize)), uintptr(unsafe.Pointer(maxInstances)), 0)
if r1 == 0 { if r1 == 0 {
@ -227,6 +210,32 @@ func localAlloc(uFlags uint32, length uint32) (ptr uintptr) {
return return
} }
func ntCreateNamedPipeFile(pipe *syscall.Handle, access uint32, oa *objectAttributes, iosb *ioStatusBlock, share uint32, disposition uint32, options uint32, typ uint32, readMode uint32, completionMode uint32, maxInstances uint32, inboundQuota uint32, outputQuota uint32, timeout *int64) (status ntstatus) {
r0, _, _ := syscall.Syscall15(procNtCreateNamedPipeFile.Addr(), 14, uintptr(unsafe.Pointer(pipe)), uintptr(access), uintptr(unsafe.Pointer(oa)), uintptr(unsafe.Pointer(iosb)), uintptr(share), uintptr(disposition), uintptr(options), uintptr(typ), uintptr(readMode), uintptr(completionMode), uintptr(maxInstances), uintptr(inboundQuota), uintptr(outputQuota), uintptr(unsafe.Pointer(timeout)), 0)
status = ntstatus(r0)
return
}
func rtlNtStatusToDosError(status ntstatus) (winerr error) {
r0, _, _ := syscall.Syscall(procRtlNtStatusToDosErrorNoTeb.Addr(), 1, uintptr(status), 0, 0)
if r0 != 0 {
winerr = syscall.Errno(r0)
}
return
}
func rtlDosPathNameToNtPathName(name *uint16, ntName *unicodeString, filePart uintptr, reserved uintptr) (status ntstatus) {
r0, _, _ := syscall.Syscall6(procRtlDosPathNameToNtPathName_U.Addr(), 4, uintptr(unsafe.Pointer(name)), uintptr(unsafe.Pointer(ntName)), uintptr(filePart), uintptr(reserved), 0, 0)
status = ntstatus(r0)
return
}
func rtlDefaultNpAcl(dacl *uintptr) (status ntstatus) {
r0, _, _ := syscall.Syscall(procRtlDefaultNpAcl.Addr(), 1, uintptr(unsafe.Pointer(dacl)), 0, 0)
status = ntstatus(r0)
return
}
func lookupAccountName(systemName *uint16, accountName string, sid *byte, sidSize *uint32, refDomain *uint16, refDomainSize *uint32, sidNameUse *uint32) (err error) { func lookupAccountName(systemName *uint16, accountName string, sid *byte, sidSize *uint32, refDomain *uint16, refDomainSize *uint32, sidNameUse *uint32) (err error) {
var _p0 *uint16 var _p0 *uint16
_p0, err = syscall.UTF16PtrFromString(accountName) _p0, err = syscall.UTF16PtrFromString(accountName)