Bugfix: Flush server artifact logs into storage frequently (#2207)

The UI needs to track progress.

Also reuse log table component for cell logs for filtering on levels.

api/reports.go

@@ -19,6 +19,10 @@ import (
 // Reports are used for various dashboards. They are almost like a
 // notebook (but historically predate it).
 // TODO: Think about consolidating reports and notebooks
+// Currently this is used from:
+// 1. Home screen (dashboard)
+// 2. Client's VQL Drilldown screen
+// 3. View Artifacts screen
 func getReport(ctx context.Context,
 	config_obj *config_proto.Config,
 	acl_manager vql_subsystem.ACLManager,

go.mod

@@ -28,7 +28,7 @@ require (
 	github.com/aws/aws-sdk-go v1.44.118
 	github.com/clbanning/mxj v1.8.4
 	github.com/crewjam/saml v0.4.8
-	github.com/davecgh/go-spew v1.1.1
+	github.com/davecgh/go-spew v1.1.2-0.20180830191138-d8f796af33cc
 	github.com/dimchansky/utfbom v1.1.1
 	github.com/dustin/go-humanize v1.0.0
 	github.com/elastic/go-elasticsearch/v7 v7.3.0 // indirect
@@ -74,7 +74,7 @@ require (
 	github.com/sebdah/goldie/v2 v2.5.3
 	github.com/sergi/go-diff v1.2.0
 	github.com/sirupsen/logrus v1.8.1
-	github.com/stretchr/testify v1.8.0
+	github.com/stretchr/testify v1.8.1
 	github.com/tink-ab/tempfile v0.0.0-20180226111222-33beb0518f1a
 	github.com/vjeantet/grok v1.0.0
 	github.com/xor-gate/ar v0.0.0-20170530204233-5c72ae81e2b7 // indirect
@@ -98,12 +98,12 @@ require (
 	howett.net/plist v1.0.0
 	www.velocidex.com/golang/evtx v0.2.1-0.20220404133451-1fdf8be7325e
 	www.velocidex.com/golang/go-ese v0.1.1-0.20220107095505-c38622559671
-	www.velocidex.com/golang/go-ntfs v0.1.2-0.20221101075911-4e31a101eb08
+	www.velocidex.com/golang/go-ntfs v0.1.2-0.20221101112551-e6275f2bbaa3
 	www.velocidex.com/golang/go-pe v0.1.1-0.20220506020923-9fac492a9b0d
 	www.velocidex.com/golang/go-prefetch v0.0.0-20220801101854-338dbe61982a
 	www.velocidex.com/golang/oleparse v0.0.0-20220617011920-94df2342d0b7
 	www.velocidex.com/golang/regparser v0.0.0-20221020153526-bbc758cbd18b
-	www.velocidex.com/golang/vfilter v0.0.0-20221020070405-7af3cd80b934
+	www.velocidex.com/golang/vfilter v0.0.0-20221101121437-3c06b865adbf
 )
 
 require (

go.sum

@@ -214,8 +214,9 @@ github.com/danwakefield/fnmatch v0.0.0-20160403171240-cbb64ac3d964 h1:y5HC9v93H5
 github.com/danwakefield/fnmatch v0.0.0-20160403171240-cbb64ac3d964/go.mod h1:Xd9hchkHSWYkEqJwUGisez3G1QY8Ryz0sdWrLPMGjLk=
 github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
 github.com/davecgh/go-spew v1.1.1-0.20170711183451-adab96458c51/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
-github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c=
 github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
+github.com/davecgh/go-spew v1.1.2-0.20180830191138-d8f796af33cc h1:U9qPSI2PIWSS1VwoXQT9A3Wy9MM3WgvqSxFWenqJduM=
+github.com/davecgh/go-spew v1.1.2-0.20180830191138-d8f796af33cc/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
 github.com/dimchansky/utfbom v1.1.1 h1:vV6w1AhK4VMnhBno/TPVCoK9U/LP0PkLCS9tbxHdi/U=
 github.com/dimchansky/utfbom v1.1.1/go.mod h1:SxdoEBH5qIqFocHMyGOXVAybYJdr71b1Q/j0mACtrfE=
 github.com/dlclark/regexp2 v1.2.0/go.mod h1:2pZnwuY/m+8K6iRw6wQdMtk+rH5tNGR1i55kozfMjCc=
@@ -592,6 +593,7 @@ github.com/stretchr/objx v0.1.1/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+
 github.com/stretchr/objx v0.2.0/go.mod h1:qt09Ya8vawLte6SNmTgCsAVtYtaKzEcn8ATUoHMkEqE=
 github.com/stretchr/objx v0.3.0/go.mod h1:qt09Ya8vawLte6SNmTgCsAVtYtaKzEcn8ATUoHMkEqE=
 github.com/stretchr/objx v0.4.0/go.mod h1:YvHI0jy2hoMjB+UWwv71VJQ9isScKT/TqJzVSSt89Yw=
+github.com/stretchr/objx v0.5.0/go.mod h1:Yh+to48EsGEfYuaHDzXPcE3xhTkx73EhmCGUpEOglKo=
 github.com/stretchr/testify v1.1.5-0.20170528135104-b8c9b4ef3dad/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs=
 github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs=
 github.com/stretchr/testify v1.2.3-0.20181224173747-660f15d67dbb/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs=
@@ -601,8 +603,9 @@ github.com/stretchr/testify v1.5.1/go.mod h1:5W2xD1RspED5o8YsWQXVCued0rvSQ+mT+I5
 github.com/stretchr/testify v1.6.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
 github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
 github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
-github.com/stretchr/testify v1.8.0 h1:pSgiaMZlXftHpm5L7V1+rVB+AZJydKsMxsQBIJw4PKk=
 github.com/stretchr/testify v1.8.0/go.mod h1:yNjHg4UonilssWZ8iaSj1OCr/vHnekPRkoO+kdMU+MU=
+github.com/stretchr/testify v1.8.1 h1:w7B6lhMri9wdJUVmEZPGGhZzrYTPvgJArz7wNPgYKsk=
+github.com/stretchr/testify v1.8.1/go.mod h1:w2LPCIKwWwSfY2zedu0+kehJoqGctiVI29o6fzry7u4=
 github.com/tink-ab/tempfile v0.0.0-20180226111222-33beb0518f1a h1:Qhm/9UKGO1+AjEKIsq8G72uCq4SrYxSxS5wiD0F3IC4=
 github.com/tink-ab/tempfile v0.0.0-20180226111222-33beb0518f1a/go.mod h1:Wt5qSdcHgX6XkqZKAZTxnN+93jnqtx0jEgTQakpZ1CE=
 github.com/tklauser/go-sysconf v0.3.9 h1:JeUVdAOWhhxVcU6Eqr/ATFHgXk/mmiItdKeJPev3vTo=
@@ -1183,8 +1186,8 @@ www.velocidex.com/golang/evtx v0.2.1-0.20220404133451-1fdf8be7325e h1:AhcXPgNKhJ
 www.velocidex.com/golang/evtx v0.2.1-0.20220404133451-1fdf8be7325e/go.mod h1:ykEQ7AUF9AL+mfCefDmLwmZOnU2So6wM3qKM8xdsHhU=
 www.velocidex.com/golang/go-ese v0.1.1-0.20220107095505-c38622559671 h1:pfvo7NFo0eJj6Zr7d+4vMx/Zr2JriMMPEWRHUf1YjUw=
 www.velocidex.com/golang/go-ese v0.1.1-0.20220107095505-c38622559671/go.mod h1:qnzHyB9yD2khtYO+wf3ck9FQxX3wFhXeJHFBnuUIZcc=
-www.velocidex.com/golang/go-ntfs v0.1.2-0.20221101075911-4e31a101eb08 h1:NJzZPvNwOEGu+AtTPkowu+F6Y4hn9EGbJyxgadE8Slg=
-www.velocidex.com/golang/go-ntfs v0.1.2-0.20221101075911-4e31a101eb08/go.mod h1:EJBeGhwlRw0Ktx9p/Mz+pWHcLzd9RR8Id6rsv95145c=
+www.velocidex.com/golang/go-ntfs v0.1.2-0.20221101112551-e6275f2bbaa3 h1:lPSi1+ykrrdCPitxX1iTNQk0qrPkmwI0nemRg3wf908=
+www.velocidex.com/golang/go-ntfs v0.1.2-0.20221101112551-e6275f2bbaa3/go.mod h1:itvbHQcnLdTVIDY6fI3lR0zeBwXwBYBdUFtswE0x1vc=
 www.velocidex.com/golang/go-pe v0.1.1-0.20220107093716-e91743c801de/go.mod h1:j9Xy8Z9wxzY2SCB8CqDkkoSzy+eUwevnOrRm/XM2q/A=
 www.velocidex.com/golang/go-pe v0.1.1-0.20220506020923-9fac492a9b0d h1:OQKwxK0O4a/8YTmfkQNzUspyrvlpRbLi318L08DC0oY=
 www.velocidex.com/golang/go-pe v0.1.1-0.20220506020923-9fac492a9b0d/go.mod h1:TPJ3phbAuZIu7XuPyNqgoP2k3P+eNHfHHGcivhcsxaA=
@@ -1197,5 +1200,7 @@ www.velocidex.com/golang/regparser v0.0.0-20221020153526-bbc758cbd18b/go.mod h1:
 www.velocidex.com/golang/vfilter v0.0.0-20220103082604-85bb38175cb7/go.mod h1:eEFMhAmoFHWGCKF39j+iOhTH8REpqBndc3OsdPsxqo8=
 www.velocidex.com/golang/vfilter v0.0.0-20221020070405-7af3cd80b934 h1:vUdXxTpIjiZmSvAp3dPEZs4ZcBpQKJWh3lfmZVqYKNQ=
 www.velocidex.com/golang/vfilter v0.0.0-20221020070405-7af3cd80b934/go.mod h1:R3nLf1iHcc7eezqqc68KF+SUOXaAJeFz3TV+j8xorfY=
+www.velocidex.com/golang/vfilter v0.0.0-20221101121437-3c06b865adbf h1:9QCjJRFZWaXrUhcUFzld1EhgHSXywn1dpEqq25dx55Q=
+www.velocidex.com/golang/vfilter v0.0.0-20221101121437-3c06b865adbf/go.mod h1:R3nLf1iHcc7eezqqc68KF+SUOXaAJeFz3TV+j8xorfY=
 www.velocidex.com/golang/vtypes v0.0.0-20220816192452-6a27ae078f12 h1:8azOLd/l6sPy1/ug03ueA7jLfsVwE1sI3oHg9q/nkqQ=
 www.velocidex.com/golang/vtypes v0.0.0-20220816192452-6a27ae078f12/go.mod h1:gpuRaiyhcuPmZYvI/zw+rjlDXklR2ORaLQBuzCXe84o=

gui/velociraptor/package.json

@@ -1,6 +1,6 @@
 {
     "name": "velociraptor",
-    "version": "0.6.6",
+    "version": "0.6.7",
     "private": true,
     "dependencies": {
         "@fortawesome/fontawesome-svg-core": "^1.3.0",

gui/velociraptor/src/components/flows/flow-logs.js

@@ -20,18 +20,31 @@ export default class FlowLogs extends React.Component {
 
     state = {
         level_filter: "all",
+        level_column: "level",
     }
 
     makeTransform() {
         if (this.state.level_filter !== "all") {
             return {
-                filter_column: "level",
+                filter_column: this.state.level_column,
                 filter_regex: this.state.level_filter,
             };
         }
         return {};
     }
 
+    getParams = ()=>{
+        return {
+            client_id: this.props.flow.client_id,
+            flow_id: this.props.flow.session_id,
+            type: "log",
+        };
+    }
+
+    getVersion = ()=>{
+        return getFlowState(this.props.flow);
+    }
+
     render() {
         let renderers = {
             client_time: (cell, row, rowIndex) => {
@@ -74,14 +87,10 @@ export default class FlowLogs extends React.Component {
             <VeloPagedTable
               className="col-12"
               renderers={renderers}
-              params={{
-                  client_id: this.props.flow.client_id,
-                  flow_id: this.props.flow.session_id,
-                  type: "log",
-              }}
+              params={this.getParams()}
               translate_column_headers={true}
               toolbar={toolbar}
-              version={getFlowState(this.props.flow)}
+              version={this.getVersion()}
               transform={this.makeTransform()}
               setTransform={x=>{
                   this.setState({level_filter: "all"});

gui/velociraptor/src/components/notebooks/logs.js

@@ -1,34 +1,39 @@
 import React, { Component } from 'react';
 import PropTypes from 'prop-types';
-import axios from 'axios';
 import Modal from 'react-bootstrap/Modal';
-import VeloPagedTable from '../core/paged-table.js';
-import VeloTimestamp from "../utils/time.js";
+import FlowLogs from '../flows/flow-logs.js';
 
-export default class ViewCellLogs extends Component {
+class ViewCellLogsTable extends FlowLogs {
     static propTypes = {
         cell: PropTypes.object,
         notebook_metadata: PropTypes.object.isRequired,
-        closeDialog: PropTypes.func.isRequired,
     };
 
-    // Create an artifact template from the VQL
-    componentDidMount = () => {
-        this.source = axios.CancelToken.source();
+    state = {
+        level_filter: "all",
+        level_column: "Level",
     }
 
-    componentWillUnmount() {
-        this.source.cancel("unmounted");
-    }
+    getVersion = ()=>{}
 
-    render() {
-        let params = {
+    getParams = ()=>{
+        return  {
             notebook_id: this.props.notebook_metadata &&
                 this.props.notebook_metadata.notebook_id,
             cell_id: this.props.cell && this.props.cell.cell_id,
             type: "logs",
         };
-        console.log(this.props.cell, this.props.notebook_metadata);
+    }
+}
+
+export default class ViewCellLogs extends Component {
+    static propTypes = {
+        cell: PropTypes.object,
+        notebook_metadata: PropTypes.object.isRequired,
+        closeDialog: PropTypes.func.isRequired,
+    };
+
+    render() {
         return (
             <Modal show={true}
                    className="full-height"
@@ -40,16 +45,9 @@ export default class ViewCellLogs extends Component {
                 <Modal.Title>View Cell Logs</Modal.Title>
               </Modal.Header>
               <Modal.Body>
-                <VeloPagedTable
-                  className="col-12"
-                  renderers={{
-                      Timestamp: (cell, row, rowIndex) => {
-                          return (
-                              <VeloTimestamp usec={cell / 1000}/>
-                          );
-                      }
-                  }}
-                  params={params}
+                <ViewCellLogsTable
+                  cell={this.props.cell}
+                  notebook_metadata={this.props.notebook_metadata}
                 />
               </Modal.Body>
               <Modal.Footer>

gui/velociraptor/src/components/notebooks/notebook-cell-renderer.js

@@ -706,17 +706,19 @@ export default class NotebookCellRenderer extends React.Component {
                     notebook_id={this.props.notebook_id}
                     cell={this.state.cell}/>
                   { selected &&
-                    _.map(this.state.cell.messages, (msg, idx) => {
-                        return <div key={idx} className="error-message">
-                        {msg}
-                        </div>;
-                    })}
-                  { selected && this.state.cell.more_messages &&
-                    <Button
-                      variant="secondary"
-                      onClick={()=>this.setState({showMoreLogs: true})}>
-                      {T("Logs")}
-                    </Button>
+                    <>
+                      {_.map(this.state.cell.messages, (msg, idx) => {
+                          return <div key={idx} className="error-message">
+                               {msg}
+                             </div>;
+                      })}
+
+                      <Button
+                        variant="secondary"
+                        onClick={()=>this.setState({showMoreLogs: true})}>
+                        {T("Logs")}
+                      </Button>
+                    </>
                   }
                 </div>
               </div>

services/server_artifacts/logger.go

@@ -1,6 +1,7 @@
 package server_artifacts
 
 import (
+	"context"
 	"time"
 
 	"github.com/Velocidex/ordereddict"
@@ -49,6 +50,7 @@ func (self *serverLogger) Write(b []byte) (int, error) {
 }
 
 func NewServerLogger(
+	ctx context.Context,
 	collection_context CollectionContextManager,
 	config_obj *config_proto.Config,
 	session_id string) (*serverLogger, error) {
@@ -62,9 +64,24 @@ func NewServerLogger(
 		return nil, err
 	}
 
-	return &serverLogger{
+	result := &serverLogger{
 		collection_context: collection_context,
 		config_obj:         config_obj,
 		writer:             writer,
-	}, nil
+	}
+
+	// Flush the logs every second to make sure the GUI shows
+	// progress.
+	go func() {
+		for {
+			select {
+			case <-ctx.Done():
+				return
+			case <-time.After(time.Second):
+				writer.Flush()
+			}
+		}
+	}()
+
+	return result, nil
 }

services/server_artifacts/server_artifacts.go

@@ -43,13 +43,13 @@ type ServerArtifactsRunner struct {
 	timeout          time.Duration
 	mu               sync.Mutex
 	wg               *sync.WaitGroup
-	cancellationPool map[string]func()
+	cancellationPool map[string]serverFlowContext
 }
 
 func NewServerArtifactRunner(config_obj *config_proto.Config) *ServerArtifactsRunner {
 	return &ServerArtifactsRunner{
 		config_obj:       config_obj,
-		cancellationPool: make(map[string]func()),
+		cancellationPool: make(map[string]serverFlowContext),
 		timeout:          time.Second * time.Duration(600),
 		wg:               &sync.WaitGroup{},
 	}
@@ -89,7 +89,7 @@ func (self *ServerArtifactsRunner) process(
 			if err != nil {
 				continue
 			}
-			logger, err := NewServerLogger(
+			logger, err := NewServerLogger(ctx,
 				collection_context, config_obj, session_id)
 			if err != nil {
 				continue
@@ -116,9 +116,10 @@ func (self *ServerArtifactsRunner) Cancel(flow_id string) {
 	self.mu.Lock()
 	defer self.mu.Unlock()
 
-	cancel, pres := self.cancellationPool[flow_id]
+	flow_context, pres := self.cancellationPool[flow_id]
 	if pres {
-		cancel()
+		flow_context.cancel()
+		flow_context.logger.writer.Flush()
 		delete(self.cancellationPool, flow_id)
 	}
 }
@@ -132,23 +133,17 @@ func (self *ServerArtifactsRunner) ProcessTask(
 
 	// Cancel the current collection
 	if task.Cancel != nil {
-		journal, err := services.GetJournal(config_obj)
-		if err != nil {
-			return err
+		self.mu.Lock()
+		flow_context, pres := self.cancellationPool[task.SessionId]
+		self.mu.Unlock()
+		if pres {
+			flow_context.logger.Write([]byte("INFO:Cancelling Query"))
 		}
 
-		path_manager := paths.NewFlowPathManager("server", task.SessionId).Log()
-		err = journal.AppendToResultSet(config_obj,
-			path_manager, []*ordereddict.Dict{
-				ordereddict.NewDict().
-					Set("Timestamp", time.Now().UTC().UnixNano()/1000).
-					Set("time", time.Now().UTC().String()).
-					Set("message", "Cancelling Query")})
-
 		// This task is now done.
 		self.Cancel(task.SessionId)
 
-		return err
+		return nil
 	}
 
 	err := self.runQuery(ctx, task, collection_context, logger)
@@ -204,7 +199,10 @@ func (self *ServerArtifactsRunner) runQuery(
 	sub_ctx, cancel := context.WithCancel(ctx)
 
 	self.mu.Lock()
-	self.cancellationPool[task.SessionId] = cancel
+	self.cancellationPool[task.SessionId] = serverFlowContext{
+		cancel: cancel,
+		logger: logger,
+	}
 	self.mu.Unlock()
 
 	defer func() {
@@ -373,6 +371,11 @@ func (self *ServerArtifactsRunner) runQuery(
 	return nil
 }
 
+type serverFlowContext struct {
+	cancel func()
+	logger *serverLogger
+}
+
 func NewServerArtifactService(
 	ctx context.Context,
 	wg *sync.WaitGroup,
@@ -382,7 +385,7 @@ func NewServerArtifactService(
 		config_obj:       config_obj,
 		timeout:          time.Second * time.Duration(600),
 		wg:               wg,
-		cancellationPool: make(map[string]func()),
+		cancellationPool: make(map[string]serverFlowContext),
 	}
 
 	logger := logging.GetLogger(