From 99d753741e5b6dc86b032882541c9b8f45a51bd4 Mon Sep 17 00:00:00 2001 From: Simon Ruderich Date: Tue, 18 May 2021 18:51:47 +0200 Subject: [PATCH] safcm: move logEvent() to frontend package --- cmd/safcm/sync.go | 62 +------ cmd/safcm/sync_test.go | 358 ------------------------------------- frontend/log.go | 67 +++++++ frontend/log_test.go | 390 +++++++++++++++++++++++++++++++++++++++++ 4 files changed, 458 insertions(+), 419 deletions(-) create mode 100644 frontend/log_test.go diff --git a/cmd/safcm/sync.go b/cmd/safcm/sync.go index 2f297c8..65745af 100644 --- a/cmd/safcm/sync.go +++ b/cmd/safcm/sync.go @@ -105,7 +105,7 @@ func MainSync(args []string) error { loop := &frontend.Loop{ DebugConn: cfg.LogLevel >= safcm.LogDebug3, LogEventFunc: func(x frontend.Event, failed *bool) { - logEvent(x, cfg.LogLevel, isTTY, failed) + frontend.LogEvent(x, cfg.LogLevel, isTTY, failed) }, SyncHostFunc: func(conn *rpc.Conn, host frontend.Host) error { return host.(*Sync).Host(conn) @@ -213,66 +213,6 @@ are only available after the hosts were contacted. return res, nil } -func logEvent(x frontend.Event, level safcm.LogLevel, isTTY bool, failed *bool) { - // We have multiple event sources so this is somewhat ugly. - var prefix, data string - var color frontend.Color - if x.Error != nil { - prefix = "[error]" - data = x.Error.Error() - color = frontend.ColorRed - // We logged an error, tell the caller - *failed = true - } else if x.Log.Level != 0 { - if level < x.Log.Level { - return - } - // LogError and LogDebug3 should not occur here - switch x.Log.Level { - case safcm.LogInfo: - prefix = "[info]" - case safcm.LogVerbose: - prefix = "[verbose]" - case safcm.LogDebug: - prefix = "[debug]" - case safcm.LogDebug2: - prefix = "[debug2]" - default: - prefix = fmt.Sprintf("[INVALID=%d]", x.Log.Level) - color = frontend.ColorRed - } - data = x.Log.Text - } else { - switch x.ConnEvent.Type { - case rpc.ConnEventStderr: - prefix = "[stderr]" - case rpc.ConnEventDebug: - prefix = "[debug3]" - case rpc.ConnEventUpload: - if level < safcm.LogInfo { - return - } - prefix = "[info]" - x.ConnEvent.Data = "remote helper upload in progress" - default: - prefix = fmt.Sprintf("[INVALID=%d]", x.ConnEvent.Type) - color = frontend.ColorRed - } - data = x.ConnEvent.Data - } - - host := x.Host.Name() - if color != 0 { - host = frontend.ColorString(isTTY, color, host) - } - // Make sure to escape control characters to prevent terminal - // injection attacks - if !x.Escaped { - data = frontend.EscapeControlCharacters(isTTY, data) - } - log.Printf("%-9s [%s] %s", prefix, host, data) -} - func (s *Sync) Name() string { return s.host.Name } diff --git a/cmd/safcm/sync_test.go b/cmd/safcm/sync_test.go index 4744ad5..8cde5ab 100644 --- a/cmd/safcm/sync_test.go +++ b/cmd/safcm/sync_test.go @@ -16,16 +16,11 @@ package main import ( - "bytes" "fmt" - "log" "os" "testing" - "ruderich.org/simon/safcm" "ruderich.org/simon/safcm/cmd/safcm/config" - "ruderich.org/simon/safcm/frontend" - "ruderich.org/simon/safcm/rpc" "ruderich.org/simon/safcm/testutil" ) @@ -195,356 +190,3 @@ are only available after the hosts were contacted. }) } } - -func TestLogEvent(t *testing.T) { - // Restore default logger - defer log.SetFlags(log.Flags()) - defer log.SetOutput(os.Stderr) - - tests := []struct { - name string - event frontend.Event - level safcm.LogLevel - isTTY bool - exp string - expFailed bool - }{ - - { - "Error", - frontend.Event{ - Error: fmt.Errorf("fake error"), - }, - safcm.LogDebug3, - false, - "[error] [fake-host] fake error\n", - true, - }, - { - "Error (tty)", - frontend.Event{ - Error: fmt.Errorf("fake error"), - }, - safcm.LogDebug3, - true, - "[error] [\x1b[31mfake-host\x1b[0m] fake error\n", - true, - }, - { - "Error: escape", - frontend.Event{ - Error: fmt.Errorf("\x00"), - }, - safcm.LogDebug3, - false, - "[error] [fake-host] \\x00\n", - true, - }, - { - "Error: escape (tty)", - frontend.Event{ - Error: fmt.Errorf("\x00"), - }, - safcm.LogDebug3, - true, - "[error] [\x1b[31mfake-host\x1b[0m] \x1b[35m\\x00\x1b[0m\n", - true, - }, - - { - "Log: info", - frontend.Event{ - Log: frontend.Log{ - Level: safcm.LogInfo, - Text: "info log", - }, - }, - safcm.LogDebug3, - false, - "[info] [fake-host] info log\n", - false, - }, - { - "Log: info (tty)", - frontend.Event{ - Log: frontend.Log{ - Level: safcm.LogInfo, - Text: "info log", - }, - }, - safcm.LogDebug3, - true, - "[info] [fake-host] info log\n", - false, - }, - { - "Log: verbose", - frontend.Event{ - Log: frontend.Log{ - Level: safcm.LogVerbose, - Text: "verbose log", - }, - }, - safcm.LogDebug3, - false, - "[verbose] [fake-host] verbose log\n", - false, - }, - { - "Log: debug", - frontend.Event{ - Log: frontend.Log{ - Level: safcm.LogDebug, - Text: "debug log", - }, - }, - safcm.LogDebug3, - false, - "[debug] [fake-host] debug log\n", - false, - }, - { - "Log: debug2", - frontend.Event{ - Log: frontend.Log{ - Level: safcm.LogDebug2, - Text: "debug2 log", - }, - }, - safcm.LogDebug3, - false, - "[debug2] [fake-host] debug2 log\n", - false, - }, - { - "Log: debug3", - frontend.Event{ - Log: frontend.Log{ - Level: safcm.LogDebug3, - Text: "debug3 log", - }, - }, - safcm.LogDebug3, - false, - fmt.Sprintf("[INVALID=%d] [fake-host] debug3 log\n", - safcm.LogDebug3), - false, - }, - { - "Log: debug3 (tty)", - frontend.Event{ - Log: frontend.Log{ - Level: safcm.LogDebug3, - Text: "debug3 log", - }, - }, - safcm.LogDebug3, - true, - fmt.Sprintf("[INVALID=%d] [\x1b[31mfake-host\x1b[0m] debug3 log\n", - safcm.LogDebug3), - false, - }, - { - "Log: escape", - frontend.Event{ - Log: frontend.Log{ - Level: safcm.LogInfo, - Text: "\x00", - }, - }, - safcm.LogDebug3, - false, - "[info] [fake-host] \\x00\n", - false, - }, - { - "Log: escape (tty)", - frontend.Event{ - Log: frontend.Log{ - Level: safcm.LogInfo, - Text: "\x00", - }, - }, - safcm.LogDebug3, - true, - "[info] [fake-host] \x1b[35m\\x00\x1b[0m\n", - false, - }, - - { - "ConnEvent: stderr", - frontend.Event{ - ConnEvent: rpc.ConnEvent{ - Type: rpc.ConnEventStderr, - Data: "fake stderr", - }, - }, - safcm.LogDebug3, - false, - "[stderr] [fake-host] fake stderr\n", - false, - }, - { - "ConnEvent: stderr (tty)", - frontend.Event{ - ConnEvent: rpc.ConnEvent{ - Type: rpc.ConnEventStderr, - Data: "fake stderr", - }, - }, - safcm.LogDebug3, - true, - "[stderr] [fake-host] fake stderr\n", - false, - }, - { - "ConnEvent: debug", - frontend.Event{ - ConnEvent: rpc.ConnEvent{ - Type: rpc.ConnEventDebug, - Data: "conn debug", - }, - }, - safcm.LogDebug3, - false, - "[debug3] [fake-host] conn debug\n", - false, - }, - { - "ConnEvent: upload", - frontend.Event{ - ConnEvent: rpc.ConnEvent{ - Type: rpc.ConnEventUpload, - }, - }, - safcm.LogDebug3, - false, - "[info] [fake-host] remote helper upload in progress\n", - false, - }, - { - "ConnEvent: upload (ignored)", - frontend.Event{ - ConnEvent: rpc.ConnEvent{ - Type: rpc.ConnEventUpload, - }, - }, - safcm.LogError, - false, - "", - false, - }, - { - "ConnEvent: invalid", - frontend.Event{ - ConnEvent: rpc.ConnEvent{ - Type: 42, - Data: "invalid", - }, - }, - safcm.LogError, - false, - "[INVALID=42] [fake-host] invalid\n", - false, - }, - { - "ConnEvent: invalid (tty)", - frontend.Event{ - ConnEvent: rpc.ConnEvent{ - Type: 42, - Data: "invalid", - }, - }, - safcm.LogError, - true, - "[INVALID=42] [\x1b[31mfake-host\x1b[0m] invalid\n", - false, - }, - { - "ConnEvent: escape", - frontend.Event{ - ConnEvent: rpc.ConnEvent{ - Type: rpc.ConnEventStderr, - Data: "\x00", - }, - }, - safcm.LogDebug3, - false, - "[stderr] [fake-host] \\x00\n", - false, - }, - { - "ConnEvent: escape (tty)", - frontend.Event{ - ConnEvent: rpc.ConnEvent{ - Type: rpc.ConnEventDebug, - Data: "\x01", - }, - }, - safcm.LogDebug3, - true, - "[debug3] [fake-host] \x1b[35m\\x01\x1b[0m\n", - false, - }, - - { - "Escaped", - frontend.Event{ - Log: frontend.Log{ - Level: safcm.LogInfo, - Text: "\x00", - }, - Escaped: true, - }, - safcm.LogDebug3, - false, - "[info] [fake-host] \x00\n", - false, - }, - { - "Escaped (tty)", - frontend.Event{ - Log: frontend.Log{ - Level: safcm.LogInfo, - Text: "\x00", - }, - Escaped: true, - }, - safcm.LogDebug3, - true, - "[info] [fake-host] \x00\n", - false, - }, - - { - "empty (invalid)", - frontend.Event{}, - safcm.LogDebug3, - false, - "[INVALID=0] [fake-host] \n", - false, - }, - } - - for _, tc := range tests { - t.Run(tc.name, func(t *testing.T) { - tc.event.Host = &Sync{ - host: &config.Host{ - Name: "fake-host", - }, - } - - var buf bytes.Buffer - log.SetFlags(0) - log.SetOutput(&buf) - - var failed bool - logEvent(tc.event, tc.level, tc.isTTY, &failed) - - testutil.AssertEqual(t, "log", - buf.String(), tc.exp) - testutil.AssertEqual(t, "failed", - failed, tc.expFailed) - }) - } -} diff --git a/frontend/log.go b/frontend/log.go index 33fa1d0..aed57dd 100644 --- a/frontend/log.go +++ b/frontend/log.go @@ -18,6 +18,9 @@ package frontend import ( + "fmt" + "log" + "ruderich.org/simon/safcm" "ruderich.org/simon/safcm/rpc" ) @@ -50,3 +53,67 @@ func (l *Loop) Log(host Host, level safcm.LogLevel, escaped bool, Escaped: escaped, } } + +// LogEvent logs events using the log package. It can be used to implement +// Loop.LogEventFunc. It's used by cmd/safcm to log events. +func LogEvent(x Event, level safcm.LogLevel, isTTY bool, + failed *bool) { + + // We have multiple event sources so this is somewhat ugly. + var prefix, data string + var color Color + if x.Error != nil { + prefix = "[error]" + data = x.Error.Error() + color = ColorRed + // We logged an error, tell the caller + *failed = true + } else if x.Log.Level != 0 { + if level < x.Log.Level { + return + } + // LogError and LogDebug3 should not occur here + switch x.Log.Level { + case safcm.LogInfo: + prefix = "[info]" + case safcm.LogVerbose: + prefix = "[verbose]" + case safcm.LogDebug: + prefix = "[debug]" + case safcm.LogDebug2: + prefix = "[debug2]" + default: + prefix = fmt.Sprintf("[INVALID=%d]", x.Log.Level) + color = ColorRed + } + data = x.Log.Text + } else { + switch x.ConnEvent.Type { + case rpc.ConnEventStderr: + prefix = "[stderr]" + case rpc.ConnEventDebug: + prefix = "[debug3]" + case rpc.ConnEventUpload: + if level < safcm.LogInfo { + return + } + prefix = "[info]" + x.ConnEvent.Data = "remote helper upload in progress" + default: + prefix = fmt.Sprintf("[INVALID=%d]", x.ConnEvent.Type) + color = ColorRed + } + data = x.ConnEvent.Data + } + + host := x.Host.Name() + if color != 0 { + host = ColorString(isTTY, color, host) + } + // Make sure to escape control characters to prevent terminal + // injection attacks + if !x.Escaped { + data = EscapeControlCharacters(isTTY, data) + } + log.Printf("%-9s [%s] %s", prefix, host, data) +} diff --git a/frontend/log_test.go b/frontend/log_test.go new file mode 100644 index 0000000..ebdd3ae --- /dev/null +++ b/frontend/log_test.go @@ -0,0 +1,390 @@ +// Copyright (C) 2021 Simon Ruderich +// +// This program is free software: you can redistribute it and/or modify +// it under the terms of the GNU General Public License as published by +// the Free Software Foundation, either version 3 of the License, or +// (at your option) any later version. +// +// This program is distributed in the hope that it will be useful, +// but WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +// GNU General Public License for more details. +// +// You should have received a copy of the GNU General Public License +// along with this program. If not, see . + +package frontend + +import ( + "bytes" + "fmt" + "log" + "os" + "testing" + + "ruderich.org/simon/safcm" + "ruderich.org/simon/safcm/rpc" + "ruderich.org/simon/safcm/testutil" +) + +type TestHost struct { + name string +} + +func (th *TestHost) Name() string { + return th.name +} +func (th *TestHost) Dial(*rpc.Conn) error { + return fmt.Errorf("not implemented") +} + +func TestLogEvent(t *testing.T) { + // Restore default logger + defer log.SetFlags(log.Flags()) + defer log.SetOutput(os.Stderr) + + tests := []struct { + name string + event Event + level safcm.LogLevel + isTTY bool + exp string + expFailed bool + }{ + + { + "Error", + Event{ + Error: fmt.Errorf("fake error"), + }, + safcm.LogDebug3, + false, + "[error] [fake-host] fake error\n", + true, + }, + { + "Error (tty)", + Event{ + Error: fmt.Errorf("fake error"), + }, + safcm.LogDebug3, + true, + "[error] [\x1b[31mfake-host\x1b[0m] fake error\n", + true, + }, + { + "Error: escape", + Event{ + Error: fmt.Errorf("\x00"), + }, + safcm.LogDebug3, + false, + "[error] [fake-host] \\x00\n", + true, + }, + { + "Error: escape (tty)", + Event{ + Error: fmt.Errorf("\x00"), + }, + safcm.LogDebug3, + true, + "[error] [\x1b[31mfake-host\x1b[0m] \x1b[35m\\x00\x1b[0m\n", + true, + }, + + { + "Log: info", + Event{ + Log: Log{ + Level: safcm.LogInfo, + Text: "info log", + }, + }, + safcm.LogDebug3, + false, + "[info] [fake-host] info log\n", + false, + }, + { + "Log: info (tty)", + Event{ + Log: Log{ + Level: safcm.LogInfo, + Text: "info log", + }, + }, + safcm.LogDebug3, + true, + "[info] [fake-host] info log\n", + false, + }, + { + "Log: verbose", + Event{ + Log: Log{ + Level: safcm.LogVerbose, + Text: "verbose log", + }, + }, + safcm.LogDebug3, + false, + "[verbose] [fake-host] verbose log\n", + false, + }, + { + "Log: debug", + Event{ + Log: Log{ + Level: safcm.LogDebug, + Text: "debug log", + }, + }, + safcm.LogDebug3, + false, + "[debug] [fake-host] debug log\n", + false, + }, + { + "Log: debug2", + Event{ + Log: Log{ + Level: safcm.LogDebug2, + Text: "debug2 log", + }, + }, + safcm.LogDebug3, + false, + "[debug2] [fake-host] debug2 log\n", + false, + }, + { + "Log: debug3", + Event{ + Log: Log{ + Level: safcm.LogDebug3, + Text: "debug3 log", + }, + }, + safcm.LogDebug3, + false, + fmt.Sprintf("[INVALID=%d] [fake-host] debug3 log\n", + safcm.LogDebug3), + false, + }, + { + "Log: debug3 (tty)", + Event{ + Log: Log{ + Level: safcm.LogDebug3, + Text: "debug3 log", + }, + }, + safcm.LogDebug3, + true, + fmt.Sprintf("[INVALID=%d] [\x1b[31mfake-host\x1b[0m] debug3 log\n", + safcm.LogDebug3), + false, + }, + { + "Log: escape", + Event{ + Log: Log{ + Level: safcm.LogInfo, + Text: "\x00", + }, + }, + safcm.LogDebug3, + false, + "[info] [fake-host] \\x00\n", + false, + }, + { + "Log: escape (tty)", + Event{ + Log: Log{ + Level: safcm.LogInfo, + Text: "\x00", + }, + }, + safcm.LogDebug3, + true, + "[info] [fake-host] \x1b[35m\\x00\x1b[0m\n", + false, + }, + + { + "ConnEvent: stderr", + Event{ + ConnEvent: rpc.ConnEvent{ + Type: rpc.ConnEventStderr, + Data: "fake stderr", + }, + }, + safcm.LogDebug3, + false, + "[stderr] [fake-host] fake stderr\n", + false, + }, + { + "ConnEvent: stderr (tty)", + Event{ + ConnEvent: rpc.ConnEvent{ + Type: rpc.ConnEventStderr, + Data: "fake stderr", + }, + }, + safcm.LogDebug3, + true, + "[stderr] [fake-host] fake stderr\n", + false, + }, + { + "ConnEvent: debug", + Event{ + ConnEvent: rpc.ConnEvent{ + Type: rpc.ConnEventDebug, + Data: "conn debug", + }, + }, + safcm.LogDebug3, + false, + "[debug3] [fake-host] conn debug\n", + false, + }, + { + "ConnEvent: upload", + Event{ + ConnEvent: rpc.ConnEvent{ + Type: rpc.ConnEventUpload, + }, + }, + safcm.LogDebug3, + false, + "[info] [fake-host] remote helper upload in progress\n", + false, + }, + { + "ConnEvent: upload (ignored)", + Event{ + ConnEvent: rpc.ConnEvent{ + Type: rpc.ConnEventUpload, + }, + }, + safcm.LogError, + false, + "", + false, + }, + { + "ConnEvent: invalid", + Event{ + ConnEvent: rpc.ConnEvent{ + Type: 42, + Data: "invalid", + }, + }, + safcm.LogError, + false, + "[INVALID=42] [fake-host] invalid\n", + false, + }, + { + "ConnEvent: invalid (tty)", + Event{ + ConnEvent: rpc.ConnEvent{ + Type: 42, + Data: "invalid", + }, + }, + safcm.LogError, + true, + "[INVALID=42] [\x1b[31mfake-host\x1b[0m] invalid\n", + false, + }, + { + "ConnEvent: escape", + Event{ + ConnEvent: rpc.ConnEvent{ + Type: rpc.ConnEventStderr, + Data: "\x00", + }, + }, + safcm.LogDebug3, + false, + "[stderr] [fake-host] \\x00\n", + false, + }, + { + "ConnEvent: escape (tty)", + Event{ + ConnEvent: rpc.ConnEvent{ + Type: rpc.ConnEventDebug, + Data: "\x01", + }, + }, + safcm.LogDebug3, + true, + "[debug3] [fake-host] \x1b[35m\\x01\x1b[0m\n", + false, + }, + + { + "Escaped", + Event{ + Log: Log{ + Level: safcm.LogInfo, + Text: "\x00", + }, + Escaped: true, + }, + safcm.LogDebug3, + false, + "[info] [fake-host] \x00\n", + false, + }, + { + "Escaped (tty)", + Event{ + Log: Log{ + Level: safcm.LogInfo, + Text: "\x00", + }, + Escaped: true, + }, + safcm.LogDebug3, + true, + "[info] [fake-host] \x00\n", + false, + }, + + { + "empty (invalid)", + Event{}, + safcm.LogDebug3, + false, + "[INVALID=0] [fake-host] \n", + false, + }, + } + + for _, tc := range tests { + t.Run(tc.name, func(t *testing.T) { + tc.event.Host = &TestHost{ + name: "fake-host", + } + + var buf bytes.Buffer + log.SetFlags(0) + log.SetOutput(&buf) + + var failed bool + LogEvent(tc.event, tc.level, tc.isTTY, &failed) + + testutil.AssertEqual(t, "log", + buf.String(), tc.exp) + testutil.AssertEqual(t, "failed", + failed, tc.expFailed) + }) + } +} -- 2.43.2