logging.go

Documentation: github.com/tetratelabs/wazero/internal/wasip1/logging

     1  package logging
     2  
     3  import (
     4  	"context"
     5  	"encoding/binary"
     6  	"strconv"
     7  	"strings"
     8  
     9  	"github.com/tetratelabs/wazero/api"
    10  	"github.com/tetratelabs/wazero/internal/logging"
    11  	"github.com/tetratelabs/wazero/internal/sys"
    12  	. "github.com/tetratelabs/wazero/internal/wasip1"
    13  )
    14  
    15  var le = binary.LittleEndian
    16  
    17  func isClockFunction(fnd api.FunctionDefinition) bool {
    18  	return strings.HasPrefix(fnd.Name(), "clock_")
    19  }
    20  
    21  func isProcFunction(fnd api.FunctionDefinition) bool {
    22  	return fnd.Name() == ProcExitName
    23  }
    24  
    25  func isFilesystemFunction(fnd api.FunctionDefinition) bool {
    26  	switch {
    27  	case strings.HasPrefix(fnd.Name(), "path_"):
    28  		return true
    29  	case strings.HasPrefix(fnd.Name(), "fd_"):
    30  		return true
    31  	}
    32  	return false
    33  }
    34  
    35  func isPollFunction(fnd api.FunctionDefinition) bool {
    36  	return fnd.Name() == PollOneoffName
    37  }
    38  
    39  func isRandomFunction(fnd api.FunctionDefinition) bool {
    40  	return fnd.Name() == RandomGetName
    41  }
    42  
    43  func isSockFunction(fnd api.FunctionDefinition) bool {
    44  	return strings.HasPrefix(fnd.Name(), "sock_")
    45  }
    46  
    47  // IsInLogScope returns true if the current function is in any of the scopes.
    48  func IsInLogScope(fnd api.FunctionDefinition, scopes logging.LogScopes) bool {
    49  	if scopes.IsEnabled(logging.LogScopeClock) {
    50  		if isClockFunction(fnd) {
    51  			return true
    52  		}
    53  	}
    54  
    55  	if scopes.IsEnabled(logging.LogScopeProc) {
    56  		if isProcFunction(fnd) {
    57  			return true
    58  		}
    59  	}
    60  
    61  	if scopes.IsEnabled(logging.LogScopeFilesystem) {
    62  		if isFilesystemFunction(fnd) {
    63  			return true
    64  		}
    65  	}
    66  
    67  	if scopes.IsEnabled(logging.LogScopePoll) {
    68  		if isPollFunction(fnd) {
    69  			return true
    70  		}
    71  	}
    72  
    73  	if scopes.IsEnabled(logging.LogScopeRandom) {
    74  		if isRandomFunction(fnd) {
    75  			return true
    76  		}
    77  	}
    78  
    79  	if scopes.IsEnabled(logging.LogScopeSock) {
    80  		if isSockFunction(fnd) {
    81  			return true
    82  		}
    83  	}
    84  
    85  	return scopes == logging.LogScopeAll
    86  }
    87  
    88  func Config(fnd api.FunctionDefinition) (pSampler logging.ParamSampler, pLoggers []logging.ParamLogger, rLoggers []logging.ResultLogger) {
    89  	types := fnd.ParamTypes()
    90  	names := fnd.ParamNames()
    91  
    92  	switch fnd.Name() {
    93  	case FdPrestatGetName:
    94  		pLoggers = []logging.ParamLogger{logging.NewParamLogger(0, "fd", logging.ValueTypeI32)}
    95  		rLoggers = []logging.ResultLogger{resultParamLogger("prestat", logPrestat(1).Log), logErrno}
    96  		return
    97  	case ProcExitName:
    98  		pLoggers, rLoggers = logging.Config(fnd)
    99  		return
   100  	case FdReadName, FdWriteName:
   101  		pSampler = fdReadWriteSampler
   102  	}
   103  
   104  	for idx := uint32(0); idx < uint32(len(types)); idx++ {
   105  		name := names[idx]
   106  		var logger logging.ParamLogger
   107  
   108  		if isLookupFlags(fnd, name) {
   109  			lf := &logLookupflags{name, idx}
   110  			logger = lf.Log
   111  			pLoggers = append(pLoggers, logger)
   112  			continue
   113  		}
   114  
   115  		isResult := strings.HasPrefix(name, "result.")
   116  
   117  		if strings.Contains(name, "path") {
   118  			if isResult {
   119  				name = resultParamName(name)
   120  				logger = logString(idx).Log
   121  				rLoggers = append(rLoggers, resultParamLogger(name, logger))
   122  			} else {
   123  				logger = logging.NewParamLogger(idx, name, logging.ValueTypeString)
   124  				pLoggers = append(pLoggers, logger)
   125  			}
   126  			idx++
   127  			continue
   128  		}
   129  
   130  		if strings.HasPrefix(fnd.Name(), "clock_") {
   131  			switch name {
   132  			case "id":
   133  				logger = logClockId(idx).Log
   134  			case "result.resolution":
   135  				name = resultParamName(name)
   136  				logger = logMemI32(idx).Log
   137  				rLoggers = append(rLoggers, resultParamLogger(name, logger))
   138  				continue
   139  			case "result.timestamp":
   140  				name = resultParamName(name)
   141  				logger = logMemI64(idx).Log
   142  				rLoggers = append(rLoggers, resultParamLogger(name, logger))
   143  				continue
   144  			default:
   145  				logger = logging.NewParamLogger(idx, name, types[idx])
   146  			}
   147  			pLoggers = append(pLoggers, logger)
   148  			continue
   149  		}
   150  
   151  		if strings.HasPrefix(fnd.Name(), "sock_") {
   152  			switch name {
   153  			case "flags":
   154  				logger = logFlags(idx).Log
   155  			case "ri_flags":
   156  				logger = logRiFlags(idx).Log
   157  			case "si_flags":
   158  				logger = logSiFlags(idx).Log
   159  			case "how":
   160  				logger = logSdFlags(idx).Log
   161  			case "result.fd", "result.ro_datalen", "result.so_datalen":
   162  				name = resultParamName(name)
   163  				logger = logMemI32(idx).Log
   164  				rLoggers = append(rLoggers, resultParamLogger(name, logger))
   165  				continue
   166  			case "result.ro_flags":
   167  				logger = logRoFlags(idx).Log
   168  				rLoggers = append(rLoggers, resultParamLogger("ro_flags", logger))
   169  				continue
   170  			default:
   171  				logger = logging.NewParamLogger(idx, name, types[idx])
   172  			}
   173  			pLoggers = append(pLoggers, logger)
   174  			continue
   175  		}
   176  
   177  		switch name {
   178  		case "fdflags":
   179  			logger = logFdflags(idx).Log
   180  		case "flags":
   181  			logger = logFlags(idx).Log
   182  		case "fst_flags":
   183  			logger = logFstflags(idx).Log
   184  		case "oflags":
   185  			logger = logOflags(idx).Log
   186  		case "fs_rights_base":
   187  			logger = logFsRightsBase(idx).Log
   188  		case "fs_rights_inheriting":
   189  			logger = logFsRightsInheriting(idx).Log
   190  		case "result.nread", "result.nwritten", "result.opened_fd", "result.nevents", "result.bufused":
   191  			name = resultParamName(name)
   192  			logger = logMemI32(idx).Log
   193  			rLoggers = append(rLoggers, resultParamLogger(name, logger))
   194  			continue
   195  		case "result.newoffset":
   196  			name = resultParamName(name)
   197  			logger = logMemI64(idx).Log
   198  			rLoggers = append(rLoggers, resultParamLogger(name, logger))
   199  			continue
   200  		case "result.filestat":
   201  			name = resultParamName(name)
   202  			logger = logFilestat(idx).Log
   203  			rLoggers = append(rLoggers, resultParamLogger(name, logger))
   204  			continue
   205  		case "result.stat":
   206  			name = resultParamName(name)
   207  			logger = logFdstat(idx).Log
   208  			rLoggers = append(rLoggers, resultParamLogger(name, logger))
   209  			continue
   210  		default:
   211  			logger = logging.NewParamLogger(idx, name, types[idx])
   212  		}
   213  		pLoggers = append(pLoggers, logger)
   214  	}
   215  	// All WASI functions except proc_after return only an logErrno result.
   216  	rLoggers = append(rLoggers, logErrno)
   217  	return
   218  }
   219  
   220  // Ensure we don't clutter log with reads and writes to stdio.
   221  func fdReadWriteSampler(_ context.Context, _ api.Module, params []uint64) bool {
   222  	fd := int32(params[0])
   223  	return fd > sys.FdStderr
   224  }
   225  
   226  func isLookupFlags(fnd api.FunctionDefinition, name string) bool {
   227  	switch fnd.Name() {
   228  	case PathFilestatGetName, PathFilestatSetTimesName:
   229  		return name == "flags"
   230  	case PathLinkName:
   231  		return name == "old_flags"
   232  	case PathOpenName:
   233  		return name == "dirflags"
   234  	}
   235  	return false
   236  }
   237  
   238  func logErrno(_ context.Context, _ api.Module, w logging.Writer, _, results []uint64) {
   239  	errno := ErrnoName(uint32(results[0]))
   240  	w.WriteString("errno=") //nolint
   241  	w.WriteString(errno)    //nolint
   242  }
   243  
   244  type logMemI32 uint32
   245  
   246  func (i logMemI32) Log(_ context.Context, mod api.Module, w logging.Writer, params []uint64) {
   247  	if v, ok := mod.Memory().ReadUint32Le(uint32(params[i])); ok {
   248  		writeI32(w, v)
   249  	}
   250  }
   251  
   252  type logMemI64 uint32
   253  
   254  func (i logMemI64) Log(_ context.Context, mod api.Module, w logging.Writer, params []uint64) {
   255  	if v, ok := mod.Memory().ReadUint64Le(uint32(params[i])); ok {
   256  		writeI64(w, v)
   257  	}
   258  }
   259  
   260  type logFilestat uint32
   261  
   262  func (i logFilestat) Log(_ context.Context, mod api.Module, w logging.Writer, params []uint64) {
   263  	offset, byteCount := uint32(params[i]), uint32(64)
   264  	if buf, ok := mod.Memory().Read(offset, byteCount); ok {
   265  		w.WriteString("{filetype=")          //nolint
   266  		w.WriteString(FiletypeName(buf[16])) //nolint
   267  		w.WriteString(",size=")              //nolint
   268  		writeI64(w, le.Uint64(buf[32:]))
   269  		w.WriteString(",mtim=") //nolint
   270  		writeI64(w, le.Uint64(buf[48:]))
   271  		w.WriteString("}") //nolint
   272  	}
   273  }
   274  
   275  type logFdstat uint32
   276  
   277  func (i logFdstat) Log(_ context.Context, mod api.Module, w logging.Writer, params []uint64) {
   278  	offset, byteCount := uint32(params[i]), uint32(24)
   279  	if buf, ok := mod.Memory().Read(offset, byteCount); ok {
   280  		w.WriteString("{filetype=")                           //nolint
   281  		w.WriteString(FiletypeName(buf[0]))                   //nolint
   282  		w.WriteString(",fdflags=")                            //nolint
   283  		w.WriteString(FdFlagsString(int(le.Uint16(buf[2:])))) //nolint
   284  		w.WriteString(",fs_rights_base=")                     //nolint
   285  		w.WriteString(RightsString(int(le.Uint16(buf[8:]))))  //nolint
   286  		w.WriteString(",fs_rights_inheriting=")               //nolint
   287  		w.WriteString(RightsString(int(le.Uint16(buf[16:])))) //nolint
   288  		w.WriteString("}")                                    //nolint
   289  	}
   290  }
   291  
   292  type logString uint32
   293  
   294  func (i logString) Log(_ context.Context, mod api.Module, w logging.Writer, params []uint64) {
   295  	offset, byteCount := uint32(params[i]), uint32(params[i+1])
   296  	if s, ok := mod.Memory().Read(offset, byteCount); ok {
   297  		w.Write(s) //nolint
   298  	}
   299  }
   300  
   301  type logPrestat uint32
   302  
   303  // Log writes the only valid field: pr_name_len
   304  // See https://github.com/WebAssembly/WASI/blob/snapshot-01/phases/snapshot/docs.md#prestat_dir
   305  func (i logPrestat) Log(_ context.Context, mod api.Module, w logging.Writer, params []uint64) {
   306  	offset := uint32(params[i]) + 4 // skip to pre_name_len field
   307  	if nameLen, ok := mod.Memory().ReadUint32Le(offset); ok {
   308  		w.WriteString("{pr_name_len=") //nolint
   309  		writeI32(w, nameLen)
   310  		w.WriteString("}") //nolint
   311  	}
   312  }
   313  
   314  // resultParamLogger logs the value of the parameter on ESUCCESS.
   315  func resultParamLogger(name string, pLogger logging.ParamLogger) logging.ResultLogger {
   316  	prefix := name + "="
   317  	return func(ctx context.Context, mod api.Module, w logging.Writer, params, results []uint64) {
   318  		w.WriteString(prefix) //nolint
   319  		if Errno(results[0]) == ErrnoSuccess {
   320  			pLogger(ctx, mod, w, params)
   321  		}
   322  	}
   323  }
   324  
   325  type logClockId int
   326  
   327  func (i logClockId) Log(_ context.Context, _ api.Module, w logging.Writer, params []uint64) {
   328  	id := uint32(params[i])
   329  	w.WriteString("id=") //nolint
   330  	switch id {
   331  	case ClockIDRealtime:
   332  		w.WriteString("realtime") //nolint
   333  	case ClockIDMonotonic:
   334  		w.WriteString("monotonic") //nolint
   335  	default:
   336  		writeI32(w, id)
   337  	}
   338  }
   339  
   340  type logFdflags int
   341  
   342  func (i logFdflags) Log(_ context.Context, _ api.Module, w logging.Writer, params []uint64) {
   343  	w.WriteString("fdflags=")                    //nolint
   344  	w.WriteString(FdFlagsString(int(params[i]))) //nolint
   345  }
   346  
   347  type logLookupflags struct {
   348  	name string
   349  	i    uint32
   350  }
   351  
   352  func (l *logLookupflags) Log(_ context.Context, _ api.Module, w logging.Writer, params []uint64) {
   353  	w.WriteString(l.name)                              //nolint
   354  	w.WriteByte('=')                                   //nolint
   355  	w.WriteString(LookupflagsString(int(params[l.i]))) //nolint
   356  }
   357  
   358  type logFsRightsBase uint32
   359  
   360  func (i logFsRightsBase) Log(_ context.Context, _ api.Module, w logging.Writer, params []uint64) {
   361  	w.WriteString("fs_rights_base=")            //nolint
   362  	w.WriteString(RightsString(int(params[i]))) //nolint
   363  }
   364  
   365  type logFsRightsInheriting uint32
   366  
   367  func (i logFsRightsInheriting) Log(_ context.Context, _ api.Module, w logging.Writer, params []uint64) {
   368  	w.WriteString("fs_rights_inheriting=")      //nolint
   369  	w.WriteString(RightsString(int(params[i]))) //nolint
   370  }
   371  
   372  type logOflags int
   373  
   374  func (i logOflags) Log(_ context.Context, _ api.Module, w logging.Writer, params []uint64) {
   375  	w.WriteString("oflags=")                    //nolint
   376  	w.WriteString(OflagsString(int(params[i]))) //nolint
   377  }
   378  
   379  type logFstflags int
   380  
   381  func (i logFstflags) Log(_ context.Context, _ api.Module, w logging.Writer, params []uint64) {
   382  	w.WriteString("fst_flags=")                   //nolint
   383  	w.WriteString(FstflagsString(int(params[i]))) //nolint
   384  }
   385  
   386  type logFlags int
   387  
   388  func (i logFlags) Log(_ context.Context, _ api.Module, w logging.Writer, params []uint64) {
   389  	w.WriteString("flags=")                      //nolint
   390  	w.WriteString(FdFlagsString(int(params[i]))) //nolint
   391  }
   392  
   393  type logSdFlags int
   394  
   395  func (i logSdFlags) Log(_ context.Context, _ api.Module, w logging.Writer, params []uint64) {
   396  	w.WriteString("how=")                        //nolint
   397  	w.WriteString(SdFlagsString(int(params[i]))) //nolint
   398  }
   399  
   400  type logSiFlags int
   401  
   402  func (i logSiFlags) Log(_ context.Context, _ api.Module, w logging.Writer, params []uint64) {
   403  	w.WriteString("si_flags=")                   //nolint
   404  	w.WriteString(SiFlagsString(int(params[i]))) //nolint
   405  }
   406  
   407  type logRiFlags int
   408  
   409  func (i logRiFlags) Log(_ context.Context, _ api.Module, w logging.Writer, params []uint64) {
   410  	w.WriteString("ri_flags=")                   //nolint
   411  	w.WriteString(RiFlagsString(int(params[i]))) //nolint
   412  }
   413  
   414  type logRoFlags int
   415  
   416  func (i logRoFlags) Log(_ context.Context, _ api.Module, w logging.Writer, params []uint64) {
   417  	w.WriteString(RoFlagsString(int(params[i]))) //nolint
   418  }
   419  
   420  func resultParamName(name string) string {
   421  	return name[7:] // without "result."
   422  }
   423  
   424  func writeI32(w logging.Writer, v uint32) {
   425  	w.WriteString(strconv.FormatInt(int64(int32(v)), 10)) //nolint
   426  }
   427  
   428  func writeI64(w logging.Writer, v uint64) {
   429  	w.WriteString(strconv.FormatInt(int64(v), 10)) //nolint
   430  }
   431
View as plain text