From b272c2acb5005fe12565c584745b430595a96711 Mon Sep 17 00:00:00 2001 From: Awbrey Hughlett Date: Fri, 8 Dec 2023 14:31:18 -0600 Subject: [PATCH] Verbose Simulation Output By default, the simulation output was already verbose by printing logs for each node to separate files and printing simulation output to a file. This change makes verbose no longer default and adds an option to do verbose logging output. --- SIMULATOR.md | 29 ++++++------ cmd/simulator/main.go | 3 +- tools/simulator/node/stats.go | 2 - tools/simulator/run/output.go | 20 +++++++-- tools/simulator/telemetry/contract.go | 10 ++--- tools/simulator/telemetry/log.go | 63 ++++++++++++++++++--------- tools/simulator/telemetry/rpc.go | 12 ++++- 7 files changed, 90 insertions(+), 49 deletions(-) diff --git a/SIMULATOR.md b/SIMULATOR.md index 2ab26707..2972d1fc 100644 --- a/SIMULATOR.md +++ b/SIMULATOR.md @@ -12,20 +12,6 @@ network layers are both fully simulated and do not match real instances 1:1. The simulator uses runbooks to control some of the underlying simulations such as p2p network latency, block production, upkeep schedules, and more. -## Profiling - -Start the service in one terminal window and run the pprof tool in another. For -more information on pprof, view some docs -[here](https://github.com/google/pprof/blob/main/doc/README.md) to get started. - -``` -# terminal 1 -$ ./bin/simulator --pprof --simulate -f ./tools/simulator/plans/simplan_fast_check.json - -# terminal 2 -$ go tool pprof -top http://localhost:6060/debug/pprof/heap -``` - ## Usage The current iteration of the simulator requires a full build before a run as the @@ -50,11 +36,26 @@ $ ./bin/simulator --simulate -f ./tools/simulator/plans/simplan_fast_check.json *Options* - `--simulation-file | -f [string]`: default ./simulation_plan.json, path to JSON file defining simulation parameters - `--output-directory | -o [string]`: default ./simulation_logs, path to output directory where run logs are written +- `--verbose [bool]`: default false, make output verbose (prints logs to output directory) - `--simulate [bool]`: default false, run simulation and output results - `--charts [bool]`: default false, start and run charts service to display results - `--pprof [bool]`: default false, run pprof server on simulation startup - `--pprof-port [int]`: default 6060, port to serve pprof profiler on +## Profiling + +Start the service in one terminal window and run the pprof tool in another. For +more information on pprof, view some docs +[here](https://github.com/google/pprof/blob/main/doc/README.md) to get started. + +``` +# terminal 1 +$ ./bin/simulator --pprof --simulate -f ./tools/simulator/plans/simplan_fast_check.json + +# terminal 2 +$ go tool pprof -top http://localhost:6060/debug/pprof/heap +``` + ## Simulation Plan A simulation plan is a set of configurations for the simulator defined in a JSON file and is designed to produce a diff --git a/cmd/simulator/main.go b/cmd/simulator/main.go index 7269d6d3..2983f5d5 100644 --- a/cmd/simulator/main.go +++ b/cmd/simulator/main.go @@ -26,6 +26,7 @@ import ( var ( simulationFile = flag.StringP("simulation-file", "f", "./simulation_plan.json", "file path to read simulation config from") outputDirectory = flag.StringP("output-directory", "o", "./simulation_plan_logs", "directory path to output log files") + verbose = flag.BoolP("verbose", "v", false, "make output verbose (prints logs to output directory)") simulate = flag.Bool("simulate", false, "run simulation") serveCharts = flag.Bool("charts", false, "create and serve charts") profiler = flag.Bool("pprof", false, "run pprof server on startup") @@ -53,7 +54,7 @@ func main() { } // ----- setup simulation output directory and file handles - outputs, err := run.SetupOutput(*outputDirectory, *simulate, plan) + outputs, err := run.SetupOutput(*outputDirectory, *simulate, *verbose, plan) if err != nil { procLog.Printf("failed to setup output directory: %s", err) os.Exit(1) diff --git a/tools/simulator/node/stats.go b/tools/simulator/node/stats.go index e0be7226..5d2a7ea3 100644 --- a/tools/simulator/node/stats.go +++ b/tools/simulator/node/stats.go @@ -24,7 +24,6 @@ func newUpkeepStatsBuilder( checks map[string][]string, encoder ocr2keepers.Encoder, ) (*upkeepStatsBuilder, error) { - // count the number of transmits per account accTr := make(map[string]int) @@ -85,7 +84,6 @@ func (b *upkeepStatsBuilder) UpkeepIDs() []string { srcUpkeepID := ocr2keepers.UpkeepIdentifier(upkeep.UpkeepID) for _, upkeepID := range allIDs { - if upkeepID == srcUpkeepID.String() { found = true } diff --git a/tools/simulator/run/output.go b/tools/simulator/run/output.go index d2c73118..7d201743 100644 --- a/tools/simulator/run/output.go +++ b/tools/simulator/run/output.go @@ -3,6 +3,7 @@ package run import ( "errors" "fmt" + "io" "io/fs" "log" "os" @@ -29,7 +30,18 @@ func (out *Outputs) Close() error { return err } -func SetupOutput(path string, simulate bool, plan config.SimulationPlan) (*Outputs, error) { +func SetupOutput(path string, simulate, verbose bool, plan config.SimulationPlan) (*Outputs, error) { + if !verbose { + logger := log.New(io.Discard, "", 0) + + return &Outputs{ + SimulationLog: logger, + RPCCollector: telemetry.NewNodeRPCCollector("", false), + LogCollector: telemetry.NewNodeLogCollector("", false), + EventCollector: telemetry.NewContractEventCollector(logger), + }, nil + } + var ( logger *log.Logger lggF *os.File @@ -59,9 +71,9 @@ func SetupOutput(path string, simulate bool, plan config.SimulationPlan) (*Outpu return &Outputs{ SimulationLog: logger, - RPCCollector: telemetry.NewNodeRPCCollector(path), - LogCollector: telemetry.NewNodeLogCollector(path), - EventCollector: telemetry.NewContractEventCollector(path, logger), + RPCCollector: telemetry.NewNodeRPCCollector(path, true), + LogCollector: telemetry.NewNodeLogCollector(path, true), + EventCollector: telemetry.NewContractEventCollector(logger), simulationLogFileHandle: lggF, }, nil } diff --git a/tools/simulator/telemetry/contract.go b/tools/simulator/telemetry/contract.go index 8416f876..a8cba066 100644 --- a/tools/simulator/telemetry/contract.go +++ b/tools/simulator/telemetry/contract.go @@ -13,24 +13,20 @@ type ContractEventCollector struct { // dependencies logger *log.Logger - // configuration - filePath string - // internal state properties mu sync.RWMutex nodes map[string]*WrappedContractCollector } -func NewContractEventCollector(path string, logger *log.Logger) *ContractEventCollector { +func NewContractEventCollector(logger *log.Logger) *ContractEventCollector { return &ContractEventCollector{ baseCollector: baseCollector{ t: NodeLogType, io: []io.WriteCloser{}, ioLookup: make(map[string]int), }, - logger: log.New(logger.Writer(), "[contract-event-collector]", log.Ldate|log.Ltime|log.Lshortfile), - filePath: path, - nodes: make(map[string]*WrappedContractCollector), + logger: log.New(logger.Writer(), "[contract-event-collector]", log.Ldate|log.Ltime|log.Lshortfile), + nodes: make(map[string]*WrappedContractCollector), } } diff --git a/tools/simulator/telemetry/log.go b/tools/simulator/telemetry/log.go index 1df417d5..91168d7a 100644 --- a/tools/simulator/telemetry/log.go +++ b/tools/simulator/telemetry/log.go @@ -10,12 +10,14 @@ import ( type NodeLogCollector struct { baseCollector filePath string + verbose bool } -func NewNodeLogCollector(path string) *NodeLogCollector { - err := os.MkdirAll(path, 0750) - if err != nil && !os.IsExist(err) { - panic(err) +func NewNodeLogCollector(path string, verbose bool) *NodeLogCollector { + if verbose { + if err := os.MkdirAll(path, 0750); err != nil && !os.IsExist(err) { + panic(err) + } } return &NodeLogCollector{ @@ -25,6 +27,7 @@ func NewNodeLogCollector(path string) *NodeLogCollector { ioLookup: make(map[string]int), }, filePath: path, + verbose: verbose, } } @@ -52,35 +55,55 @@ func (c *NodeLogCollector) GeneralLog(node string) io.Writer { func (c *NodeLogCollector) AddNode(node string) error { path := fmt.Sprintf("%s/%s", c.filePath, node) - err := os.MkdirAll(path, 0750) - if err != nil && !os.IsExist(err) { - panic(err) - } - var perms fs.FileMode = 0666 - flag := os.O_RDWR | os.O_CREATE | os.O_TRUNC + if c.verbose { + if err := os.MkdirAll(path, 0750); err != nil && !os.IsExist(err) { + panic(err) + } + } - key := fmt.Sprintf("general/%s", node) + if err := c.addWriterForKey(fmt.Sprintf("%s/general.log", path), fmt.Sprintf("general/%s", node)); err != nil { + return err + } - f, err := os.OpenFile(fmt.Sprintf("%s/general.log", path), flag, perms) - if err != nil { - f.Close() + if err := c.addWriterForKey(fmt.Sprintf("%s/contract.log", path), fmt.Sprintf("contract/%s", node)); err != nil { return err } - c.ioLookup[key] = len(c.io) - c.io = append(c.io, f) + return nil +} + +func (c *NodeLogCollector) addWriterForKey(path, key string) error { + if !c.verbose { + c.ioLookup[key] = len(c.io) + c.io = append(c.io, writeCloseDiscard{}) - key = fmt.Sprintf("contract/%s", node) + return nil + } + + var perms fs.FileMode = 0666 - cLog, err := os.OpenFile(fmt.Sprintf("%s/contract.log", path), flag, perms) + flag := os.O_RDWR | os.O_CREATE | os.O_TRUNC + + file, err := os.OpenFile(fmt.Sprintf("%s/general.log", path), flag, perms) if err != nil { - cLog.Close() + file.Close() + return err } c.ioLookup[key] = len(c.io) - c.io = append(c.io, cLog) + c.io = append(c.io, file) + + return nil +} + +type writeCloseDiscard struct{} + +func (writeCloseDiscard) Write(bts []byte) (int, error) { + return len(bts), nil +} +func (writeCloseDiscard) Close() error { return nil } diff --git a/tools/simulator/telemetry/rpc.go b/tools/simulator/telemetry/rpc.go index 75694cb3..f16111a8 100644 --- a/tools/simulator/telemetry/rpc.go +++ b/tools/simulator/telemetry/rpc.go @@ -20,14 +20,16 @@ import ( type RPCCollector struct { baseCollector filePath string + verbose bool nodes map[string]*WrappedRPCCollector } -func NewNodeRPCCollector(path string) *RPCCollector { +func NewNodeRPCCollector(path string, verbose bool) *RPCCollector { return &RPCCollector{ baseCollector: baseCollector{ t: RPCType, }, + verbose: verbose, filePath: path, nodes: make(map[string]*WrappedRPCCollector), } @@ -45,6 +47,10 @@ func (c *RPCCollector) AddNode(node string) error { } func (c *RPCCollector) WriteResults() error { + if !c.verbose { + return nil + } + for key, node := range c.nodes { path := fmt.Sprintf("%s/%s", c.filePath, key) err := os.MkdirAll(path, 0750) @@ -159,6 +165,10 @@ func (c *RPCCollector) collectDataFromFile() ([]string, map[string][]rpcDataPoin rateData := make(map[string][]rpcDataPoint) path := c.filePath + if !c.verbose { + return ids, rateData, fmt.Errorf("verbose logging not activated") + } + files, err := os.ReadDir(path) if err != nil { return ids, rateData, err