From 64b7e120beee216a938954544ea55eb76ec26172 Mon Sep 17 00:00:00 2001 From: brchri <126272303+brchri@users.noreply.github.com> Date: Mon, 16 Oct 2023 16:33:00 -0600 Subject: [PATCH] chore: add more verbose debug logging, bump go version (#25) Start using logrus package for better logging, add more verbose debug logs, bump golang to v1.21, and add some checks that valid garage doors and cars were found. --- Dockerfile | 2 +- cmd/app/main.go | 92 ++++++++++++++++++++++++++++------------- go.mod | 25 ++++++++++- go.sum | 73 ++++++++++++++++++++++++++------ internal/geo/geo.go | 63 ++++++++++++++-------------- internal/util/config.go | 77 +++++++++++++++++++++++++++++----- 6 files changed, 248 insertions(+), 84 deletions(-) diff --git a/Dockerfile b/Dockerfile index 19236c3..eb9442e 100644 --- a/Dockerfile +++ b/Dockerfile @@ -1,4 +1,4 @@ -FROM golang:1.20.5-alpine3.18 AS builder +FROM golang:1.21-alpine3.18 AS builder ARG BUILD_VERSION diff --git a/cmd/app/main.go b/cmd/app/main.go index 81d0c30..5196dbe 100644 --- a/cmd/app/main.go +++ b/cmd/app/main.go @@ -16,6 +16,7 @@ import ( geo "github.com/brchri/tesla-youq/internal/geo" "github.com/google/uuid" + logger "github.com/sirupsen/logrus" util "github.com/brchri/tesla-youq/internal/util" @@ -23,7 +24,6 @@ import ( ) var ( - debug bool configFile string cars []*util.Car // list of all cars from all garage doors version string = "v0.0.1" // pass -ldflags="-X main.version=" at build time to set linker flag and bake in binary version @@ -31,6 +31,10 @@ var ( ) func init() { + logger.SetFormatter(&util.CustomFormatter{}) + if val, ok := os.LookupEnv("DEBUG"); ok && strings.ToLower(val) == "true" { + logger.SetLevel(logger.DebugLevel) + } log.SetOutput(os.Stdout) parseArgs() util.LoadConfig(configFile) @@ -75,13 +79,13 @@ func parseArgs() { if configFile == "" { var exists bool if configFile, exists = os.LookupEnv("CONFIG_FILE"); !exists { - log.Fatalf("Config file must be defined with '-c' or 'CONFIG_FILE' environment variable") + logger.Fatalf("Config file must be defined with '-c' or 'CONFIG_FILE' environment variable") } } // check that ConfigFile exists if _, err := os.Stat(configFile); err != nil { - log.Fatalf("Config file %v doesn't exist!", configFile) + logger.Fatalf("Config file %v doesn't exist!", configFile) } } else { // if -d flag passed, get devices and exit @@ -92,51 +96,70 @@ func parseArgs() { } func main() { - if value, exists := os.LookupEnv("TESTING"); exists { - util.Config.Testing, _ = strconv.ParseBool(value) - } - if value, exists := os.LookupEnv("DEBUG"); exists { - debug, _ = strconv.ParseBool(value) - } - fmt.Println() - messageChan = make(chan mqtt.Message) + logger.Debug("Setting MQTT Opts:") // create a new MQTT client opts := mqtt.NewClientOptions() + logger.Debug(" OrderMatters: false") opts.SetOrderMatters(false) + logger.Debug(" KeepAlive: 30 seconds") opts.SetKeepAlive(30 * time.Second) + logger.Debug(" PingTimeout: 10 seconds") opts.SetPingTimeout(10 * time.Second) + logger.Debug(" AutoReconnect: true") opts.SetAutoReconnect(true) + if util.Config.Global.MqttUser != "" { + logger.Debug(" Username: true ") + } else { + logger.Debug(" Username: false (not set)") + } opts.SetUsername(util.Config.Global.MqttUser) // if not defined, will just set empty strings and won't be used by pkg + if util.Config.Global.MqttPass != "" { + logger.Debug(" Password: true ") + } else { + logger.Debug(" Password: false (not set)") + } opts.SetPassword(util.Config.Global.MqttPass) // if not defined, will just set empty strings and won't be used by pkg opts.OnConnect = onMqttConnect // set conditional MQTT client opts if util.Config.Global.MqttClientID != "" { + logger.Debugf(" ClientID: %s", util.Config.Global.MqttClientID) opts.SetClientID(util.Config.Global.MqttClientID) } else { // generate UUID for mqtt client connection if not specified in config file - opts.SetClientID(uuid.New().String()) + id := uuid.New().String() + logger.Debugf(" ClientID: %s", id) + opts.SetClientID(id) } + logger.Debug(" Protocol: TCP") mqttProtocol := "tcp" if util.Config.Global.MqttUseTls { + logger.Debug(" UseTLS: true") + logger.Debugf(" SkipTLSVerify: %t", util.Config.Global.MqttSkipTlsVerify) opts.SetTLSConfig(&tls.Config{ InsecureSkipVerify: util.Config.Global.MqttSkipTlsVerify, }) mqttProtocol = "ssl" + } else { + logger.Debug(" UseTLS: false") } - opts.AddBroker(fmt.Sprintf("%s://%s:%d", mqttProtocol, util.Config.Global.MqttHost, util.Config.Global.MqttPort)) + broker := fmt.Sprintf("%s://%s:%d", mqttProtocol, util.Config.Global.MqttHost, util.Config.Global.MqttPort) + logger.Debugf(" Broker: %s", broker) + opts.AddBroker(broker) // create a new MQTT client object client := mqtt.NewClient(opts) // connect to the MQTT broker + logger.Debug("Connecting to MQTT broker") if token := client.Connect(); token.Wait() && token.Error() != nil { - log.Fatalf("could not connect to mqtt broker: %v", token.Error()) + logger.Fatalf("could not connect to mqtt broker: %v", token.Error()) } else { - log.Println("Connected to MQTT broker") + logger.Info("Connected to MQTT broker") } + logger.Debugf("MQTT Broker Connected: %t", client.IsConnected()) // listen for incoming messages signalChannel := make(chan os.Signal, 1) @@ -161,21 +184,17 @@ func main() { case "geofence": car.PrevGeofence = car.CurGeofence car.CurGeofence = string(message.Payload()) - log.Printf("Received geo for car %d: %v", car.ID, car.CurGeofence) + logger.Infof("Received geo for car %d: %v", car.ID, car.CurGeofence) go geo.CheckGeofence(util.Config, car) case "latitude": - if debug { - log.Printf("Received lat for car %d: %v", car.ID, string(message.Payload())) - } + logger.Debugf("Received lat for car %d: %v", car.ID, string(message.Payload())) lat, _ := strconv.ParseFloat(string(message.Payload()), 64) go func(lat float64) { // send as goroutine so it doesn't block other vehicle updates if channel buffer is full car.LocationUpdate <- util.Point{Lat: lat, Lng: 0} }(lat) case "longitude": - if debug { - log.Printf("Received long for car %d: %v", car.ID, string(message.Payload())) - } + logger.Debugf("Received long for car %d: %v", car.ID, string(message.Payload())) lng, _ := strconv.ParseFloat(string(message.Payload()), 64) go func(lng float64) { // send as goroutine so it doesn't block other vehicle updates if channel buffer is full @@ -184,7 +203,7 @@ func main() { } case <-signalChannel: - log.Println("Received interrupt signal, shutting down...") + logger.Info("Received interrupt signal, shutting down...") client.Disconnect(250) time.Sleep(250 * time.Millisecond) return @@ -213,7 +232,7 @@ func processLocationUpdates(car *util.Car) { // subscribe to topics when MQTT client connects (or reconnects) func onMqttConnect(client mqtt.Client) { for _, car := range cars { - log.Printf("Subscribing to MQTT topics for car %d", car.ID) + logger.Infof("Subscribing to MQTT topics for car %d", car.ID) // define which topics are relevant for each car based on config var topics []string @@ -231,44 +250,59 @@ func onMqttConnect(client mqtt.Client) { topicSubscribed := false // retry topic subscription attempts with 1 sec delay between attempts for retryAttempts := 5; retryAttempts > 0; retryAttempts-- { + fullTopic := fmt.Sprintf("teslamate/cars/%d/%s", car.ID, topic) + logger.Debugf("Subscribing to topic: %s", fullTopic) if token := client.Subscribe( - fmt.Sprintf("teslamate/cars/%d/%s", car.ID, topic), + fullTopic, 0, func(client mqtt.Client, message mqtt.Message) { messageChan <- message }); token.Wait() && token.Error() == nil { topicSubscribed = true + logger.Debugf("Topic subscribed successfully: %s", fullTopic) break } else { - log.Printf("Failed to subscribe to topic %s for car %d, will make %d more attempts. Error: %v", topic, car.ID, retryAttempts, token.Error()) + logger.Infof("Failed to subscribe to topic %s for car %d, will make %d more attempts. Error: %v", topic, car.ID, retryAttempts, token.Error()) } time.Sleep(5 * time.Second) } if !topicSubscribed { - log.Fatalf("Unable to subscribe to topics, exiting") + logger.Fatalf("Unable to subscribe to topics, exiting") } } } - log.Println("Topics subscribed, listening for events...") + logger.Info("Topics subscribed, listening for events...") } // check for env vars and validate that a myq_email and myq_pass exists func checkEnvVars() { + logger.Debug("Checking environment variables:") // override config with env vars if present if value, exists := os.LookupEnv("MYQ_EMAIL"); exists { + logger.Debug(" MYQ_EMAIL defined, overriding config") util.Config.Global.MyQEmail = value } if value, exists := os.LookupEnv("MYQ_PASS"); exists { + logger.Debug(" MYQ_PASS defined, overriding config") util.Config.Global.MyQPass = value } if util.Config.Global.MyQEmail == "" || util.Config.Global.MyQPass == "" { - log.Fatal("MYQ_EMAIL and MYQ_PASS must be defined in the config file or as env vars") + logger.Fatal(" MYQ_EMAIL and MYQ_PASS must be defined in the config file or as env vars") } if value, exists := os.LookupEnv("MQTT_USER"); exists { + logger.Debug(" MQTT_USER defined, overriding config") util.Config.Global.MqttUser = value } if value, exists := os.LookupEnv("MQTT_PASS"); exists { + logger.Debug(" MQTT_PASS defined, overriding config") util.Config.Global.MqttPass = value } + if value, exists := os.LookupEnv("TESTING"); exists { + util.Config.Testing, _ = strconv.ParseBool(value) + logger.Debugf(" TESTING=%t", util.Config.Testing) + } + if value, exists := os.LookupEnv("DEBUG"); exists { + logger.Debugf(" DEBUG=%s", value) + } } diff --git a/go.mod b/go.mod index 36f7864..7d5114a 100644 --- a/go.mod +++ b/go.mod @@ -1,20 +1,43 @@ module github.com/brchri/tesla-youq -go 1.19 +go 1.21 require ( github.com/brchri/myq v0.0.0-20231011234622-15e50fb789db github.com/eclipse/paho.mqtt.golang v1.4.2 github.com/google/uuid v1.3.0 + github.com/sirupsen/logrus v1.9.3 github.com/stretchr/testify v1.8.4 gopkg.in/yaml.v3 v3.0.1 ) require ( + github.com/cilium/ebpf v0.12.0 // indirect + github.com/cosiner/argv v0.1.0 // indirect + github.com/cpuguy83/go-md2man/v2 v2.0.3 // indirect github.com/davecgh/go-spew v1.1.1 // indirect + github.com/derekparker/trie v0.0.0-20230829180723-39f4de51ef7d // indirect + github.com/go-delve/delve v1.21.1 // indirect + github.com/go-delve/liner v1.2.3-0.20220127212407-d32d89dd2a5d // indirect + github.com/google/go-dap v0.11.0 // indirect github.com/gorilla/websocket v1.4.2 // indirect + github.com/hashicorp/golang-lru v1.0.2 // indirect + github.com/inconshreveable/mousetrap v1.1.0 // indirect + github.com/mattn/go-colorable v0.1.13 // indirect + github.com/mattn/go-isatty v0.0.19 // indirect + github.com/mattn/go-runewidth v0.0.15 // indirect github.com/pmezard/go-difflib v1.0.0 // indirect + github.com/rivo/uniseg v0.4.4 // indirect + github.com/russross/blackfriday/v2 v2.1.0 // indirect + github.com/shurcooL/sanitized_anchor_name v1.0.0 // indirect + github.com/spf13/cobra v1.7.0 // indirect + github.com/spf13/pflag v1.0.5 // indirect github.com/stretchr/objx v0.5.0 // indirect + go.starlark.net v0.0.0-20231013162135-47c85baa7a64 // indirect + golang.org/x/arch v0.5.0 // indirect + golang.org/x/exp v0.0.0-20231006140011-7918f672742d // indirect golang.org/x/net v0.17.0 // indirect golang.org/x/sync v0.0.0-20210220032951-036812b2e83c // indirect + golang.org/x/sys v0.13.0 // indirect + gopkg.in/yaml.v2 v2.4.0 // indirect ) diff --git a/go.sum b/go.sum index 4940c29..eb7bac1 100644 --- a/go.sum +++ b/go.sum @@ -1,39 +1,77 @@ -github.com/brchri/myq v0.0.0-20231002041725-18aa0c937db3 h1:t5edNn/KiV1Kgz1Ll1kdpupABPUtOUDIebHLm5JmDV8= -github.com/brchri/myq v0.0.0-20231002041725-18aa0c937db3/go.mod h1:EDuAgiwrpS8cfzKCUrXpelEw1YOjxO/jhklEthAKmEs= -github.com/brchri/myq v0.0.0-20231011144103-b24617ee607a h1:BMPw9+y9A60fk3NAvknSJp/vJXWCsKf5xYAxp5IvxQ4= -github.com/brchri/myq v0.0.0-20231011144103-b24617ee607a/go.mod h1:EDuAgiwrpS8cfzKCUrXpelEw1YOjxO/jhklEthAKmEs= -github.com/brchri/myq v0.0.0-20231011144527-624a68a134f7 h1:3Uht+0sMKLk9x8+QWZUBfivHtuprFJ4fpe++c8OzZRI= -github.com/brchri/myq v0.0.0-20231011144527-624a68a134f7/go.mod h1:EDuAgiwrpS8cfzKCUrXpelEw1YOjxO/jhklEthAKmEs= -github.com/brchri/myq v0.0.0-20231011145427-af9fc472ba40 h1:umY7pdRNohhcfNWs3BGV9br4gYoPGxo/q/NvGr5pYg0= -github.com/brchri/myq v0.0.0-20231011145427-af9fc472ba40/go.mod h1:EDuAgiwrpS8cfzKCUrXpelEw1YOjxO/jhklEthAKmEs= -github.com/brchri/myq v0.0.0-20231011223614-977a9792b054 h1:NbR/KNuDzmSGXi78b5K5KY0Dre7t9dMoqHMcZbZ0hMM= -github.com/brchri/myq v0.0.0-20231011223614-977a9792b054/go.mod h1:EDuAgiwrpS8cfzKCUrXpelEw1YOjxO/jhklEthAKmEs= github.com/brchri/myq v0.0.0-20231011234622-15e50fb789db h1:7ann1FJumNDQsCpWh7laZqp6VNb9N0QDcCjcVZ5reFs= github.com/brchri/myq v0.0.0-20231011234622-15e50fb789db/go.mod h1:EDuAgiwrpS8cfzKCUrXpelEw1YOjxO/jhklEthAKmEs= +github.com/chzyer/logex v1.1.10/go.mod h1:+Ywpsq7O8HXn0nuIou7OrIPyXbp3wmkHB+jjWRnGsAI= +github.com/chzyer/readline v0.0.0-20180603132655-2972be24d48e/go.mod h1:nSuG5e5PlCu98SY8svDHJxuZscDgtXS6KTTbou5AhLI= +github.com/chzyer/test v0.0.0-20180213035817-a1ea475d72b1/go.mod h1:Q3SI9o4m/ZMnBNeIyt5eFwwo7qiLfzFZmjNmxjkiQlU= +github.com/cilium/ebpf v0.12.0 h1:oQEuIQIXgYhe1v7sYUG0P9vtJTYZLLdA6tiQmrOB1mo= +github.com/cilium/ebpf v0.12.0/go.mod h1:u9H29/Iq+8cy70YqI6p5pfADkFl3vdnV2qXDg5JL0Zo= +github.com/cosiner/argv v0.1.0 h1:BVDiEL32lwHukgJKP87btEPenzrrHUjajs/8yzaqcXg= +github.com/cosiner/argv v0.1.0/go.mod h1:EusR6TucWKX+zFgtdUsKT2Cvg45K5rtpCcWz4hK06d8= +github.com/cpuguy83/go-md2man/v2 v2.0.2/go.mod h1:tgQtvFlXSQOSOSIRvRPT7W67SCa46tRHOmNcaadrF8o= +github.com/cpuguy83/go-md2man/v2 v2.0.3 h1:qMCsGGgs+MAzDFyp9LpAe1Lqy/fY/qCovCm0qnXZOBM= +github.com/cpuguy83/go-md2man/v2 v2.0.3/go.mod h1:tgQtvFlXSQOSOSIRvRPT7W67SCa46tRHOmNcaadrF8o= github.com/davecgh/go-spew v1.1.0/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/derekparker/trie v0.0.0-20230829180723-39f4de51ef7d h1:hUWoLdw5kvo2xCsqlsIBMvWUc1QCSsCYD2J2+Fg6YoU= +github.com/derekparker/trie v0.0.0-20230829180723-39f4de51ef7d/go.mod h1:C7Es+DLenIpPc9J6IYw4jrK0h7S9bKj4DNl8+KxGEXU= github.com/eclipse/paho.mqtt.golang v1.4.2 h1:66wOzfUHSSI1zamx7jR6yMEI5EuHnT1G6rNA5PM12m4= github.com/eclipse/paho.mqtt.golang v1.4.2/go.mod h1:JGt0RsEwEX+Xa/agj90YJ9d9DH2b7upDZMK9HRbFvCA= +github.com/go-delve/delve v1.21.1 h1:oDpED8gvXPLS1VKSYzaMH/ihZtyk04H9jqQ9xpyFXl0= +github.com/go-delve/delve v1.21.1/go.mod h1:FgTAiRUe43RS5EexL06RPyMtP8AMZVL/t9Qqgy3qUe4= +github.com/go-delve/liner v1.2.3-0.20220127212407-d32d89dd2a5d h1:pxjSLshkZJGLVm0wv20f/H0oTWiq/egkoJQ2ja6LEvo= +github.com/go-delve/liner v1.2.3-0.20220127212407-d32d89dd2a5d/go.mod h1:biJCRbqp51wS+I92HMqn5H8/A0PAhxn2vyOT+JqhiGI= +github.com/google/go-dap v0.11.0 h1:SpAZJL41rOOvd85PuLCCLE1dteTQOyKNnn0H3DBHywo= +github.com/google/go-dap v0.11.0/go.mod h1:HAeyoSd2WIfTfg+0GRXcFrb+RnojAtGNh+k+XTIxJDE= 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/gorilla/websocket v1.4.2 h1:+/TMaTYc4QFitKJxsQ7Yye35DkWvkdLcvGKqM+x0Ufc= github.com/gorilla/websocket v1.4.2/go.mod h1:YR8l580nyteQvAITg2hZ9XVh4b55+EU/adAjf1fMHhE= +github.com/hashicorp/golang-lru v1.0.2 h1:dV3g9Z/unq5DpblPpw+Oqcv4dU/1omnb4Ok8iPY6p1c= +github.com/hashicorp/golang-lru v1.0.2/go.mod h1:iADmTwqILo4mZ8BN3D2Q6+9jd8WM5uGBxy+E8yxSoD4= +github.com/inconshreveable/mousetrap v1.1.0 h1:wN+x4NVGpMsO7ErUn/mUI3vEoE6Jt13X2s0bqwp9tc8= +github.com/inconshreveable/mousetrap v1.1.0/go.mod h1:vpF70FUmC8bwa3OWnCshd2FqLfsEA9PFc4w1p2J65bw= +github.com/mattn/go-colorable v0.1.13 h1:fFA4WZxdEF4tXPZVKMLwD8oUnCTTo08duU7wxecdEvA= +github.com/mattn/go-colorable v0.1.13/go.mod h1:7S9/ev0klgBDR4GtXTXX8a3vIGJpMovkB8vQcUbaXHg= +github.com/mattn/go-isatty v0.0.16/go.mod h1:kYGgaQfpe5nmfYZH+SKPsOc2e4SrIfOl2e/yFXSvRLM= +github.com/mattn/go-isatty v0.0.19 h1:JITubQf0MOLdlGRuRq+jtsDlekdYPia9ZFsB8h/APPA= +github.com/mattn/go-isatty v0.0.19/go.mod h1:W+V8PltTTMOvKvAeJH7IuucS94S2C6jfK/D7dTCTo3Y= +github.com/mattn/go-runewidth v0.0.3/go.mod h1:LwmH8dsx7+W8Uxz3IHJYH5QSwggIsqBzpuz5H//U1FU= +github.com/mattn/go-runewidth v0.0.15 h1:UNAjwbU9l54TA3KzvqLGxwWjHmMgBUVhBiTjelZgg3U= +github.com/mattn/go-runewidth v0.0.15/go.mod h1:Jdepj2loyihRzMpdS35Xk/zdY8IAYHsh153qUoGf23w= github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= +github.com/rivo/uniseg v0.2.0/go.mod h1:J6wj4VEh+S6ZtnVlnTBMWIodfgj8LQOQFoIToxlJtxc= +github.com/rivo/uniseg v0.4.4 h1:8TfxU8dW6PdqD27gjM8MVNuicgxIjxpm4K7x4jp8sis= +github.com/rivo/uniseg v0.4.4/go.mod h1:FN3SvrM+Zdj16jyLfmOkMNblXMcoc8DfTHruCPUcx88= +github.com/russross/blackfriday/v2 v2.1.0 h1:JIOH55/0cWyOuilr9/qlrm0BSXldqnqwMsf35Ld67mk= +github.com/russross/blackfriday/v2 v2.1.0/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM= +github.com/shurcooL/sanitized_anchor_name v1.0.0 h1:PdmoCO6wvbs+7yrJyMORt4/BmY5IYyJwS/kOiWx8mHo= +github.com/shurcooL/sanitized_anchor_name v1.0.0/go.mod h1:1NzhyTcUVG4SuEtjjoZeVRXNmyL/1OwPU0+IJeTBvfc= +github.com/sirupsen/logrus v1.9.3 h1:dueUQJ1C2q9oE3F7wvmSGAaVtTmUizReu6fjN8uqzbQ= +github.com/sirupsen/logrus v1.9.3/go.mod h1:naHLuLoDiP4jHNo9R0sCBMtWGeIprob74mVsIT4qYEQ= +github.com/spf13/cobra v1.7.0 h1:hyqWnYt1ZQShIddO5kBpj3vu05/++x6tJ6dg8EC572I= +github.com/spf13/cobra v1.7.0/go.mod h1:uLxZILRyS/50WlhOIKD7W6V5bgeIt+4sICxh6uRMrb0= +github.com/spf13/pflag v1.0.5 h1:iy+VFUOCP1a+8yFto/drg2CJ5u0yRoB7fZw3DKv/JXA= +github.com/spf13/pflag v1.0.5/go.mod h1:McXfInJRrz4CZXVZOBLb0bTZqETkiAhM9Iw0y3An2Bg= github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= github.com/stretchr/objx v0.4.0/go.mod h1:YvHI0jy2hoMjB+UWwv71VJQ9isScKT/TqJzVSSt89Yw= github.com/stretchr/objx v0.5.0 h1:1zr/of2m5FGMsad5YfcqgdqdWrIhu+EBEJRhR1U7z/c= github.com/stretchr/objx v0.5.0/go.mod h1:Yh+to48EsGEfYuaHDzXPcE3xhTkx73EhmCGUpEOglKo= +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/go.mod h1:yNjHg4UonilssWZ8iaSj1OCr/vHnekPRkoO+kdMU+MU= github.com/stretchr/testify v1.8.4 h1:CcVxjf3Q8PM0mHUKJCdn+eZZtm5yQwehR5yeSVQQcUk= github.com/stretchr/testify v1.8.4/go.mod h1:sz/lmYIOXD/1dqDmKjjqLyZ2RngseejIcXlSw2iwfAo= +go.starlark.net v0.0.0-20231013162135-47c85baa7a64 h1:oEn8uu0f/4jnlInr2y86GrMRux+y9i8XrO8w1jVyVNo= +go.starlark.net v0.0.0-20231013162135-47c85baa7a64/go.mod h1:LcLNIzVOMp4oV+uusnpk+VU+SzXaJakUuBjoCSWH5dM= +golang.org/x/arch v0.5.0 h1:jpGode6huXQxcskEIpOCvrU+tzo81b6+oFLUYXWtH/Y= +golang.org/x/arch v0.5.0/go.mod h1:5om86z9Hs0C8fWVUuoMHwpExlXzs5Tkyp9hOrfG7pp8= golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w= +golang.org/x/exp v0.0.0-20231006140011-7918f672742d h1:jtJma62tbqLibJ5sFQz8bKtEM8rJBtfilJ2qTU199MI= +golang.org/x/exp v0.0.0-20231006140011-7918f672742d/go.mod h1:ldy0pHrwJyGW56pPQzzkH36rKxoZW1tw7ZJpeKx+hdo= golang.org/x/net v0.0.0-20200425230154-ff2c4b7c35a0/go.mod h1:qpuaurCH72eLCgpAm/N6yyVIVM9cpaDIP3A8BGJEC5A= golang.org/x/net v0.0.0-20210917221730-978cfadd31cf/go.mod h1:9nx3DQGgdP8bBQD5qxJ1jj9UTztislL4KSBs9R2vV5Y= -golang.org/x/net v0.15.0 h1:ugBLEUaxABaB5AJqW9enI0ACdci2RUd4eP51NTBvuJ8= -golang.org/x/net v0.15.0/go.mod h1:idbUs1IY1+zTqbi8yxTbhexhEEk5ur9LInksu6HrEpk= golang.org/x/net v0.17.0 h1:pVaXccu2ozPjCXewfr1S7xza/zcXTity9cCdXQYSjIM= golang.org/x/net v0.17.0/go.mod h1:NxSsAGuq816PNPmqtQdLE42eU2Fs7NoRIZrHJAlaCOE= golang.org/x/sync v0.0.0-20210220032951-036812b2e83c h1:5KslGYwFpkhGh+Q16bwMP3cOontH8FOep7tGV86Y7SQ= @@ -42,12 +80,23 @@ golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5h golang.org/x/sys v0.0.0-20200323222414-85ca7c5b95cd/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20201119102817-f84b799fce68/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20210423082822-04245dca01da/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20211117180635-dee7805ff2e1/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.0.0-20220811171246-fbc7d0a398ab/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.6.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.13.0 h1:Af8nKPmuFypiUBjVoU9V20FiaFXOcuZI21p0ycVYYGE= +golang.org/x/sys v0.13.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo= golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ= golang.org/x/text v0.3.6/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ= golang.org/x/tools v0.0.0-20180917221912-90fa682c2a6e/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ= +golang.org/x/xerrors v0.0.0-20200804184101-5ec99f83aff1/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= +google.golang.org/protobuf v1.25.0/go.mod h1:9JNX74DMeImyA3h4bdi1ymwjUzf21/xIlbajtzgsN7c= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= +gopkg.in/yaml.v2 v2.4.0 h1:D8xgwECY7CYvx+Y2n4sBz93Jn9JRvxdiyyo8CTfuKaY= +gopkg.in/yaml.v2 v2.4.0/go.mod h1:RDklbk79AGWmwhnvt/jBztapEOGDOx6ZbXqjP6csGnQ= gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA= gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= +rsc.io/pdf v0.1.1/go.mod h1:n8OzWcQ6Sp37PL01nO98y4iUCRdTGarVfzxY20ICaU4= diff --git a/internal/geo/geo.go b/internal/geo/geo.go index 491520c..9ac0d73 100644 --- a/internal/geo/geo.go +++ b/internal/geo/geo.go @@ -3,12 +3,13 @@ package geo import ( "fmt" "io" - "log" "math" "os" + "strings" "time" util "github.com/brchri/tesla-youq/internal/util" + logger "github.com/sirupsen/logrus" "github.com/brchri/myq" ) @@ -48,13 +49,13 @@ func (m *MyqSessionWrapper) Login() error { if err == nil && util.Config.Global.CacheTokenFile != "" { file, fileErr := os.OpenFile(util.Config.Global.CacheTokenFile, os.O_WRONLY|os.O_CREATE|os.O_TRUNC, 0644) if fileErr != nil { - log.Printf("WARNING: Unable to write to cache file %s", util.Config.Global.CacheTokenFile) + logger.Infof("WARNING: Unable to write to cache file %s", util.Config.Global.CacheTokenFile) } else { defer file.Close() _, writeErr := file.WriteString(m.GetToken()) if writeErr != nil { - log.Printf("WARNING: Unable to write to cache file %s", util.Config.Global.CacheTokenFile) + logger.Infof("WARNING: Unable to write to cache file %s", util.Config.Global.CacheTokenFile) } } } @@ -82,6 +83,10 @@ var myqExec MyqSessionInterface // executes myq package commands func init() { myqExec = &MyqSessionWrapper{} myqExec.New() + logger.SetFormatter(&util.CustomFormatter{}) + if val, ok := os.LookupEnv("DEBUG"); ok && strings.ToLower(val) == "true" { + logger.SetLevel(logger.DebugLevel) + } } func distance(point1 util.Point, point2 util.Point) float64 { @@ -124,10 +129,10 @@ func CheckGeofence(config util.ConfigStruct, car *util.Car) { // run as goroutine to prevent blocking update channels from mqtt broker in main go func() { if car.GarageDoor.GeofenceType == util.TeslamateGeofenceType { - log.Printf("Attempting to %s garage door for car %d", action, car.ID) + logger.Infof("Attempting to %s garage door for car %d", action, car.ID) } else { // if closing door based on lat and lng, print those values - log.Printf("Attempting to %s garage door for car %d at lat %f, long %f", action, car.ID, car.CurrentLocation.Lat, car.CurrentLocation.Lng) + logger.Infof("Attempting to %s garage door for car %d at lat %f, long %f", action, car.ID, car.CurrentLocation.Lat, car.CurrentLocation.Lng) } // create retry loop to set the garage door state @@ -137,9 +142,9 @@ func CheckGeofence(config util.ConfigStruct, car *util.Car) { break } if i == 1 { - log.Println("Unable to set garage door state, no further attempts will be made") + logger.Info("Unable to set garage door state, no further attempts will be made") } else { - log.Printf("Retrying set garage door state %d more time(s)", i-1) + logger.Infof("Retrying set garage door state %d more time(s)", i-1) } } @@ -226,7 +231,7 @@ func setGarageDoor(config util.ConfigStruct, deviceSerial string, action string) } if config.Testing { - log.Printf("TESTING flag set - Would attempt action %v", action) + logger.Infof("TESTING flag set - Would attempt action %v", action) return nil } @@ -234,13 +239,13 @@ func setGarageDoor(config util.ConfigStruct, deviceSerial string, action string) if util.Config.Global.CacheTokenFile != "" && myqExec.GetToken() == "" { file, err := os.Open(util.Config.Global.CacheTokenFile) if err != nil { - log.Printf("WARNING: Unable to read token cache from %s", util.Config.Global.CacheTokenFile) + logger.Infof("WARNING: Unable to read token cache from %s", util.Config.Global.CacheTokenFile) } else { defer file.Close() data, err := io.ReadAll(file) if err != nil { - log.Printf("WARNING: Unable to read token cache from %s", util.Config.Global.CacheTokenFile) + logger.Infof("WARNING: Unable to read token cache from %s", util.Config.Global.CacheTokenFile) } else { myqExec.SetToken(string(data)) } @@ -250,36 +255,36 @@ func setGarageDoor(config util.ConfigStruct, deviceSerial string, action string) curState, err := myqExec.DeviceState(deviceSerial) if err != nil { // fetching device state may have failed due to invalid session token; try fresh login to resolve - log.Println("Acquiring MyQ session...") + logger.Info("Acquiring MyQ session...") myqExec.New() myqExec.SetUsername(config.Global.MyQEmail) myqExec.SetPassword(config.Global.MyQPass) if err := myqExec.Login(); err != nil { - log.Printf("ERROR: %v\n", err) + logger.Infof("ERROR: %v\n", err) return err } - log.Println("Session acquired...") + logger.Info("Session acquired...") curState, err = myqExec.DeviceState(deviceSerial) if err != nil { - log.Printf("Couldn't get device state: %v", err) + logger.Infof("Couldn't get device state: %v", err) return err } } - log.Printf("Requested action: %v, Current state: %v", action, curState) + logger.Infof("Requested action: %v, Current state: %v", action, curState) if (action == myq.ActionOpen && curState == myq.StateClosed) || (action == myq.ActionClose && curState == myq.StateOpen) { - log.Printf("Attempting action: %v", action) + logger.Infof("Attempting action: %v", action) err := myqExec.SetDoorState(deviceSerial, action) if err != nil { - log.Printf("Unable to set door state: %v", err) + logger.Infof("Unable to set door state: %v", err) return err } } else { - log.Printf("Action and state mismatch: garage state is not valid for executing requested action") + logger.Infof("Action and state mismatch: garage state is not valid for executing requested action") return nil } - log.Printf("Waiting for door to %s...\n", action) + logger.Infof("Waiting for door to %s...\n", action) var currentState string deadline := time.Now().Add(60 * time.Second) @@ -290,7 +295,7 @@ func setGarageDoor(config util.ConfigStruct, deviceSerial string, action string) } if state != currentState { if currentState != "" { - log.Printf("Door state changed to %s\n", state) + logger.Infof("Door state changed to %s\n", state) } currentState = state } @@ -312,25 +317,23 @@ func GetGarageDoorSerials(config util.ConfigStruct) error { s.Username = config.Global.MyQEmail s.Password = config.Global.MyQPass - log.Println("Acquiring MyQ session...") + logger.Info("Acquiring MyQ session...") if err := s.Login(); err != nil { - log.SetOutput(os.Stderr) - log.Printf("ERROR: %v\n", err) - log.SetOutput(os.Stdout) + logger.Errorf("ERROR: %v\n", err) return err } - log.Println("Session acquired...") + logger.Info("Session acquired...") devices, err := s.Devices() if err != nil { - log.Printf("Could not get devices: %v", err) + logger.Infof("Could not get devices: %v", err) return err } for _, d := range devices { - log.Printf("Device Name: %v", d.Name) - log.Printf("Device State: %v", d.DoorState) - log.Printf("Device Type: %v", d.Type) - log.Printf("Device Serial: %v", d.SerialNumber) + logger.Infof("Device Name: %v", d.Name) + logger.Infof("Device State: %v", d.DoorState) + logger.Infof("Device Type: %v", d.Type) + logger.Infof("Device Serial: %v", d.SerialNumber) fmt.Println() } diff --git a/internal/util/config.go b/internal/util/config.go index c9aee96..e3960a5 100644 --- a/internal/util/config.go +++ b/internal/util/config.go @@ -2,11 +2,12 @@ package util import ( "encoding/xml" - "log" + "fmt" "os" "strconv" "strings" + logger "github.com/sirupsen/logrus" "gopkg.in/yaml.v3" ) @@ -100,6 +101,10 @@ type ( GarageDoors []*GarageDoor `yaml:"garage_doors"` Testing bool } + + CustomFormatter struct { + logger.TextFormatter + } ) var Config ConfigStruct @@ -110,6 +115,36 @@ const ( TeslamateGeofenceType = "TeslamateGeofence" // geofence defined in teslamate ) +func init() { + logger.SetFormatter(&CustomFormatter{}) + if val, ok := os.LookupEnv("DEBUG"); ok && strings.ToLower(val) == "true" { + logger.SetLevel(logger.DebugLevel) + } +} + +// format log level to always have 5 characters between brackets (e.g. `[INFO ]`) +func formatLevel(level logger.Level) string { + str := fmt.Sprintf("%-5s", level) + if len(str) > 5 { + return str[:5] + } + return strings.ToUpper(str) +} + +// custom formatter for logrus package +// 01/02/2006 15:04:05 [LEVEL] Message... +func (f *CustomFormatter) Format(entry *logger.Entry) ([]byte, error) { + // Use the timestamp from the log entry to format it as you like + timestamp := entry.Time.Format("01/02/2006 15:04:05") + + // Ensure the log level string is always 5 characters + paddedLevel := formatLevel(entry.Level) + + // Combine the timestamp with the log level and the message + logMessage := fmt.Sprintf("%s [%s] %s\n", timestamp, paddedLevel, entry.Message) + return []byte(logMessage), nil +} + // checks for valid geofence values for a garage door // preferred priority is polygon > circular > teslamate func (g GarageDoor) GetGeofenceType() string { @@ -134,24 +169,44 @@ func (p Point) IsPointDefined() bool { // load yaml config func LoadConfig(configFile string) { + logger.Debugf("Attempting to read config file: %v", configFile) yamlFile, err := os.ReadFile(configFile) if err != nil { - log.Fatalf("Could not read config file: %v", err) + logger.Fatalf("Could not read config file: %v", err) + } else { + logger.Debug("Config file read successfully") } + logger.Debug("Unmarshaling yaml into config object") err = yaml.Unmarshal(yamlFile, &Config) if err != nil { - log.Fatalf("Could not load yaml from config file, received error: %v", err) + logger.Fatalf("Could not load yaml from config file, received error: %v", err) + } else { + logger.Debug("Config yaml unmarshalled successfully") } - for _, g := range Config.GarageDoors { + logger.Debug("Checking garage door configs") + if len(Config.GarageDoors) == 0 { + logger.Fatal("Unable to find garage doors in config! Please ensure proper spacing in the config file") + } + for i, g := range Config.GarageDoors { + if len(g.Cars) == 0 { + logger.Fatalf("No cars found for garage door #%d! Please ensure proper spacing in the config file", i) + } // check if kml_file was defined, and if so, load and parse kml and set polygon geofences accordingly if g.PolygonGeofence != nil && g.PolygonGeofence.KMLFile != "" { - loadKMLFile(g.PolygonGeofence) + logger.Debugf("KML file %s found, loading", g.PolygonGeofence.KMLFile) + if err := loadKMLFile(g.PolygonGeofence); err != nil { + logger.Warnf("Unable to load KML file: %v", err) + } else { + logger.Debug("KML file loaded successfully") + } } g.GeofenceType = g.GetGeofenceType() if g.GeofenceType == "" { - log.Fatalf("error: no supported geofences defined for garage door %v", g) + logger.Fatalf("error: no supported geofences defined for garage door %v", g) + } else { + logger.Debugf("Garage door geofence type identified: %s", g.GeofenceType) } // initialize location update channel @@ -160,7 +215,7 @@ func LoadConfig(configFile string) { } } - log.Println("Config loaded successfully") + logger.Info("Config loaded successfully") } // loads kml file and overrides polygon geofence points with parsed data @@ -168,14 +223,14 @@ func loadKMLFile(p *PolygonGeofence) error { fileContent, err := os.ReadFile(p.KMLFile) lowerKML := strings.ToLower(string(fileContent)) // convert xml to lower to make xml tag parsing case insensitive if err != nil { - log.Printf("Could not read file %s, received error: %e", p.KMLFile, err) + logger.Infof("Could not read file %s, received error: %e", p.KMLFile, err) return err } var kml KML err = xml.Unmarshal([]byte(lowerKML), &kml) if err != nil { - log.Printf("Could not load kml from file %s, received error: %e", p.KMLFile, err) + logger.Infof("Could not load kml from file %s, received error: %e", p.KMLFile, err) return err } @@ -198,12 +253,12 @@ func loadKMLFile(p *PolygonGeofence) error { coords := strings.Split(c, ",") lat, err := strconv.ParseFloat(coords[1], 64) if err != nil { - log.Printf("Could not parse lng/lat coordinates from line %s, received error: %e", c, err) + logger.Infof("Could not parse lng/lat coordinates from line %s, received error: %e", c, err) return err } lng, err := strconv.ParseFloat(coords[0], 64) if err != nil { - log.Printf("Could not parse lng/lat coordinates from line %s, received error: %e", c, err) + logger.Infof("Could not parse lng/lat coordinates from line %s, received error: %e", c, err) return err }