From 00abdc8b1c4be3536ada97580757c0117a37ff09 Mon Sep 17 00:00:00 2001 From: Noah Metz Date: Sun, 4 Jun 2023 13:18:10 -0600 Subject: [PATCH] Moved logging to a global object that's initialized on first log call --- event.go | 29 +++++++++++------------ go.mod | 4 ++++ go.sum | 13 +++++++++++ graph.go | 67 ++++++++++++++++++++++++++++++++++++++++++++++++----- main.go | 64 ++++++++++++++++++++++---------------------------- manager.go | 17 +++++++------- resource.go | 1 + vex.go | 41 ++++++++++++++++---------------- 8 files changed, 149 insertions(+), 87 deletions(-) diff --git a/event.go b/event.go index f6ce5c7..8fba6d5 100644 --- a/event.go +++ b/event.go @@ -3,7 +3,6 @@ package main import ( "fmt" "time" - "log" "errors" "reflect" "sort" @@ -162,7 +161,7 @@ func AddChild(event Event, child Event, info EventInfo) error { } func RunEvent(event Event) error { - log.Printf("EVENT_RUN: %s", event.Name()) + log.Logf("event", "EVENT_RUN: %s", event.Name()) go SendUpdate(event, NewSignal(event, "event_start")) next_action := "start" var err error = nil @@ -173,14 +172,14 @@ func RunEvent(event Event) error { return errors.New(error_str) } - log.Printf("EVENT_ACTION: %s - %s", event.Name(), next_action) + log.Logf("event", "EVENT_ACTION: %s - %s", event.Name(), next_action) next_action, err = action() if err != nil { return err } } - log.Printf("EVENT_RUN_DONE: %s", event.Name()) + log.Logf("event", "EVENT_RUN_DONE: %s", event.Name()) return nil } @@ -224,7 +223,7 @@ func LockResources(event Event) error { func FinishEvent(event Event) error { // TODO make more 'safe' like LockResources, or make UnlockResource not return errors - log.Printf("EVENT_FINISH: %s", event.Name()) + log.Logf("event", "EVENT_FINISH: %s", event.Name()) for _, resource := range(event.RequiredResources()) { err := UnlockResource(resource, event) if err != nil { @@ -278,26 +277,26 @@ func (event * BaseEvent) Action(action string) (func() (string, error), bool) { func EventWait(event Event) (func() (string, error)) { return func() (string, error) { - log.Printf("EVENT_WAIT: %s TIMEOUT: %+v", event.Name(), event.Timeout()) + log.Logf("event", "EVENT_WAIT: %s TIMEOUT: %+v", event.Name(), event.Timeout()) select { case signal := <- event.Signal(): if signal.Source() != nil { - log.Printf("EVENT_SIGNAL: %s %s %s -> %+v", event.Name(), signal.Last(), signal.Source().Name(), signal) + log.Logf("event", "EVENT_SIGNAL: %s %s %s -> %+v", event.Name(), signal.Last(), signal.Source().Name(), signal) } else { - log.Printf("EVENT_SIGNAL: %s %s nil -> %+v", event.Name(), signal.Last(), signal) + log.Logf("event", "EVENT_SIGNAL: %s %s nil -> %+v", event.Name(), signal.Last(), signal) } if signal.Type() == "abort" { return "", errors.New("State machine aborted by signal") } else { signal_fn, exists := event.Handler(signal.Type()) if exists == true { - log.Printf("EVENT_HANDLER: %s - %s", event.Name(), signal.Type()) + log.Logf("event", "EVENT_HANDLER: %s - %s", event.Name(), signal.Type()) return signal_fn(signal) } } return "wait", nil case <- event.Timeout(): - log.Printf("EVENT_TIMEOUT %s - NEXT_STATE: %s", event.Name(), event.TimeoutAction()) + log.Logf("event", "EVENT_TIMEOUT %s - NEXT_STATE: %s", event.Name(), event.TimeoutAction()) return event.TimeoutAction(), nil } } @@ -403,15 +402,15 @@ func NewEventQueue(name string, description string, required_resources []Resourc err := LockResources(event) // start in new goroutine if err != nil { - //log.Printf("Failed to lock %s: %s", event.Name(), err) + //log.Logf("event", "Failed to lock %s: %s", event.Name(), err) } else { info.state = "running" - log.Printf("EVENT_START: %s", event.Name()) + log.Logf("event", "EVENT_START: %s", event.Name()) go func(event Event, info * EventQueueInfo, queue Event) { - log.Printf("EVENT_GOROUTINE: %s", event.Name()) + log.Logf("event", "EVENT_GOROUTINE: %s", event.Name()) err := RunEvent(event) if err != nil { - log.Printf("EVENT_ERROR: %s", err) + log.Logf("event", "EVENT_ERROR: %s", err) } info.state = "done" FinishEvent(event) @@ -426,7 +425,7 @@ func NewEventQueue(name string, description string, required_resources []Resourc for _, resource := range(needed_resources) { _, exists := queue.listened_resources[resource.ID()] if exists == false { - log.Printf("REGISTER_RESOURCE: %s - %s", queue.Name(), resource.Name()) + log.Logf("event", "REGISTER_RESOURCE: %s - %s", queue.Name(), resource.Name()) queue.listened_resources[resource.ID()] = resource resource.RegisterChannel(queue.signal) } diff --git a/go.mod b/go.mod index bcd5f47..142fa5e 100644 --- a/go.mod +++ b/go.mod @@ -4,4 +4,8 @@ go 1.20 require ( github.com/google/uuid v1.3.0 // indirect + github.com/mattn/go-colorable v0.1.12 // indirect + github.com/mattn/go-isatty v0.0.14 // indirect + github.com/rs/zerolog v1.29.1 // indirect + golang.org/x/sys v0.0.0-20210927094055-39ccf1dd6fa6 // indirect ) diff --git a/go.sum b/go.sum index c189241..5d5a432 100644 --- a/go.sum +++ b/go.sum @@ -1,7 +1,9 @@ +github.com/coreos/go-systemd/v22 v22.5.0/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc= github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/go-logr/logr v1.2.2/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= github.com/go-logr/logr v1.2.3/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= github.com/go-logr/stdr v1.2.2/go.mod h1:mMo/vtBO5dYbehREoey6XUKy/eSumjCCveDpRre4VKE= +github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA= github.com/google/go-cmp v0.5.7/go.mod h1:n+brtR0CgQNWTVd5ZUFpTBC8YFBDLK/h/bpaJ8/DtOE= github.com/google/uuid v1.3.0 h1:t6JiXgmwXMjEs8VusXIJk2BXHsn+wx8BZdTaoZ5fu7I= github.com/google/uuid v1.3.0/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo= @@ -9,13 +11,24 @@ github.com/graph-gophers/graphql-go v1.5.0 h1:fDqblo50TEpD0LY7RXk/LFVYEVqo3+tXMN github.com/graph-gophers/graphql-go v1.5.0/go.mod h1:YtmJZDLbF1YYNrlNAuiO5zAStUWc3XZT07iGsVqe1Os= github.com/looplab/fsm v1.0.1 h1:OEW0ORrIx095N/6lgoGkFkotqH6s7vaFPsgjLAaF5QU= github.com/looplab/fsm v1.0.1/go.mod h1:PmD3fFvQEIsjMEfvZdrCDZ6y8VwKTwWNjlpEr6IKPO4= +github.com/mattn/go-colorable v0.1.12 h1:jF+Du6AlPIjs2BiUiQlKOX0rt3SujHxPnksPKZbaA40= +github.com/mattn/go-colorable v0.1.12/go.mod h1:u5H1YNBxpqRaxsYJYSkiCWKzEfiAb1Gb520KVy5xxl4= +github.com/mattn/go-isatty v0.0.14 h1:yVuAays6BHfxijgZPzw+3Zlu5yQgKGP2/hcQbHb7S9Y= +github.com/mattn/go-isatty v0.0.14/go.mod h1:7GGIvUiUoEMVVmxf/4nioHXj79iQHKdU27kJ6hsGG94= github.com/opentracing/opentracing-go v1.2.0/go.mod h1:GxEUsuufX4nBwe+T+Wl9TAgYrxe9dPLANfrWvHYVTgc= +github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= +github.com/rs/xid v1.4.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg= +github.com/rs/zerolog v1.29.1 h1:cO+d60CHkknCbvzEWxP0S9K6KqyTjrCNUy1LdQLCGPc= +github.com/rs/zerolog v1.29.1/go.mod h1:Le6ESbR7hc+DP6Lt1THiV8CQSdkkNrd3R0XbEgp3ZBU= github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI= github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= go.opentelemetry.io/otel v1.6.3/go.mod h1:7BgNga5fNlF/iZjG06hM3yofffp0ofKCDwSXx1GC4dI= go.opentelemetry.io/otel/trace v1.6.3/go.mod h1:GNJQusJlUgZl9/TQBPKU/Y/ty+0iVB5fjhKeJGZPGFs= +golang.org/x/sys v0.0.0-20210630005230-0f9fa26af87c/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.0.0-20210927094055-39ccf1dd6fa6 h1:foEbQz/B0Oz6YIqu/69kfXPYeFQAuuMYFkjaqXzl5Wo= +golang.org/x/sys v0.0.0-20210927094055-39ccf1dd6fa6/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/xerrors v0.0.0-20191204190536-9bdfabe68543/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= diff --git a/graph.go b/graph.go index 58b2b87..8b3b46b 100644 --- a/graph.go +++ b/graph.go @@ -1,12 +1,67 @@ package main import ( - "log" "sync" "github.com/google/uuid" "time" + "os" + "github.com/rs/zerolog" + "fmt" + "io" ) +type Logger interface { + Init() error + Logf(component string, format string, items ... interface{}) +} + +type DefaultLogger struct { + init bool + init_lock sync.Mutex + loggers map[string]zerolog.Logger +} + +var log DefaultLogger = DefaultLogger{loggers: map[string]zerolog.Logger{}} +var all_components = []string{"update", "graph", "event", "resource", "manager", "test"} + +func (logger * DefaultLogger) Init(components []string) error { + file, err := os.OpenFile("test.log", os.O_TRUNC|os.O_CREATE|os.O_WRONLY, 0666) + if err != nil { + return err + } + + component_enabled := func (component string) bool { + for _, c := range(components) { + if c == component { + return true + } + } + return false + } + + writer := io.MultiWriter(file, os.Stdout) + for _, c := range(all_components) { + if component_enabled(c) == true { + logger.loggers[c] = zerolog.New(writer).With().Timestamp().Str("component", c).Logger() + } + } + return nil +} + +func (logger * DefaultLogger) Logf(component string, format string, items ... interface{}) { + logger.init_lock.Lock() + if logger.init == false { + logger.Init(all_components) + logger.init = true + } + logger.init_lock.Unlock() + + l, exists := logger.loggers[component] + if exists == true { + l.Log().Msg(fmt.Sprintf(format, items...)) + } +} + // Generate a random graphql id func randid() string{ uuid_str := uuid.New().String() @@ -84,7 +139,7 @@ func NewBaseNode(name string, description string, id string) BaseNode { signal: make(chan GraphSignal, 1000), listeners: map[chan GraphSignal]chan GraphSignal{}, } - log.Printf("NEW_NODE: %s - %s", node.ID(), node.Name()) + log.Logf("graph", "NEW_NODE: %s - %s", node.ID(), node.Name()) return node } @@ -146,11 +201,11 @@ func (node * BaseNode) UpdateListeners(update GraphSignal) { closed := []chan GraphSignal{} for _, listener := range node.listeners { - log.Printf("UPDATE_LISTENER %s: %p", node.Name(), listener) + log.Logf("update", "UPDATE_LISTENER %s: %p", node.Name(), listener) select { case listener <- update: default: - log.Printf("CLOSED_LISTENER: %s: %p", node.Name(), listener) + log.Logf("update", "CLOSED_LISTENER: %s: %p", node.Name(), listener) go func(node GraphNode, listener chan GraphSignal) { listener <- NewSignal(node, "listener_closed") close(listener) @@ -171,9 +226,9 @@ func (node * BaseNode) update(signal GraphSignal) { func SendUpdate(node GraphNode, signal GraphSignal) { if signal.Source() != nil { - log.Printf("UPDATE %s -> %s: %+v", signal.Source().Name(), node.Name(), signal) + log.Logf("update", "UPDATE %s -> %s: %+v", signal.Source().Name(), node.Name(), signal) } else { - log.Printf("UPDATE %s: %+v", node.Name(), signal) + log.Logf("update", "UPDATE %s: %+v", node.Name(), signal) } node.UpdateListeners(signal) diff --git a/main.go b/main.go index 8cf8fa5..e9cdb5e 100644 --- a/main.go +++ b/main.go @@ -1,7 +1,6 @@ package main import ( - "log" "runtime/pprof" "time" "os" @@ -95,32 +94,25 @@ func fake_data() (* EventManager, *Arena, *Arena) { root_event := NewEventQueue("root_event", "", []Resource{}) - stay_resource := NewResource("stay_resource", "", []Resource{}) - resources = append(resources, stay_resource) - stay_event := NewEvent("stay_event", "", []Resource{stay_resource}) - LockResource(stay_resource, stay_event) event_manager := NewEventManager(root_event, resources) - event_manager.AddEvent(root_event, stay_event, NewEventQueueInfo(1)) - - go func(alliances []*Alliance, arenas []*Arena, event_manager * EventManager) { - for i, alliance := range(alliances) { - for j, alliance2 := range(alliances) { - if j != i { - if alliance.Children()[0] == alliance2.Children()[0] || alliance.Children()[0] == alliance2.Children()[1] || alliance.Children()[1] == alliance2.Children()[0] || alliance.Children()[1] == alliance2.Children()[1] { - } else { - for arena_idx := 0; arena_idx < len(arenas); arena_idx++ { - match := NewMatch(alliance, alliance2, arenas[arena_idx]) - log.Printf("Adding %s", match.Name()) - err := event_manager.AddEvent(root_event, match, NewEventQueueInfo(i)) - if err != nil { - log.Printf("Error adding %s: %s", match.Name(), err) - } + + for i, alliance := range(alliances) { + for j, alliance2 := range(alliances) { + if j != i { + if alliance.Children()[0] == alliance2.Children()[0] || alliance.Children()[0] == alliance2.Children()[1] || alliance.Children()[1] == alliance2.Children()[0] || alliance.Children()[1] == alliance2.Children()[1] { + } else { + for arena_idx := 0; arena_idx < len(arenas); arena_idx++ { + match := NewMatch(alliance, alliance2, arenas[arena_idx]) + log.Logf("test", "Adding %s", match.Name()) + err := event_manager.AddEvent(root_event, match, NewEventQueueInfo(i)) + if err != nil { + log.Logf("test", "Error adding %s: %s", match.Name(), err) } } } } } - }(alliances, arenas, event_manager) + } return event_manager, arenas[0], arenas[1] } @@ -146,49 +138,49 @@ func NewFakeClient(arena *Arena) * FakeClient { func (client * FakeClient) process_update(update GraphSignal) { arena := client.arena if update.Source() != nil { - log.Printf("FAKE_CLIENT_UPDATE: %s -> %+v", update.Source().ID(), update) + log.Logf("test", "FAKE_CLIENT_UPDATE: %s -> %+v", update.Source().ID(), update) } else { - log.Printf("FAKE_CLIENT_UPDATE: nil -> %+v", update) + log.Logf("test", "FAKE_CLIENT_UPDATE: nil -> %+v", update) } if update.Type() == "event_start" { if client.state != "init" { - log.Printf("BAD_CLIENT_STATE: event_start when match not in init: %s %s", arena.Name(), client.state) + log.Logf("test", "BAD_CLIENT_STATE: event_start when match not in init: %s %s", arena.Name(), client.state) } client.state = "autonomous_queued" - log.Printf("FAKE_CLIENT_ACTION: Match started on %s, queuing autonomous automatically", arena.Name()) + log.Logf("test", "FAKE_CLIENT_ACTION: Match started on %s, queuing autonomous automatically", arena.Name()) SendUpdate(arena, NewSignal(nil, "queue_autonomous")) } else if update.Type() == "autonomous_queued" { if client.state != "autonomous_queued" { - log.Printf("BAD_CLIENT_STATE: autonomous_queued when match not in autonomous_queued: %s %s", arena.Name(), client.state) + log.Logf("test", "BAD_CLIENT_STATE: autonomous_queued when match not in autonomous_queued: %s %s", arena.Name(), client.state) } client.state = "autonomous_started" - log.Printf("FAKE_CLIENT_ACTION: Autonomous queued on %s for %s, starting automatically at requested time", arena.Name(), update.Time()) + log.Logf("test", "FAKE_CLIENT_ACTION: Autonomous queued on %s for %s, starting automatically at requested time", arena.Name(), update.Time()) signal := NewSignal(nil, "start_autonomous") signal.time = update.Time() SendUpdate(arena, signal) } else if update.Type() == "autonomous_done" { if client.state != "autonomous_started" { - log.Printf("BAD_CLIENT_STATE: autonomous_done when match not in autonomous_started: %s %s", arena.Name(), client.state) + log.Logf("test", "BAD_CLIENT_STATE: autonomous_done when match not in autonomous_started: %s %s", arena.Name(), client.state) } client.state = "driver_queued" - log.Printf("FAKE_CLIENT_ACTION: Autonomous done on %s for %s, queueing driver automatically", arena.Name(), update.Time()) + log.Logf("test", "FAKE_CLIENT_ACTION: Autonomous done on %s for %s, queueing driver automatically", arena.Name(), update.Time()) signal := NewSignal(nil, "queue_driver") SendUpdate(arena, signal) } else if update.Type() == "driver_queued" { if client.state != "driver_queued" { - log.Printf("BAD_CLIENT_STATE: driver_queued when match not in autonomous_done: %s %s", arena.Name(), client.state) + log.Logf("test", "BAD_CLIENT_STATE: driver_queued when match not in autonomous_done: %s %s", arena.Name(), client.state) } client.state = "driver_started" - log.Printf("FAKE_CLIENT_ACTION: Driver queueud on %s for %s, starting driver automatically at requested time", arena.Name(), update.Time()) + log.Logf("test", "FAKE_CLIENT_ACTION: Driver queueud on %s for %s, starting driver automatically at requested time", arena.Name(), update.Time()) signal := NewSignal(nil, "start_driver") signal.time = update.Time() SendUpdate(arena, signal) } else if update.Type() == "driver_done" { if client.state != "driver_started" { - log.Printf("BAD_CLIENT_STATE: driver_done when match not in driver_started: %s %s", arena.Name(), client.state) + log.Logf("test", "BAD_CLIENT_STATE: driver_done when match not in driver_started: %s %s", arena.Name(), client.state) } client.state = "init" - log.Printf("FAKE_CLIENT_ACTION: Driver done on %s for %s", arena.Name(), update.Time()) + log.Logf("test", "FAKE_CLIENT_ACTION: Driver done on %s for %s", arena.Name(), update.Time()) } } @@ -214,11 +206,11 @@ func main() { } } }() - log.Printf("Starting event_manager") + log.Logf("test", "Starting event_manager") err := event_manager.Run() if err != nil { - log.Printf("Error running event_manager: %s", err) + log.Logf("test", "Error running event_manager: %s", err) } else { - log.Printf("Finished event_manager") + log.Logf("test", "Finished event_manager") } } diff --git a/manager.go b/manager.go index cd982f5..7c383c7 100644 --- a/manager.go +++ b/manager.go @@ -2,7 +2,6 @@ package main import ( "fmt" - "log" "errors" ) @@ -25,14 +24,14 @@ func NewEventManager(root_event Event, dag_nodes []Resource) * EventManager { for _, resource := range dag_nodes { err := manager.AddResource(resource) if err != nil { - log.Printf("Failed to add %s to EventManager: %s", resource.Name(), err) + log.Logf("manager", "Failed to add %s to EventManager: %s", resource.Name(), err) return nil } } err := manager.AddEvent(nil, root_event, nil) if err != nil { - log.Printf("Failed to add %s to EventManager as root_event: %s", root_event.Name(), err) + log.Logf("manager", "Failed to add %s to EventManager as root_event: %s", root_event.Name(), err) } return manager; @@ -40,7 +39,7 @@ func NewEventManager(root_event Event, dag_nodes []Resource) * EventManager { // Connect to all resources(in a thread to handle reconnections), and start the first event func (manager * EventManager) Run() error { - log.Printf("MANAGER_START") + log.Logf("manager", "MANAGER_START") abort := make(chan error, 1) go func(abort chan error, manager * EventManager) { @@ -52,7 +51,7 @@ func (manager * EventManager) Run() error { err := LockResources(manager.root_event) if err != nil { - log.Printf("MANAGER_LOCK_ERR: %s", err) + log.Logf("manager", "MANAGER_LOCK_ERR: %s", err) abort <- nil return err } @@ -60,16 +59,16 @@ func (manager * EventManager) Run() error { err = RunEvent(manager.root_event) abort <- nil if err != nil { - log.Printf("MANAGER_RUN_ERR: %s", err) + log.Logf("manager", "MANAGER_RUN_ERR: %s", err) return err } err = FinishEvent(manager.root_event) if err != nil { - log.Printf("MANAGER_FINISH_ERR: %s", err) + log.Logf("manager", "MANAGER_FINISH_ERR: %s", err) return err } - log.Printf("MANAGER_DONE") + log.Logf("manager", "MANAGER_DONE") return nil } @@ -90,7 +89,7 @@ func (manager * EventManager) FindEvent(id string) Event { } func (manager * EventManager) AddResource(resource Resource) error { - log.Printf("Adding resource %s", resource.Name()) + log.Logf("manager", "Adding resource %s", resource.Name()) _, exists := manager.dag_nodes[resource.ID()] if exists == true { error_str := fmt.Sprintf("%s is already in the resource DAG, cannot add again", resource.Name()) diff --git a/resource.go b/resource.go index e94780e..ad75cf9 100644 --- a/resource.go +++ b/resource.go @@ -20,6 +20,7 @@ func (resource * BaseResource) update(signal GraphSignal) { SendUpdate(resource.lock_holder, new_signal) } } + } // Resource is the interface that DAG nodes are made from diff --git a/vex.go b/vex.go index 26c6b05..6aba5d1 100644 --- a/vex.go +++ b/vex.go @@ -2,7 +2,6 @@ package main import ( "fmt" - "log" "time" "errors" ) @@ -80,7 +79,7 @@ func NewVirtualArena(name string) * Arena { func (arena * Arena) lock(event Event) error { if arena.connected == false { - log.Printf("ARENA NOT CONNECTED: %s", arena.Name()) + log.Logf("vex", "ARENA NOT CONNECTED: %s", arena.Name()) error_str := fmt.Sprintf("%s is not connected, cannot lock", arena.Name()) return errors.New(error_str) } @@ -88,36 +87,36 @@ func (arena * Arena) lock(event Event) error { } func (arena * Arena) update(signal GraphSignal) { - log.Printf("ARENA_UPDATE: %s", arena.Name()) + log.Logf("vex", "ARENA_UPDATE: %s", arena.Name()) arena.signal <- signal arena.BaseResource.update(signal) } func (arena * Arena) Connect(abort chan error) bool { - log.Printf("Connecting %s", arena.Name()) + log.Logf("vex", "Connecting %s", arena.Name()) go func(arena * Arena, abort chan error) { update_str := fmt.Sprintf("VIRTUAL_ARENA connected: %s", arena.Name()) signal := NewSignal(arena, "resource_connected") signal.description = update_str arena.connected = true go SendUpdate(arena, signal) - log.Printf("VIRTUAL_ARENA goroutine starting: %s", arena.Name()) + log.Logf("vex", "VIRTUAL_ARENA goroutine starting: %s", arena.Name()) for true { select { case <- abort: - log.Printf("Virtual arena %s aborting", arena.Name()) + log.Logf("vex", "Virtual arena %s aborting", arena.Name()) break case update := <- arena.signal: - log.Printf("VIRTUAL_ARENA_ACTION: %s : %+v", arena.Name(), update) + log.Logf("vex", "VIRTUAL_ARENA_ACTION: %s : %+v", arena.Name(), update) } } }(arena, abort) return true } -const start_slack = 3000 * time.Millisecond -const TEMP_AUTON_TIME = time.Second * 3 -const TEMP_DRIVE_TIME = time.Second * 5 +const start_slack = 250 * time.Millisecond +const TEMP_AUTON_TIME = time.Second * 1 +const TEMP_DRIVE_TIME = time.Second * 1 type Match struct { BaseEvent @@ -147,7 +146,7 @@ func NewMatch(alliance0 * Alliance, alliance1 * Alliance, arena * Arena) * Match match.actions["wait"] = EventWait(match) match.actions["start"] = func() (string, error) { - log.Printf("STARTING_MATCH %s", match.Name()) + log.Logf("vex", "STARTING_MATCH %s", match.Name()) match.control = "none" match.state = "scheduled" return "wait", nil @@ -155,10 +154,10 @@ func NewMatch(alliance0 * Alliance, alliance1 * Alliance, arena * Arena) * Match match.handlers["queue_autonomous"] = func(signal GraphSignal) (string, error) { if match.state != "scheduled" { - log.Printf("BAD_STATE: %s: %s - %s", signal.Type(), match.state, match.Name()) + log.Logf("vex", "BAD_STATE: %s: %s - %s", signal.Type(), match.state, match.Name()) return "wait", nil } - log.Printf("AUTONOMOUS_QUEUED: %s", match.Name()) + log.Logf("vex", "AUTONOMOUS_QUEUED: %s", match.Name()) match.control = "none" match.state = "autonomous_queued" match.control_start = time.Now().Add(start_slack) @@ -170,10 +169,10 @@ func NewMatch(alliance0 * Alliance, alliance1 * Alliance, arena * Arena) * Match match.handlers["start_autonomous"] = func(signal GraphSignal) (string, error) { if match.state != "autonomous_queued" { - log.Printf("BAD_STATE: %s: %s - %s", signal.Type(), match.state, match.Name()) + log.Logf("vex", "BAD_STATE: %s: %s - %s", signal.Type(), match.state, match.Name()) return "wait", nil } - log.Printf("AUTONOMOUS_RUNNING: %s", match.Name()) + log.Logf("vex", "AUTONOMOUS_RUNNING: %s", match.Name()) match.control = "program" match.state = "autonomous_running" match.control_start = signal.Time() @@ -181,16 +180,16 @@ func NewMatch(alliance0 * Alliance, alliance1 * Alliance, arena * Arena) * Match end_time := match.control_start.Add(TEMP_AUTON_TIME) match.SetTimeout(end_time, "autonomous_done") - log.Printf("AUTONOMOUS_END_TIME: %s %+v", end_time, match.timeout) + log.Logf("vex", "AUTONOMOUS_END_TIME: %s %+v", end_time, match.timeout) return "wait", nil } match.handlers["autonomous_done"] = func(signal GraphSignal) (string, error) { if match.state != "autonomous_running" { - log.Printf("BAD_STATE: %s: %s - %s", signal.Type(), match.state, match.Name()) + log.Logf("vex", "BAD_STATE: %s: %s - %s", signal.Type(), match.state, match.Name()) return "wait", nil } - log.Printf("AUTONOMOUS_DONE: %s", match.Name()) + log.Logf("vex", "AUTONOMOUS_DONE: %s", match.Name()) match.control = "none" match.state = "autonomous_done" @@ -199,7 +198,7 @@ func NewMatch(alliance0 * Alliance, alliance1 * Alliance, arena * Arena) * Match match.handlers["queue_driver"] = func(signal GraphSignal) (string, error) { if match.state != "autonomous_done"{ - log.Printf("BAD_STATE: %s: %s - %s", signal.Type(), match.state, match.Name()) + log.Logf("vex", "BAD_STATE: %s: %s - %s", signal.Type(), match.state, match.Name()) return "wait", nil } match.control = "none" @@ -213,7 +212,7 @@ func NewMatch(alliance0 * Alliance, alliance1 * Alliance, arena * Arena) * Match match.handlers["start_driver"] = func(signal GraphSignal) (string, error) { if match.state != "driver_queued" { - log.Printf("BAD_STATE: %s: %s - %s", signal.Type(), match.state, match.Name()) + log.Logf("vex", "BAD_STATE: %s: %s - %s", signal.Type(), match.state, match.Name()) return "wait", nil } match.control = "driver" @@ -230,7 +229,7 @@ func NewMatch(alliance0 * Alliance, alliance1 * Alliance, arena * Arena) * Match match.handlers["driver_done"] = func(signal GraphSignal) (string, error) { if match.state != "driver_running" { - log.Printf("BAD_STATE: %s: %s - %s", signal.Type(), match.state, match.Name()) + log.Logf("vex", "BAD_STATE: %s: %s - %s", signal.Type(), match.state, match.Name()) return "wait", nil } match.control = "none"