2016-01-25 17:49:52 -05:00
|
|
|
// Package etwlogs provides a log driver for forwarding container logs
|
|
|
|
// as ETW events.(ETW stands for Event Tracing for Windows)
|
|
|
|
// A client can then create an ETW listener to listen for events that are sent
|
|
|
|
// by the ETW provider that we register, using the provider's GUID "a3693192-9ed6-46d2-a981-f8226c8363bd".
|
|
|
|
// Here is an example of how to do this using the logman utility:
|
|
|
|
// 1. logman start -ets DockerContainerLogs -p {a3693192-9ed6-46d2-a981-f8226c8363bd} 0 0 -o trace.etl
|
|
|
|
// 2. Run container(s) and generate log messages
|
|
|
|
// 3. logman stop -ets DockerContainerLogs
|
|
|
|
// 4. You can then convert the etl log file to XML using: tracerpt -y trace.etl
|
|
|
|
//
|
2016-05-07 21:36:10 -04:00
|
|
|
// Each container log message generates an ETW event that also contains:
|
2016-01-25 17:49:52 -05:00
|
|
|
// the container name and ID, the timestamp, and the stream type.
|
2018-02-05 16:05:59 -05:00
|
|
|
package etwlogs // import "github.com/docker/docker/daemon/logger/etwlogs"
|
2016-01-25 17:49:52 -05:00
|
|
|
|
|
|
|
import (
|
|
|
|
"errors"
|
|
|
|
"fmt"
|
|
|
|
"sync"
|
|
|
|
"unsafe"
|
|
|
|
|
|
|
|
"github.com/docker/docker/daemon/logger"
|
2017-07-26 17:42:13 -04:00
|
|
|
"github.com/sirupsen/logrus"
|
2016-11-21 17:35:06 -05:00
|
|
|
"golang.org/x/sys/windows"
|
2016-01-25 17:49:52 -05:00
|
|
|
)
|
|
|
|
|
|
|
|
type etwLogs struct {
|
|
|
|
containerName string
|
|
|
|
imageName string
|
|
|
|
containerID string
|
|
|
|
imageID string
|
|
|
|
}
|
|
|
|
|
|
|
|
const (
|
|
|
|
name = "etwlogs"
|
|
|
|
win32CallSuccess = 0
|
|
|
|
)
|
|
|
|
|
2016-11-21 17:35:06 -05:00
|
|
|
var (
|
|
|
|
modAdvapi32 = windows.NewLazySystemDLL("Advapi32.dll")
|
|
|
|
procEventRegister = modAdvapi32.NewProc("EventRegister")
|
|
|
|
procEventWriteString = modAdvapi32.NewProc("EventWriteString")
|
|
|
|
procEventUnregister = modAdvapi32.NewProc("EventUnregister")
|
|
|
|
)
|
2017-05-23 10:22:32 -04:00
|
|
|
var providerHandle windows.Handle
|
2016-01-25 17:49:52 -05:00
|
|
|
var refCount int
|
|
|
|
var mu sync.Mutex
|
|
|
|
|
|
|
|
func init() {
|
2017-05-23 10:22:32 -04:00
|
|
|
providerHandle = windows.InvalidHandle
|
2016-01-25 17:49:52 -05:00
|
|
|
if err := logger.RegisterLogDriver(name, New); err != nil {
|
2022-04-21 05:50:37 -04:00
|
|
|
panic(err)
|
2016-01-25 17:49:52 -05:00
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
// New creates a new etwLogs logger for the given container and registers the EWT provider.
|
2016-11-26 00:08:34 -05:00
|
|
|
func New(info logger.Info) (logger.Logger, error) {
|
2016-01-25 17:49:52 -05:00
|
|
|
if err := registerETWProvider(); err != nil {
|
|
|
|
return nil, err
|
|
|
|
}
|
2016-11-26 00:08:34 -05:00
|
|
|
logrus.Debugf("logging driver etwLogs configured for container: %s.", info.ContainerID)
|
2016-01-25 17:49:52 -05:00
|
|
|
|
|
|
|
return &etwLogs{
|
2016-11-26 00:08:34 -05:00
|
|
|
containerName: info.Name(),
|
|
|
|
imageName: info.ContainerImageName,
|
|
|
|
containerID: info.ContainerID,
|
|
|
|
imageID: info.ContainerImageID,
|
2016-01-25 17:49:52 -05:00
|
|
|
}, nil
|
|
|
|
}
|
|
|
|
|
|
|
|
// Log logs the message to the ETW stream.
|
|
|
|
func (etwLogger *etwLogs) Log(msg *logger.Message) error {
|
2017-05-23 10:22:32 -04:00
|
|
|
if providerHandle == windows.InvalidHandle {
|
2016-01-25 17:49:52 -05:00
|
|
|
// This should never be hit, if it is, it indicates a programming error.
|
|
|
|
errorMessage := "ETWLogs cannot log the message, because the event provider has not been registered."
|
|
|
|
logrus.Error(errorMessage)
|
|
|
|
return errors.New(errorMessage)
|
|
|
|
}
|
2016-12-12 09:54:20 -05:00
|
|
|
m := createLogMessage(etwLogger, msg)
|
|
|
|
logger.PutMessage(msg)
|
|
|
|
return callEventWriteString(m)
|
2016-01-25 17:49:52 -05:00
|
|
|
}
|
|
|
|
|
|
|
|
// Close closes the logger by unregistering the ETW provider.
|
|
|
|
func (etwLogger *etwLogs) Close() error {
|
|
|
|
unregisterETWProvider()
|
|
|
|
return nil
|
|
|
|
}
|
|
|
|
|
|
|
|
func (etwLogger *etwLogs) Name() string {
|
|
|
|
return name
|
|
|
|
}
|
|
|
|
|
|
|
|
func createLogMessage(etwLogger *etwLogs, msg *logger.Message) string {
|
|
|
|
return fmt.Sprintf("container_name: %s, image_name: %s, container_id: %s, image_id: %s, source: %s, log: %s",
|
|
|
|
etwLogger.containerName,
|
|
|
|
etwLogger.imageName,
|
|
|
|
etwLogger.containerID,
|
|
|
|
etwLogger.imageID,
|
|
|
|
msg.Source,
|
|
|
|
msg.Line)
|
|
|
|
}
|
|
|
|
|
|
|
|
func registerETWProvider() error {
|
|
|
|
mu.Lock()
|
|
|
|
defer mu.Unlock()
|
|
|
|
if refCount == 0 {
|
|
|
|
var err error
|
|
|
|
if err = callEventRegister(); err != nil {
|
|
|
|
return err
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
refCount++
|
|
|
|
return nil
|
|
|
|
}
|
|
|
|
|
|
|
|
func unregisterETWProvider() {
|
|
|
|
mu.Lock()
|
|
|
|
defer mu.Unlock()
|
|
|
|
if refCount == 1 {
|
|
|
|
if callEventUnregister() {
|
|
|
|
refCount--
|
2017-05-23 10:22:32 -04:00
|
|
|
providerHandle = windows.InvalidHandle
|
2016-01-25 17:49:52 -05:00
|
|
|
}
|
|
|
|
// Not returning an error if EventUnregister fails, because etwLogs will continue to work
|
|
|
|
} else {
|
|
|
|
refCount--
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
func callEventRegister() error {
|
|
|
|
// The provider's GUID is {a3693192-9ed6-46d2-a981-f8226c8363bd}
|
2017-05-23 10:22:32 -04:00
|
|
|
guid := windows.GUID{
|
2017-01-03 04:12:15 -05:00
|
|
|
Data1: 0xa3693192,
|
|
|
|
Data2: 0x9ed6,
|
|
|
|
Data3: 0x46d2,
|
|
|
|
Data4: [8]byte{0xa9, 0x81, 0xf8, 0x22, 0x6c, 0x83, 0x63, 0xbd},
|
2016-01-25 17:49:52 -05:00
|
|
|
}
|
|
|
|
|
2016-11-21 17:35:06 -05:00
|
|
|
ret, _, _ := procEventRegister.Call(uintptr(unsafe.Pointer(&guid)), 0, 0, uintptr(unsafe.Pointer(&providerHandle)))
|
2016-01-25 17:49:52 -05:00
|
|
|
if ret != win32CallSuccess {
|
|
|
|
errorMessage := fmt.Sprintf("Failed to register ETW provider. Error: %d", ret)
|
|
|
|
logrus.Error(errorMessage)
|
|
|
|
return errors.New(errorMessage)
|
|
|
|
}
|
|
|
|
return nil
|
|
|
|
}
|
|
|
|
|
|
|
|
func callEventWriteString(message string) error {
|
2017-05-23 10:22:32 -04:00
|
|
|
utf16message, err := windows.UTF16FromString(message)
|
2017-01-13 10:54:19 -05:00
|
|
|
|
|
|
|
if err != nil {
|
|
|
|
return err
|
|
|
|
}
|
|
|
|
|
|
|
|
ret, _, _ := procEventWriteString.Call(uintptr(providerHandle), 0, 0, uintptr(unsafe.Pointer(&utf16message[0])))
|
2016-01-25 17:49:52 -05:00
|
|
|
if ret != win32CallSuccess {
|
|
|
|
errorMessage := fmt.Sprintf("ETWLogs provider failed to log message. Error: %d", ret)
|
|
|
|
logrus.Error(errorMessage)
|
|
|
|
return errors.New(errorMessage)
|
|
|
|
}
|
|
|
|
return nil
|
|
|
|
}
|
|
|
|
|
|
|
|
func callEventUnregister() bool {
|
2016-11-21 17:35:06 -05:00
|
|
|
ret, _, _ := procEventUnregister.Call(uintptr(providerHandle))
|
2016-12-14 15:36:58 -05:00
|
|
|
return ret == win32CallSuccess
|
2016-01-25 17:49:52 -05:00
|
|
|
}
|