Moved logging to a global object that's initialized on first log call

graph-rework
noah metz 2023-06-04 13:18:10 -06:00
parent 0f92de1619
commit 00abdc8b1c
8 changed files with 149 additions and 87 deletions

@ -3,7 +3,6 @@ package main
import ( import (
"fmt" "fmt"
"time" "time"
"log"
"errors" "errors"
"reflect" "reflect"
"sort" "sort"
@ -162,7 +161,7 @@ func AddChild(event Event, child Event, info EventInfo) error {
} }
func RunEvent(event Event) 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")) go SendUpdate(event, NewSignal(event, "event_start"))
next_action := "start" next_action := "start"
var err error = nil var err error = nil
@ -173,14 +172,14 @@ func RunEvent(event Event) error {
return errors.New(error_str) 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() next_action, err = action()
if err != nil { if err != nil {
return err return err
} }
} }
log.Printf("EVENT_RUN_DONE: %s", event.Name()) log.Logf("event", "EVENT_RUN_DONE: %s", event.Name())
return nil return nil
} }
@ -224,7 +223,7 @@ func LockResources(event Event) error {
func FinishEvent(event Event) error { func FinishEvent(event Event) error {
// TODO make more 'safe' like LockResources, or make UnlockResource not return errors // 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()) { for _, resource := range(event.RequiredResources()) {
err := UnlockResource(resource, event) err := UnlockResource(resource, event)
if err != nil { if err != nil {
@ -278,26 +277,26 @@ func (event * BaseEvent) Action(action string) (func() (string, error), bool) {
func EventWait(event Event) (func() (string, error)) { func EventWait(event Event) (func() (string, error)) {
return 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 { select {
case signal := <- event.Signal(): case signal := <- event.Signal():
if signal.Source() != nil { 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 { } 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" { if signal.Type() == "abort" {
return "", errors.New("State machine aborted by signal") return "", errors.New("State machine aborted by signal")
} else { } else {
signal_fn, exists := event.Handler(signal.Type()) signal_fn, exists := event.Handler(signal.Type())
if exists == true { 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 signal_fn(signal)
} }
} }
return "wait", nil return "wait", nil
case <- event.Timeout(): 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 return event.TimeoutAction(), nil
} }
} }
@ -403,15 +402,15 @@ func NewEventQueue(name string, description string, required_resources []Resourc
err := LockResources(event) err := LockResources(event)
// start in new goroutine // start in new goroutine
if err != nil { 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 { } else {
info.state = "running" 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) { 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) err := RunEvent(event)
if err != nil { if err != nil {
log.Printf("EVENT_ERROR: %s", err) log.Logf("event", "EVENT_ERROR: %s", err)
} }
info.state = "done" info.state = "done"
FinishEvent(event) FinishEvent(event)
@ -426,7 +425,7 @@ func NewEventQueue(name string, description string, required_resources []Resourc
for _, resource := range(needed_resources) { for _, resource := range(needed_resources) {
_, exists := queue.listened_resources[resource.ID()] _, exists := queue.listened_resources[resource.ID()]
if exists == false { 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 queue.listened_resources[resource.ID()] = resource
resource.RegisterChannel(queue.signal) resource.RegisterChannel(queue.signal)
} }

@ -4,4 +4,8 @@ go 1.20
require ( require (
github.com/google/uuid v1.3.0 // indirect 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
) )

@ -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/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.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/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/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/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 h1:t6JiXgmwXMjEs8VusXIJk2BXHsn+wx8BZdTaoZ5fu7I=
github.com/google/uuid v1.3.0/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo= 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/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 h1:OEW0ORrIx095N/6lgoGkFkotqH6s7vaFPsgjLAaF5QU=
github.com/looplab/fsm v1.0.1/go.mod h1:PmD3fFvQEIsjMEfvZdrCDZ6y8VwKTwWNjlpEr6IKPO4= 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/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/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/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.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI=
github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= 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 v1.6.3/go.mod h1:7BgNga5fNlF/iZjG06hM3yofffp0ofKCDwSXx1GC4dI=
go.opentelemetry.io/otel/trace v1.6.3/go.mod h1:GNJQusJlUgZl9/TQBPKU/Y/ty+0iVB5fjhKeJGZPGFs= 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= 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/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= gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=

@ -1,12 +1,67 @@
package main package main
import ( import (
"log"
"sync" "sync"
"github.com/google/uuid" "github.com/google/uuid"
"time" "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 // Generate a random graphql id
func randid() string{ func randid() string{
uuid_str := uuid.New().String() uuid_str := uuid.New().String()
@ -84,7 +139,7 @@ func NewBaseNode(name string, description string, id string) BaseNode {
signal: make(chan GraphSignal, 1000), signal: make(chan GraphSignal, 1000),
listeners: map[chan GraphSignal]chan GraphSignal{}, 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 return node
} }
@ -146,11 +201,11 @@ func (node * BaseNode) UpdateListeners(update GraphSignal) {
closed := []chan GraphSignal{} closed := []chan GraphSignal{}
for _, listener := range node.listeners { 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 { select {
case listener <- update: case listener <- update:
default: 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) { go func(node GraphNode, listener chan GraphSignal) {
listener <- NewSignal(node, "listener_closed") listener <- NewSignal(node, "listener_closed")
close(listener) close(listener)
@ -171,9 +226,9 @@ func (node * BaseNode) update(signal GraphSignal) {
func SendUpdate(node GraphNode, signal GraphSignal) { func SendUpdate(node GraphNode, signal GraphSignal) {
if signal.Source() != nil { 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 { } else {
log.Printf("UPDATE %s: %+v", node.Name(), signal) log.Logf("update", "UPDATE %s: %+v", node.Name(), signal)
} }
node.UpdateListeners(signal) node.UpdateListeners(signal)

@ -1,7 +1,6 @@
package main package main
import ( import (
"log"
"runtime/pprof" "runtime/pprof"
"time" "time"
"os" "os"
@ -95,14 +94,8 @@ func fake_data() (* EventManager, *Arena, *Arena) {
root_event := NewEventQueue("root_event", "", []Resource{}) 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 := 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 i, alliance := range(alliances) {
for j, alliance2 := range(alliances) { for j, alliance2 := range(alliances) {
if j != i { if j != i {
@ -110,17 +103,16 @@ func fake_data() (* EventManager, *Arena, *Arena) {
} else { } else {
for arena_idx := 0; arena_idx < len(arenas); arena_idx++ { for arena_idx := 0; arena_idx < len(arenas); arena_idx++ {
match := NewMatch(alliance, alliance2, arenas[arena_idx]) match := NewMatch(alliance, alliance2, arenas[arena_idx])
log.Printf("Adding %s", match.Name()) log.Logf("test", "Adding %s", match.Name())
err := event_manager.AddEvent(root_event, match, NewEventQueueInfo(i)) err := event_manager.AddEvent(root_event, match, NewEventQueueInfo(i))
if err != nil { if err != nil {
log.Printf("Error adding %s: %s", match.Name(), err) log.Logf("test", "Error adding %s: %s", match.Name(), err)
} }
} }
} }
} }
} }
} }
}(alliances, arenas, event_manager)
return event_manager, arenas[0], arenas[1] return event_manager, arenas[0], arenas[1]
} }
@ -146,49 +138,49 @@ func NewFakeClient(arena *Arena) * FakeClient {
func (client * FakeClient) process_update(update GraphSignal) { func (client * FakeClient) process_update(update GraphSignal) {
arena := client.arena arena := client.arena
if update.Source() != nil { 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 { } else {
log.Printf("FAKE_CLIENT_UPDATE: nil -> %+v", update) log.Logf("test", "FAKE_CLIENT_UPDATE: nil -> %+v", update)
} }
if update.Type() == "event_start" { if update.Type() == "event_start" {
if client.state != "init" { 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" 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")) SendUpdate(arena, NewSignal(nil, "queue_autonomous"))
} else if update.Type() == "autonomous_queued" { } else if update.Type() == "autonomous_queued" {
if client.state != "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" 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 := NewSignal(nil, "start_autonomous")
signal.time = update.Time() signal.time = update.Time()
SendUpdate(arena, signal) SendUpdate(arena, signal)
} else if update.Type() == "autonomous_done" { } else if update.Type() == "autonomous_done" {
if client.state != "autonomous_started" { 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" 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") signal := NewSignal(nil, "queue_driver")
SendUpdate(arena, signal) SendUpdate(arena, signal)
} else if update.Type() == "driver_queued" { } else if update.Type() == "driver_queued" {
if client.state != "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" 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 := NewSignal(nil, "start_driver")
signal.time = update.Time() signal.time = update.Time()
SendUpdate(arena, signal) SendUpdate(arena, signal)
} else if update.Type() == "driver_done" { } else if update.Type() == "driver_done" {
if client.state != "driver_started" { 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" 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() err := event_manager.Run()
if err != nil { if err != nil {
log.Printf("Error running event_manager: %s", err) log.Logf("test", "Error running event_manager: %s", err)
} else { } else {
log.Printf("Finished event_manager") log.Logf("test", "Finished event_manager")
} }
} }

@ -2,7 +2,6 @@ package main
import ( import (
"fmt" "fmt"
"log"
"errors" "errors"
) )
@ -25,14 +24,14 @@ func NewEventManager(root_event Event, dag_nodes []Resource) * EventManager {
for _, resource := range dag_nodes { for _, resource := range dag_nodes {
err := manager.AddResource(resource) err := manager.AddResource(resource)
if err != nil { 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 return nil
} }
} }
err := manager.AddEvent(nil, root_event, nil) err := manager.AddEvent(nil, root_event, nil)
if err != 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; 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 // Connect to all resources(in a thread to handle reconnections), and start the first event
func (manager * EventManager) Run() error { func (manager * EventManager) Run() error {
log.Printf("MANAGER_START") log.Logf("manager", "MANAGER_START")
abort := make(chan error, 1) abort := make(chan error, 1)
go func(abort chan error, manager * EventManager) { go func(abort chan error, manager * EventManager) {
@ -52,7 +51,7 @@ func (manager * EventManager) Run() error {
err := LockResources(manager.root_event) err := LockResources(manager.root_event)
if err != nil { if err != nil {
log.Printf("MANAGER_LOCK_ERR: %s", err) log.Logf("manager", "MANAGER_LOCK_ERR: %s", err)
abort <- nil abort <- nil
return err return err
} }
@ -60,16 +59,16 @@ func (manager * EventManager) Run() error {
err = RunEvent(manager.root_event) err = RunEvent(manager.root_event)
abort <- nil abort <- nil
if err != nil { if err != nil {
log.Printf("MANAGER_RUN_ERR: %s", err) log.Logf("manager", "MANAGER_RUN_ERR: %s", err)
return err return err
} }
err = FinishEvent(manager.root_event) err = FinishEvent(manager.root_event)
if err != nil { if err != nil {
log.Printf("MANAGER_FINISH_ERR: %s", err) log.Logf("manager", "MANAGER_FINISH_ERR: %s", err)
return err return err
} }
log.Printf("MANAGER_DONE") log.Logf("manager", "MANAGER_DONE")
return nil return nil
} }
@ -90,7 +89,7 @@ func (manager * EventManager) FindEvent(id string) Event {
} }
func (manager * EventManager) AddResource(resource Resource) error { 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()] _, exists := manager.dag_nodes[resource.ID()]
if exists == true { if exists == true {
error_str := fmt.Sprintf("%s is already in the resource DAG, cannot add again", resource.Name()) error_str := fmt.Sprintf("%s is already in the resource DAG, cannot add again", resource.Name())

@ -20,6 +20,7 @@ func (resource * BaseResource) update(signal GraphSignal) {
SendUpdate(resource.lock_holder, new_signal) SendUpdate(resource.lock_holder, new_signal)
} }
} }
} }
// Resource is the interface that DAG nodes are made from // Resource is the interface that DAG nodes are made from

@ -2,7 +2,6 @@ package main
import ( import (
"fmt" "fmt"
"log"
"time" "time"
"errors" "errors"
) )
@ -80,7 +79,7 @@ func NewVirtualArena(name string) * Arena {
func (arena * Arena) lock(event Event) error { func (arena * Arena) lock(event Event) error {
if arena.connected == false { 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()) error_str := fmt.Sprintf("%s is not connected, cannot lock", arena.Name())
return errors.New(error_str) return errors.New(error_str)
} }
@ -88,36 +87,36 @@ func (arena * Arena) lock(event Event) error {
} }
func (arena * Arena) update(signal GraphSignal) { 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.signal <- signal
arena.BaseResource.update(signal) arena.BaseResource.update(signal)
} }
func (arena * Arena) Connect(abort chan error) bool { 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) { go func(arena * Arena, abort chan error) {
update_str := fmt.Sprintf("VIRTUAL_ARENA connected: %s", arena.Name()) update_str := fmt.Sprintf("VIRTUAL_ARENA connected: %s", arena.Name())
signal := NewSignal(arena, "resource_connected") signal := NewSignal(arena, "resource_connected")
signal.description = update_str signal.description = update_str
arena.connected = true arena.connected = true
go SendUpdate(arena, signal) 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 { for true {
select { select {
case <- abort: case <- abort:
log.Printf("Virtual arena %s aborting", arena.Name()) log.Logf("vex", "Virtual arena %s aborting", arena.Name())
break break
case update := <- arena.signal: 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) }(arena, abort)
return true return true
} }
const start_slack = 3000 * time.Millisecond const start_slack = 250 * time.Millisecond
const TEMP_AUTON_TIME = time.Second * 3 const TEMP_AUTON_TIME = time.Second * 1
const TEMP_DRIVE_TIME = time.Second * 5 const TEMP_DRIVE_TIME = time.Second * 1
type Match struct { type Match struct {
BaseEvent BaseEvent
@ -147,7 +146,7 @@ func NewMatch(alliance0 * Alliance, alliance1 * Alliance, arena * Arena) * Match
match.actions["wait"] = EventWait(match) match.actions["wait"] = EventWait(match)
match.actions["start"] = func() (string, error) { 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.control = "none"
match.state = "scheduled" match.state = "scheduled"
return "wait", nil 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) { match.handlers["queue_autonomous"] = func(signal GraphSignal) (string, error) {
if match.state != "scheduled" { 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 return "wait", nil
} }
log.Printf("AUTONOMOUS_QUEUED: %s", match.Name()) log.Logf("vex", "AUTONOMOUS_QUEUED: %s", match.Name())
match.control = "none" match.control = "none"
match.state = "autonomous_queued" match.state = "autonomous_queued"
match.control_start = time.Now().Add(start_slack) 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) { match.handlers["start_autonomous"] = func(signal GraphSignal) (string, error) {
if match.state != "autonomous_queued" { 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 return "wait", nil
} }
log.Printf("AUTONOMOUS_RUNNING: %s", match.Name()) log.Logf("vex", "AUTONOMOUS_RUNNING: %s", match.Name())
match.control = "program" match.control = "program"
match.state = "autonomous_running" match.state = "autonomous_running"
match.control_start = signal.Time() 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) end_time := match.control_start.Add(TEMP_AUTON_TIME)
match.SetTimeout(end_time, "autonomous_done") 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 return "wait", nil
} }
match.handlers["autonomous_done"] = func(signal GraphSignal) (string, error) { match.handlers["autonomous_done"] = func(signal GraphSignal) (string, error) {
if match.state != "autonomous_running" { 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 return "wait", nil
} }
log.Printf("AUTONOMOUS_DONE: %s", match.Name()) log.Logf("vex", "AUTONOMOUS_DONE: %s", match.Name())
match.control = "none" match.control = "none"
match.state = "autonomous_done" 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) { match.handlers["queue_driver"] = func(signal GraphSignal) (string, error) {
if match.state != "autonomous_done"{ 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 return "wait", nil
} }
match.control = "none" 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) { match.handlers["start_driver"] = func(signal GraphSignal) (string, error) {
if match.state != "driver_queued" { 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 return "wait", nil
} }
match.control = "driver" 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) { match.handlers["driver_done"] = func(signal GraphSignal) (string, error) {
if match.state != "driver_running" { 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 return "wait", nil
} }
match.control = "none" match.control = "none"