Skip to content

Commit

Permalink
Fix bugs in execution log handling (#795)
Browse files Browse the repository at this point in the history 
* expose sandbox init in interface, fix bugs in execution log copy logic, consolidate result variables in RunDynamicAnalysis, enable execution log feature flag by default

Signed-off-by: Max Fisher <maxfisher@google.com>

* remove unnecessary error stdout logging and improve some comments

Signed-off-by: Max Fisher <maxfisher@google.com>

---------

Signed-off-by: Max Fisher <maxfisher@google.com>
  • Loading branch information
@maxfisher-g
maxfisher-g authored Jul 6, 2023
1 parent 1142ae2 commit ff27d1e
Show file tree
Hide file tree
Showing 3 changed files with 83 additions and 69 deletions.
2 changes: 1 addition & 1 deletion internal/featureflags/features.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -16,5 +16,5 @@ var (
// CodeExecution automatically invokes package code during the import phase
// of dynamic analysis, which may uncover extra malicious behaviour.
// A list executed function/method/class names is saved.
CodeExecution = new("CodeExecution", false)
CodeExecution = new("CodeExecution", true)
)
88 changes: 49 additions & 39 deletions internal/sandbox/sandbox.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -79,6 +79,10 @@ func (r *RunResult) Stderr() []byte {
}

type Sandbox interface {
// Init prepares the sandbox for run and copy commands. The sandbox is
// only properly initialised if this function returns nil.
Init() error

// Run executes the supplied command and args in the sandbox.
// Multiple calls to Run will reuse the same container state,
// until Clean() is called.
Expand All @@ -93,6 +97,7 @@ type Sandbox interface {
// may be files or directories. The copy fails if the host path does not exist.
// See https://docs.podman.io/en/latest/markdown/podman-cp.1.html for details
// on specifying paths.
// The sandbox must be initialised using Init() before calling this function.
CopyIntoSandbox(hostPath, sandboxPath string) error

// CopyBackToHost copies a path in the sandbox to one in the host. The paths
Expand All @@ -101,6 +106,7 @@ type Sandbox interface {
// on specifying paths.
// Caution: files coming out of the sandbox are untrusted and proper validation
// should be performed on the file before use.
// The sandbox must be initialised using Init() before calling this function.
CopyBackToHost(hostPath, sandboxPath string) error
}

Expand All @@ -119,21 +125,22 @@ func (v volume) args() []string {

// Implements the Sandbox interface using "podman".
type podmanSandbox struct {
image string
tag string
id string
container string
noPull bool
rawSockets bool
strace bool
offline bool
logPackets bool
logStdOut bool
logStdErr bool
echoStdOut bool
echoStdErr bool
volumes []volume
copies []copySpec
image string
tag string
id string
container string
noPull bool
rawSockets bool
strace bool
offline bool
logPackets bool
logStdOut bool
logStdErr bool
echoStdOut bool
echoStdErr bool
initialised bool
volumes []volume
copies []copySpec
}

type (
Expand All @@ -144,21 +151,7 @@ type (
func (o option) set(sb *podmanSandbox) { o(sb) }

func New(options ...Option) Sandbox {
sb := &podmanSandbox{
image: "",
tag: "",
container: "",
noPull: false,
rawSockets: false,
strace: false,
offline: false,
logPackets: false,
logStdOut: false,
logStdErr: false,
echoStdOut: false,
echoStdErr: false,
volumes: make([]volume, 0),
}
sb := &podmanSandbox{}
for _, o := range options {
o.set(sb)
}
Expand Down Expand Up @@ -368,8 +361,14 @@ func (s *podmanSandbox) imageWithTag() string {
return fmt.Sprintf("%s:%s", s.image, tag)
}

// init initializes the sandbox.
func (s *podmanSandbox) init() error {
// Init initializes the sandbox, including creating the container and pulling the image.
// The sandbox is marked as initialised if the function completes with no errors.
// If the sandbox has already been marked as initialised, this function simply returns nil.
func (s *podmanSandbox) Init() error {
if s.initialised {
return nil
}

if s.container != "" {
return nil
}
Expand Down Expand Up @@ -400,12 +399,15 @@ func (s *podmanSandbox) init() error {
}
}

s.initialised = true

return nil
}

// Run implements the Sandbox interface.
// If Init() has not yet been run, it will be called automatically before running
func (s *podmanSandbox) Run(command string, args ...string) (*RunResult, error) {
if err := s.init(); err != nil {
if err := s.Init(); err != nil {
return &RunResult{}, err
}

Expand Down Expand Up @@ -513,21 +515,29 @@ func (s *podmanSandbox) Clean() error {
return podmanCleanContainers()
}

// CopyIntoSandbox copies a file from the host into the sandbox.
// CopyIntoSandbox copies a path from the host into the sandbox.
// If the source path does not exist, the command will fail with exit status 125.
func (s *podmanSandbox) CopyIntoSandbox(hostPath, sandboxPath string) error {
if len(s.container) == 0 {
return errors.New("cannot copy while container ID is empty. (Has the container been initialised?)")
if !s.initialised {
return errors.New("sandbox not initialised")
}
if s.container == "" {
return errors.New("container ID is empty")
}

copyCmd := hostToContainerCopyCmd(hostPath, sandboxPath, s.container)
log.Info("podman " + copyCmd.String())
return podmanRun(copyCmd.Args()...)
}

// CopyBackToHost copies a file from the sandbox back the host (after it has run)
// CopyBackToHost copies a path from the sandbox back to the host (after it has run).
// If the source path does not exist, the command will fail with exit status 125.
func (s *podmanSandbox) CopyBackToHost(hostPath, sandboxPath string) error {
if len(s.container) == 0 {
return errors.New("cannot copy while container ID is empty. (Has the container been initialised?)")
if !s.initialised {
return errors.New("sandbox not initialised")
}
if s.container == "" {
return errors.New("container ID is empty")
}

copyCmd := containerToHostCopyCmd(hostPath, sandboxPath, s.container)
Expand Down
62 changes: 33 additions & 29 deletions internal/worker/rundynamic.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -101,8 +101,8 @@ func retrieveExecutionLog(sb sandbox.Sandbox) (string, error) {

// if the copy fails, it could be that the execution log is not actually present.
// For now, we'll just log the error and otherwise ignore it
if err := sb.CopyBackToHost(sandboxExecutionLogPath, hostExecutionLogPath); err != nil {
log.Warn("Could not copy execution log from sandbox", "error", err)
if err := sb.CopyBackToHost(hostExecutionLogPath, sandboxExecutionLogPath); err != nil {
log.Warn("Could not retrieve execution log from sandbox", "error", err)
return "", nil
}

Expand Down Expand Up @@ -148,12 +148,6 @@ func RunDynamicAnalysis(pkg *pkgmanager.Pkg, sbOpts []sandbox.Option, analysisCm
analysisCmd = dynamicanalysis.DefaultCommand(pkg.Ecosystem())
}

data := analysisrun.DynamicAnalysisResults{
StraceSummary: make(analysisrun.DynamicAnalysisStraceSummary),
FileWritesSummary: make(analysisrun.DynamicAnalysisFileWritesSummary),
FileWriteBufferIds: make(analysisrun.DynamicAnalysisFileWriteBufferIds),
}

sb := sandbox.New(sbOpts...)

defer func() {
Expand All @@ -162,6 +156,12 @@ func RunDynamicAnalysis(pkg *pkgmanager.Pkg, sbOpts []sandbox.Option, analysisCm
}
}()

// initialise sandbox before copy/run
if err := sb.Init(); err != nil {
LogDynamicAnalysisError(pkg, "", err)
return DynamicAnalysisResult{}, err
}

codeExecutionEnabled := false
if shouldEnableCodeExecution(pkg.Ecosystem()) {
if err := enableCodeExecution(sb); err != nil {
Expand All @@ -171,14 +171,24 @@ func RunDynamicAnalysis(pkg *pkgmanager.Pkg, sbOpts []sandbox.Option, analysisCm
}
}

var lastRunPhase analysisrun.DynamicPhase
var lastStatus analysis.Status
result := DynamicAnalysisResult{
AnalysisData: analysisrun.DynamicAnalysisResults{
StraceSummary: make(analysisrun.DynamicAnalysisStraceSummary),
FileWritesSummary: make(analysisrun.DynamicAnalysisFileWritesSummary),
FileWriteBufferIds: make(analysisrun.DynamicAnalysisFileWriteBufferIds),
},
}

// lastError holds the error that occurred in the most recently run dynamic analysis phase.
// This is not a part of the result because a non-nil value means that the error originated
// from our code, as opposed to the package under analysis
var lastError error

for _, phase := range analysisrun.DefaultDynamicPhases() {
startTime := time.Now()
args := dynamicanalysis.MakeAnalysisArgs(pkg, phase)
phaseResult, err := dynamicanalysis.Run(sb, analysisCmd, args)
lastRunPhase = phase
result.LastRunPhase = phase

runDuration := time.Since(startTime)
log.Info("Dynamic analysis phase finished",
Expand All @@ -193,17 +203,17 @@ func RunDynamicAnalysis(pkg *pkgmanager.Pkg, sbOpts []sandbox.Option, analysisCm
if err != nil {
// Error when trying to actually run; don't record the result for this phase
// or attempt subsequent phases
lastStatus = ""
result.LastStatus = ""
lastError = err
break
}

data.StraceSummary[phase] = &phaseResult.StraceSummary
data.FileWritesSummary[phase] = &phaseResult.FileWritesSummary
lastStatus = phaseResult.StraceSummary.Status
data.FileWriteBufferIds[phase] = phaseResult.FileWriteBufferIds
result.AnalysisData.StraceSummary[phase] = &phaseResult.StraceSummary
result.AnalysisData.FileWritesSummary[phase] = &phaseResult.FileWritesSummary
result.AnalysisData.FileWriteBufferIds[phase] = phaseResult.FileWriteBufferIds

if lastStatus != analysis.StatusCompleted {
result.LastStatus = phaseResult.StraceSummary.Status
if result.LastStatus != analysis.StatusCompleted {
// Error caused by an issue with the package (probably).
// Don't continue with phases if this one did not complete successfully.
break
Expand All @@ -218,31 +228,25 @@ func RunDynamicAnalysis(pkg *pkgmanager.Pkg, sbOpts []sandbox.Option, analysisCm
"version", pkg.Version(),
"heap_usage_after_dynamic_analysis", strconv.FormatUint(afterDynamic.Alloc, 10))

analysisResult := DynamicAnalysisResult{
AnalysisData: data,
LastRunPhase: lastRunPhase,
LastStatus: lastStatus,
}

if lastError != nil {
LogDynamicAnalysisError(pkg, lastRunPhase, lastError)
return analysisResult, lastError
LogDynamicAnalysisError(pkg, result.LastRunPhase, lastError)
return result, lastError
}

LogDynamicAnalysisResult(pkg, lastRunPhase, lastStatus)
LogDynamicAnalysisResult(pkg, result.LastRunPhase, result.LastStatus)

if !codeExecutionEnabled {
// nothing more to do
return analysisResult, nil
return result, nil
}

executionLog, err := retrieveExecutionLog(sb)
if err != nil {
// don't return this error, just log it
log.Error("Error retrieving execution log", "error", err)
} else {
data.ExecutionLog = analysisrun.DynamicAnalysisExecutionLog(executionLog)
result.AnalysisData.ExecutionLog = analysisrun.DynamicAnalysisExecutionLog(executionLog)
}

return analysisResult, nil
return result, nil
}

0 comments on commit ff27d1e

Please sign in to comment.