gvisor/pkg/sentry/strace/strace.go

667 lines
19 KiB
Go

// Copyright 2018 Google Inc.
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
// Package strace implements the logic to print out the input and the return value
// of each traced syscall.
package strace
import (
"encoding/binary"
"fmt"
"strconv"
"strings"
"syscall"
"time"
"gvisor.googlesource.com/gvisor/pkg/abi/linux"
"gvisor.googlesource.com/gvisor/pkg/bits"
"gvisor.googlesource.com/gvisor/pkg/eventchannel"
"gvisor.googlesource.com/gvisor/pkg/sentry/arch"
"gvisor.googlesource.com/gvisor/pkg/sentry/kernel"
pb "gvisor.googlesource.com/gvisor/pkg/sentry/strace/strace_go_proto"
slinux "gvisor.googlesource.com/gvisor/pkg/sentry/syscalls/linux"
"gvisor.googlesource.com/gvisor/pkg/sentry/usermem"
)
// DefaultLogMaximumSize is the default LogMaximumSize.
const DefaultLogMaximumSize = 1024
// LogMaximumSize determines the maximum display size for data blobs (read,
// write, etc.).
var LogMaximumSize uint = DefaultLogMaximumSize
// EventMaximumSize determines the maximum size for data blobs (read, write,
// etc.) sent over the event channel. Default is 0 because most clients cannot
// do anything useful with binary text dump of byte array arguments.
var EventMaximumSize uint
func iovecs(t *kernel.Task, addr usermem.Addr, iovcnt int, printContent bool, maxBytes uint64) string {
if iovcnt < 0 || iovcnt > linux.UIO_MAXIOV {
return fmt.Sprintf("%#x (error decoding iovecs: invalid iovcnt)", addr)
}
ars, err := t.CopyInIovecs(addr, iovcnt)
if err != nil {
return fmt.Sprintf("%#x (error decoding iovecs: %v)", addr, err)
}
var totalBytes uint64
var truncated bool
iovs := make([]string, iovcnt)
for i := 0; !ars.IsEmpty(); i, ars = i+1, ars.Tail() {
ar := ars.Head()
if ar.Length() == 0 || !printContent {
iovs[i] = fmt.Sprintf("{base=%#x, len=%d}", ar.Start, ar.Length())
continue
}
size := uint64(ar.Length())
if truncated || totalBytes+size > maxBytes {
truncated = true
size = maxBytes - totalBytes
} else {
totalBytes += uint64(ar.Length())
}
b := make([]byte, size)
amt, err := t.CopyIn(ar.Start, b)
if err != nil {
iovs[i] = fmt.Sprintf("{base=%#x, len=%d, %q..., error decoding string: %v}", ar.Start, ar.Length(), b[:amt], err)
continue
}
dot := ""
if truncated {
// Indicate truncation.
dot = "..."
}
iovs[i] = fmt.Sprintf("{base=%#x, len=%d, %q%s}", ar.Start, ar.Length(), b[:amt], dot)
}
return fmt.Sprintf("%#x %s", addr, strings.Join(iovs, ", "))
}
func dump(t *kernel.Task, addr usermem.Addr, size uint, maximumBlobSize uint) string {
origSize := size
if size > maximumBlobSize {
size = maximumBlobSize
}
if size == 0 {
return ""
}
b := make([]byte, size)
amt, err := t.CopyIn(addr, b)
if err != nil {
return fmt.Sprintf("%#x (error decoding string: %s)", addr, err)
}
dot := ""
if uint(amt) < origSize {
// ... if we truncated the dump.
dot = "..."
}
return fmt.Sprintf("%#x %q%s", addr, b[:amt], dot)
}
func path(t *kernel.Task, addr usermem.Addr) string {
path, err := t.CopyInString(addr, syscall.PathMax)
if err != nil {
return fmt.Sprintf("%#x (error decoding path: %s)", addr, err)
}
return fmt.Sprintf("%#x %s", addr, path)
}
func fdpair(t *kernel.Task, addr usermem.Addr) string {
var fds [2]int32
_, err := t.CopyIn(addr, &fds)
if err != nil {
return fmt.Sprintf("%#x (error decoding fds: %s)", addr, err)
}
return fmt.Sprintf("%#x [%d %d]", addr, fds[0], fds[1])
}
func uname(t *kernel.Task, addr usermem.Addr) string {
var u linux.UtsName
if _, err := t.CopyIn(addr, &u); err != nil {
return fmt.Sprintf("%#x (error decoding utsname: %s)", addr, err)
}
return fmt.Sprintf("%#x %s", addr, u)
}
func utimensTimespec(t *kernel.Task, addr usermem.Addr) string {
if addr == 0 {
return "null"
}
var tim linux.Timespec
if _, err := t.CopyIn(addr, &tim); err != nil {
return fmt.Sprintf("%#x (error decoding timespec: %s)", addr, err)
}
var ns string
switch tim.Nsec {
case linux.UTIME_NOW:
ns = "UTIME_NOW"
case linux.UTIME_OMIT:
ns = "UTIME_OMIT"
default:
ns = fmt.Sprintf("%v", tim.Nsec)
}
return fmt.Sprintf("%#x {sec=%v nsec=%s}", addr, tim.Sec, ns)
}
func timespec(t *kernel.Task, addr usermem.Addr) string {
if addr == 0 {
return "null"
}
var tim linux.Timespec
if _, err := t.CopyIn(addr, &tim); err != nil {
return fmt.Sprintf("%#x (error decoding timespec: %s)", addr, err)
}
return fmt.Sprintf("%#x {sec=%v nsec=%v}", addr, tim.Sec, tim.Nsec)
}
func timeval(t *kernel.Task, addr usermem.Addr) string {
if addr == 0 {
return "null"
}
var tim linux.Timeval
if _, err := t.CopyIn(addr, &tim); err != nil {
return fmt.Sprintf("%#x (error decoding timeval: %s)", addr, err)
}
return fmt.Sprintf("%#x {sec=%v usec=%v}", addr, tim.Sec, tim.Usec)
}
func utimbuf(t *kernel.Task, addr usermem.Addr) string {
if addr == 0 {
return "null"
}
var utim syscall.Utimbuf
if _, err := t.CopyIn(addr, &utim); err != nil {
return fmt.Sprintf("%#x (error decoding utimbuf: %s)", addr, err)
}
return fmt.Sprintf("%#x {actime=%v, modtime=%v}", addr, utim.Actime, utim.Modtime)
}
func stat(t *kernel.Task, addr usermem.Addr) string {
if addr == 0 {
return "null"
}
var stat linux.Stat
if _, err := t.CopyIn(addr, &stat); err != nil {
return fmt.Sprintf("%#x (error decoding stat: %s)", addr, err)
}
return fmt.Sprintf("%#x {dev=%d, ino=%d, mode=%s, nlink=%d, uid=%d, gid=%d, rdev=%d, size=%d, blksize=%d, blocks=%d, atime=%s, mtime=%s, ctime=%s}", addr, stat.Dev, stat.Ino, linux.FileMode(stat.Mode), stat.Nlink, stat.UID, stat.GID, stat.Rdev, stat.Size, stat.Blksize, stat.Blocks, time.Unix(stat.ATime.Sec, stat.ATime.Nsec), time.Unix(stat.MTime.Sec, stat.MTime.Nsec), time.Unix(stat.CTime.Sec, stat.CTime.Nsec))
}
func itimerval(t *kernel.Task, addr usermem.Addr) string {
if addr == 0 {
return "null"
}
interval := timeval(t, addr)
value := timeval(t, addr+usermem.Addr(binary.Size(linux.Timeval{})))
return fmt.Sprintf("%#x {interval=%s, value=%s}", addr, interval, value)
}
func stringVector(t *kernel.Task, addr usermem.Addr) string {
vec, err := t.CopyInVector(addr, slinux.ExecMaxElemSize, slinux.ExecMaxTotalSize)
if err != nil {
return fmt.Sprintf("%#x {error copying vector: %v}", addr, err)
}
s := fmt.Sprintf("%#x [", addr)
for i, v := range vec {
if i != 0 {
s += ", "
}
s += fmt.Sprintf("%q", v)
}
s += "]"
return s
}
func rusage(t *kernel.Task, addr usermem.Addr) string {
if addr == 0 {
return "null"
}
var ru linux.Rusage
if _, err := t.CopyIn(addr, &ru); err != nil {
return fmt.Sprintf("%#x (error decoding rusage: %s)", addr, err)
}
return fmt.Sprintf("%#x %+v", addr, ru)
}
// pre fills in the pre-execution arguments for a system call. If an argument
// cannot be interpreted before the system call is executed, then a hex value
// will be used. Note that a full output slice will always be provided, that is
// len(return) == len(args).
func (i *SyscallInfo) pre(t *kernel.Task, args arch.SyscallArguments, maximumBlobSize uint) []string {
var output []string
for arg := range args {
if arg >= len(i.format) {
break
}
switch i.format[arg] {
case WriteBuffer:
output = append(output, dump(t, args[arg].Pointer(), args[arg+1].SizeT(), maximumBlobSize))
case WriteIOVec:
output = append(output, iovecs(t, args[arg].Pointer(), int(args[arg+1].Int()), true /* content */, uint64(maximumBlobSize)))
case IOVec:
output = append(output, iovecs(t, args[arg].Pointer(), int(args[arg+1].Int()), false /* content */, uint64(maximumBlobSize)))
case SendMsgHdr:
output = append(output, msghdr(t, args[arg].Pointer(), true /* content */, uint64(maximumBlobSize)))
case RecvMsgHdr:
output = append(output, msghdr(t, args[arg].Pointer(), false /* content */, uint64(maximumBlobSize)))
case Path:
output = append(output, path(t, args[arg].Pointer()))
case ExecveStringVector:
output = append(output, stringVector(t, args[arg].Pointer()))
case SockAddr:
output = append(output, sockAddr(t, args[arg].Pointer(), uint32(args[arg+1].Uint64())))
case SockLen:
output = append(output, sockLenPointer(t, args[arg].Pointer()))
case SockFamily:
output = append(output, SocketFamily.Parse(uint64(args[arg].Int())))
case SockType:
output = append(output, sockType(args[arg].Int()))
case SockProtocol:
output = append(output, sockProtocol(args[arg-2].Int(), args[arg].Int()))
case SockFlags:
output = append(output, sockFlags(args[arg].Int()))
case Timespec:
output = append(output, timespec(t, args[arg].Pointer()))
case UTimeTimespec:
output = append(output, utimensTimespec(t, args[arg].Pointer()))
case ItimerVal:
output = append(output, itimerval(t, args[arg].Pointer()))
case Timeval:
output = append(output, timeval(t, args[arg].Pointer()))
case Utimbuf:
output = append(output, utimbuf(t, args[arg].Pointer()))
case CloneFlags:
output = append(output, CloneFlagSet.Parse(uint64(args[arg].Uint())))
case OpenFlags:
output = append(output, open(uint64(args[arg].Uint())))
case Mode:
output = append(output, linux.FileMode(args[arg].ModeT()).String())
case FutexOp:
output = append(output, futex(uint64(args[arg].Uint())))
case PtraceRequest:
output = append(output, PtraceRequestSet.Parse(args[arg].Uint64()))
case Oct:
output = append(output, "0o"+strconv.FormatUint(args[arg].Uint64(), 8))
case Hex:
fallthrough
default:
output = append(output, "0x"+strconv.FormatUint(args[arg].Uint64(), 16))
}
}
return output
}
// post fills in the post-execution arguments for a system call. This modifies
// the given output slice in place with arguments that may only be interpreted
// after the system call has been executed.
func (i *SyscallInfo) post(t *kernel.Task, args arch.SyscallArguments, rval uintptr, output []string, maximumBlobSize uint) {
for arg := range output {
if arg >= len(i.format) {
break
}
switch i.format[arg] {
case ReadBuffer:
output[arg] = dump(t, args[arg].Pointer(), uint(rval), maximumBlobSize)
case ReadIOVec:
printLength := uint64(rval)
if printLength > uint64(maximumBlobSize) {
printLength = uint64(maximumBlobSize)
}
output[arg] = iovecs(t, args[arg].Pointer(), int(args[arg+1].Int()), true /* content */, printLength)
case WriteIOVec, IOVec, WriteBuffer:
// We already have a big blast from write.
output[arg] = "..."
case SendMsgHdr:
output[arg] = msghdr(t, args[arg].Pointer(), false /* content */, uint64(maximumBlobSize))
case RecvMsgHdr:
output[arg] = msghdr(t, args[arg].Pointer(), true /* content */, uint64(maximumBlobSize))
case PipeFDs:
output[arg] = fdpair(t, args[arg].Pointer())
case Uname:
output[arg] = uname(t, args[arg].Pointer())
case Stat:
output[arg] = stat(t, args[arg].Pointer())
case PostSockAddr:
output[arg] = postSockAddr(t, args[arg].Pointer(), args[arg+1].Pointer())
case SockLen:
output[arg] = sockLenPointer(t, args[arg].Pointer())
case PostTimespec:
output[arg] = timespec(t, args[arg].Pointer())
case PostItimerVal:
output[arg] = itimerval(t, args[arg].Pointer())
case Timeval:
output[arg] = timeval(t, args[arg].Pointer())
case Rusage:
output[arg] = rusage(t, args[arg].Pointer())
}
}
}
// printEntry prints the given system call entry.
func (i *SyscallInfo) printEnter(t *kernel.Task, args arch.SyscallArguments) []string {
output := i.pre(t, args, LogMaximumSize)
switch len(output) {
case 0:
t.Infof("%s E %s()", t.Name(), i.name)
case 1:
t.Infof("%s E %s(%s)", t.Name(), i.name,
output[0])
case 2:
t.Infof("%s E %s(%s, %s)", t.Name(), i.name,
output[0], output[1])
case 3:
t.Infof("%s E %s(%s, %s, %s)", t.Name(), i.name,
output[0], output[1], output[2])
case 4:
t.Infof("%s E %s(%s, %s, %s, %s)", t.Name(), i.name,
output[0], output[1], output[2], output[3])
case 5:
t.Infof("%s E %s(%s, %s, %s, %s, %s)", t.Name(), i.name,
output[0], output[1], output[2], output[3], output[4])
case 6:
t.Infof("%s E %s(%s, %s, %s, %s, %s, %s)", t.Name(), i.name,
output[0], output[1], output[2], output[3], output[4], output[5])
}
return output
}
// printExit prints the given system call exit.
func (i *SyscallInfo) printExit(t *kernel.Task, elapsed time.Duration, output []string, args arch.SyscallArguments, retval uintptr, err error, errno int) {
var rval string
if err == nil {
// Fill in the output after successful execution.
i.post(t, args, retval, output, LogMaximumSize)
rval = fmt.Sprintf("%#x (%v)", retval, elapsed)
} else {
rval = fmt.Sprintf("%#x errno=%d (%s) (%v)", retval, errno, err, elapsed)
}
switch len(output) {
case 0:
t.Infof("%s X %s() = %s", t.Name(), i.name,
rval)
case 1:
t.Infof("%s X %s(%s) = %s", t.Name(), i.name,
output[0], rval)
case 2:
t.Infof("%s X %s(%s, %s) = %s", t.Name(), i.name,
output[0], output[1], rval)
case 3:
t.Infof("%s X %s(%s, %s, %s) = %s", t.Name(), i.name,
output[0], output[1], output[2], rval)
case 4:
t.Infof("%s X %s(%s, %s, %s, %s) = %s", t.Name(), i.name,
output[0], output[1], output[2], output[3], rval)
case 5:
t.Infof("%s X %s(%s, %s, %s, %s, %s) = %s", t.Name(), i.name,
output[0], output[1], output[2], output[3], output[4], rval)
case 6:
t.Infof("%s X %s(%s, %s, %s, %s, %s, %s) = %s", t.Name(), i.name,
output[0], output[1], output[2], output[3], output[4], output[5], rval)
}
}
// sendEnter sends the syscall enter to event log.
func (i *SyscallInfo) sendEnter(t *kernel.Task, args arch.SyscallArguments) []string {
output := i.pre(t, args, EventMaximumSize)
event := pb.Strace{
Process: t.Name(),
Function: i.name,
Info: &pb.Strace_Enter{
Enter: &pb.StraceEnter{},
},
}
for _, arg := range output {
event.Args = append(event.Args, arg)
}
eventchannel.Emit(&event)
return output
}
// sendExit sends the syscall exit to event log.
func (i *SyscallInfo) sendExit(t *kernel.Task, elapsed time.Duration, output []string, args arch.SyscallArguments, rval uintptr, err error, errno int) {
if err == nil {
// Fill in the output after successful execution.
i.post(t, args, rval, output, EventMaximumSize)
}
exit := &pb.StraceExit{
Return: fmt.Sprintf("%#x", rval),
ElapsedNs: elapsed.Nanoseconds(),
}
if err != nil {
exit.Error = err.Error()
exit.ErrNo = int64(errno)
}
event := pb.Strace{
Process: t.Name(),
Function: i.name,
Info: &pb.Strace_Exit{Exit: exit},
}
for _, arg := range output {
event.Args = append(event.Args, arg)
}
eventchannel.Emit(&event)
}
type syscallContext struct {
info SyscallInfo
args arch.SyscallArguments
start time.Time
logOutput []string
eventOutput []string
flags uint32
}
// SyscallEnter implements kernel.Stracer.SyscallEnter. It logs the syscall
// entry trace.
func (s SyscallMap) SyscallEnter(t *kernel.Task, sysno uintptr, args arch.SyscallArguments, flags uint32) interface{} {
info, ok := s[sysno]
if !ok {
info = SyscallInfo{
name: fmt.Sprintf("sys_%d", sysno),
format: defaultFormat,
}
}
var output, eventOutput []string
if bits.IsOn32(flags, kernel.StraceEnableLog) {
output = info.printEnter(t, args)
}
if bits.IsOn32(flags, kernel.StraceEnableEvent) {
eventOutput = info.sendEnter(t, args)
}
return &syscallContext{
info: info,
args: args,
start: time.Now(),
logOutput: output,
eventOutput: eventOutput,
flags: flags,
}
}
// SyscallExit implements kernel.Stracer.SyscallExit. It logs the syscall
// exit trace.
func (s SyscallMap) SyscallExit(context interface{}, t *kernel.Task, sysno, rval uintptr, err error) {
errno := t.ExtractErrno(err, int(sysno))
c := context.(*syscallContext)
elapsed := time.Since(c.start)
if bits.IsOn32(c.flags, kernel.StraceEnableLog) {
c.info.printExit(t, elapsed, c.logOutput, c.args, rval, err, errno)
}
if bits.IsOn32(c.flags, kernel.StraceEnableEvent) {
c.info.sendExit(t, elapsed, c.eventOutput, c.args, rval, err, errno)
}
}
// ConvertToSysnoMap converts the names to a map keyed on the syscall number and value set to true.
// The map is in a convenient format to call SyscallFlagsTable.Enable().
func (s SyscallMap) ConvertToSysnoMap(syscalls []string) (map[uintptr]bool, error) {
if syscalls == nil {
// Sentinel: no list.
return nil, nil
}
l := make(map[uintptr]bool)
for _, sc := range syscalls {
// Try to match this system call.
sysno, ok := s.ConvertToSysno(sc)
if !ok {
return nil, fmt.Errorf("syscall %q not found", sc)
}
l[sysno] = true
}
// Success.
return l, nil
}
// ConvertToSysno converts the name to system call number. Returns false
// if syscall with same name is not found.
func (s SyscallMap) ConvertToSysno(syscall string) (uintptr, bool) {
for sysno, info := range s {
if info.name != "" && info.name == syscall {
return sysno, true
}
}
return 0, false
}
// Name returns the syscall name.
func (s SyscallMap) Name(sysno uintptr) string {
if info, ok := s[sysno]; ok {
return info.name
}
return fmt.Sprintf("sys_%d", sysno)
}
// Initialize prepares all syscall tables for use by this package.
//
// N.B. This is not in an init function because we can't be sure all syscall
// tables are registered with the kernel when init runs.
//
// TODO: remove kernel package dependencies from this package and
// have the kernel package self-initialize all syscall tables.
func Initialize() {
for _, table := range kernel.SyscallTables() {
// Is this known?
sys, ok := Lookup(table.OS, table.Arch)
if !ok {
continue
}
table.Stracer = sys
}
}
// SinkType defines where to send straces to.
type SinkType uint32
const (
// SinkTypeLog sends straces to text log
SinkTypeLog SinkType = 1 << iota
// SinkTypeEvent sends strace to event log
SinkTypeEvent
)
func convertToSyscallFlag(sinks SinkType) uint32 {
ret := uint32(0)
if bits.IsOn32(uint32(sinks), uint32(SinkTypeLog)) {
ret |= kernel.StraceEnableLog
}
if bits.IsOn32(uint32(sinks), uint32(SinkTypeEvent)) {
ret |= kernel.StraceEnableEvent
}
return ret
}
// Enable enables the syscalls in whitelist in all syscall tables.
//
// Preconditions: Initialize has been called.
func Enable(whitelist []string, sinks SinkType) error {
flags := convertToSyscallFlag(sinks)
for _, table := range kernel.SyscallTables() {
// Is this known?
sys, ok := Lookup(table.OS, table.Arch)
if !ok {
continue
}
// Convert to a set of system calls numbers.
wl, err := sys.ConvertToSysnoMap(whitelist)
if err != nil {
return err
}
table.FeatureEnable.Enable(flags, wl, true)
}
// Done.
return nil
}
// Disable will disable Strace for all system calls and missing syscalls.
//
// Preconditions: Initialize has been called.
func Disable(sinks SinkType) {
flags := convertToSyscallFlag(sinks)
for _, table := range kernel.SyscallTables() {
// Strace will be disabled for all syscalls including missing.
table.FeatureEnable.Enable(flags, nil, false)
}
}
// EnableAll enables all syscalls in all syscall tables.
//
// Preconditions: Initialize has been called.
func EnableAll(sinks SinkType) {
flags := convertToSyscallFlag(sinks)
for _, table := range kernel.SyscallTables() {
// Is this known?
if _, ok := Lookup(table.OS, table.Arch); !ok {
continue
}
table.FeatureEnable.EnableAll(flags)
}
}