add slog and LOG_LEVEL to agent

This commit is contained in:
Henry Dollman
2024-09-26 20:07:35 -04:00
parent cec9339f6d
commit 764e043e83
4 changed files with 57 additions and 45 deletions

View File

@@ -8,7 +8,7 @@ import (
"context" "context"
"encoding/json" "encoding/json"
"fmt" "fmt"
"log" "log/slog"
"net/http" "net/http"
"os" "os"
"strconv" "strconv"
@@ -59,7 +59,7 @@ func (a *Agent) getSystemStats() (system.Info, system.Stats) {
// cpu percent // cpu percent
cpuPct, err := cpu.Percent(0, false) cpuPct, err := cpu.Percent(0, false)
if err != nil { if err != nil {
log.Println("Error getting cpu percent:", err) slog.Error("Error getting cpu percent", "err", err)
} else if len(cpuPct) > 0 { } else if len(cpuPct) > 0 {
systemStats.Cpu = twoDecimals(cpuPct[0]) systemStats.Cpu = twoDecimals(cpuPct[0])
} }
@@ -76,7 +76,6 @@ func (a *Agent) getSystemStats() (system.Info, system.Stats) {
// disk usage // disk usage
for _, stats := range a.fsStats { for _, stats := range a.fsStats {
// log.Println("Reading filesystem:", fs.Mountpoint)
if d, err := disk.Usage(stats.Mountpoint); err == nil { if d, err := disk.Usage(stats.Mountpoint); err == nil {
stats.DiskTotal = bytesToGigabytes(d.Total) stats.DiskTotal = bytesToGigabytes(d.Total)
stats.DiskUsed = bytesToGigabytes(d.Used) stats.DiskUsed = bytesToGigabytes(d.Used)
@@ -87,7 +86,7 @@ func (a *Agent) getSystemStats() (system.Info, system.Stats) {
} }
} else { } else {
// reset stats if error (likely unmounted) // reset stats if error (likely unmounted)
log.Printf("Error reading %s: %+v\n", stats.Mountpoint, err) slog.Error("Error getting disk stats", "name", stats.Mountpoint, "err", err)
stats.DiskTotal = 0 stats.DiskTotal = 0
stats.DiskUsed = 0 stats.DiskUsed = 0
stats.TotalRead = 0 stats.TotalRead = 0
@@ -130,7 +129,6 @@ func (a *Agent) getSystemStats() (system.Info, system.Stats) {
if _, exists := a.netInterfaces[v.Name]; !exists { if _, exists := a.netInterfaces[v.Name]; !exists {
continue continue
} }
// log.Printf("%+v: %+v recv, %+v sent\n", v.Name, v.BytesRecv, v.BytesSent)
bytesSent += v.BytesSent bytesSent += v.BytesSent
bytesRecv += v.BytesRecv bytesRecv += v.BytesRecv
} }
@@ -141,12 +139,12 @@ func (a *Agent) getSystemStats() (system.Info, system.Stats) {
networkRecvPs := bytesToMegabytes(recvPerSecond) networkRecvPs := bytesToMegabytes(recvPerSecond)
// add check for issue (#150) where sent is a massive number // add check for issue (#150) where sent is a massive number
if networkSentPs > 10_000 || networkRecvPs > 10_000 { if networkSentPs > 10_000 || networkRecvPs > 10_000 {
log.Printf("Warning: network sent/recv is %.2f/%.2f MB/s. Resetting stats.\n", networkSentPs, networkRecvPs) slog.Warn("Invalid network stats. Resetting.", "sent", networkSentPs, "recv", networkRecvPs)
for _, v := range netIO { for _, v := range netIO {
if _, exists := a.netInterfaces[v.Name]; !exists { if _, exists := a.netInterfaces[v.Name]; !exists {
continue continue
} }
log.Printf("%+s: %v recv, %v sent\n", v.Name, v.BytesRecv, v.BytesSent) slog.Info(v.Name, "recv", v.BytesRecv, "sent", v.BytesSent)
} }
// reset network I/O stats // reset network I/O stats
a.initializeNetIoStats() a.initializeNetIoStats()
@@ -161,8 +159,8 @@ func (a *Agent) getSystemStats() (system.Info, system.Stats) {
// temperatures // temperatures
if temps, err := sensors.TemperaturesWithContext(a.sensorsContext); err == nil { if temps, err := sensors.TemperaturesWithContext(a.sensorsContext); err == nil {
slog.Debug("Temperatures", "data", temps)
systemStats.Temperatures = make(map[string]float64) systemStats.Temperatures = make(map[string]float64)
// log.Printf("Temperatures: %+v\n", temps)
for i, temp := range temps { for i, temp := range temps {
if _, ok := systemStats.Temperatures[temp.SensorKey]; ok { if _, ok := systemStats.Temperatures[temp.SensorKey]; ok {
// if key already exists, append int to key // if key already exists, append int to key
@@ -171,7 +169,8 @@ func (a *Agent) getSystemStats() (system.Info, system.Stats) {
systemStats.Temperatures[temp.SensorKey] = twoDecimals(temp.Temperature) systemStats.Temperatures[temp.SensorKey] = twoDecimals(temp.Temperature)
} }
} }
// log.Printf("Temperature map: %+v\n", systemStats.Temperatures) } else {
slog.Debug("Error getting temperatures", "err", err)
} }
systemInfo := system.Info{ systemInfo := system.Info{
@@ -183,6 +182,7 @@ func (a *Agent) getSystemStats() (system.Info, system.Stats) {
// add host info // add host info
if info, err := host.Info(); err == nil { if info, err := host.Info(); err == nil {
// slog.Debug("Virtualization", "system", info.VirtualizationSystem, "role", info.VirtualizationRole)
systemInfo.Uptime = info.Uptime systemInfo.Uptime = info.Uptime
systemInfo.Hostname = info.Hostname systemInfo.Hostname = info.Hostname
systemInfo.KernelVersion = info.KernelVersion systemInfo.KernelVersion = info.KernelVersion
@@ -217,7 +217,7 @@ func (a *Agent) getDockerStats() ([]container.Stats, error) {
var containers []container.ApiInfo var containers []container.ApiInfo
if err := json.NewDecoder(resp.Body).Decode(&containers); err != nil { if err := json.NewDecoder(resp.Body).Decode(&containers); err != nil {
log.Printf("Error decoding containers: %+v\n", err) slog.Error("Error decoding containers", "err", err)
return nil, err return nil, err
} }
@@ -254,7 +254,7 @@ func (a *Agent) getDockerStats() ([]container.Stats, error) {
// retry once // retry once
cstats, err = a.getContainerStats(ctr) cstats, err = a.getContainerStats(ctr)
if err != nil { if err != nil {
log.Printf("Error getting container stats: %+v\n", err) slog.Error("Error getting container stats", "err", err)
return return
} }
} }
@@ -266,9 +266,9 @@ func (a *Agent) getDockerStats() ([]container.Stats, error) {
wg.Wait() wg.Wait()
// remove old / invalid container stats
for id := range a.containerStatsMap { for id := range a.containerStatsMap {
if _, exists := validIds[id]; !exists { if _, exists := validIds[id]; !exists {
// log.Printf("Removing container cpu map entry: %+v\n", id)
delete(a.containerStatsMap, id) delete(a.containerStatsMap, id)
} }
} }
@@ -295,7 +295,7 @@ func (a *Agent) getContainerStats(ctr container.ApiInfo) (container.Stats, error
// check if container has valid data, otherwise may be in restart loop (#103) // check if container has valid data, otherwise may be in restart loop (#103)
if statsJson.MemoryStats.Usage == 0 { if statsJson.MemoryStats.Usage == 0 {
return cStats, fmt.Errorf("%s - invalid data", name) return cStats, fmt.Errorf("%s - no memory stats - see https://github.com/henrygd/beszel/issues/144", name)
} }
// memory (https://docs.docker.com/reference/cli/docker/container/stats/) // memory (https://docs.docker.com/reference/cli/docker/container/stats/)
@@ -336,13 +336,11 @@ func (a *Agent) getContainerStats(ctr container.ApiInfo) (container.Stats, error
secondsElapsed := time.Since(stats.Net.Time).Seconds() secondsElapsed := time.Since(stats.Net.Time).Seconds()
sent_delta = float64(total_sent-stats.Net.Sent) / secondsElapsed sent_delta = float64(total_sent-stats.Net.Sent) / secondsElapsed
recv_delta = float64(total_recv-stats.Net.Recv) / secondsElapsed recv_delta = float64(total_recv-stats.Net.Recv) / secondsElapsed
// log.Printf("sent delta: %+v, recv delta: %+v\n", sent_delta, recv_delta)
} }
stats.Net.Sent = total_sent stats.Net.Sent = total_sent
stats.Net.Recv = total_recv stats.Net.Recv = total_recv
stats.Net.Time = time.Now() stats.Net.Time = time.Now()
// cStats := a.containerStatsPool.Get().(*container.Stats)
cStats.Name = name cStats.Name = name
cStats.Cpu = twoDecimals(cpuPct) cStats.Cpu = twoDecimals(cpuPct)
cStats.Mem = bytesToMegabytes(float64(usedMemory)) cStats.Mem = bytesToMegabytes(float64(usedMemory))
@@ -369,16 +367,28 @@ func (a *Agent) gatherStats() system.CombinedData {
systemData.Stats.ExtraFs[name] = stats systemData.Stats.ExtraFs[name] = stats
} }
} }
// log.Printf("%+v\n", systemData)
return systemData return systemData
} }
func (a *Agent) Run() { func (a *Agent) Run() {
// Create map for disk stats
a.fsStats = make(map[string]*system.FsStats) a.fsStats = make(map[string]*system.FsStats)
// set sensors context (allows overriding sys location for sensors) // Set up slog with a log level determined by the LOG_LEVEL env var
if logLevelStr, exists := os.LookupEnv("LOG_LEVEL"); exists {
switch strings.ToLower(logLevelStr) {
case "debug":
slog.SetLogLoggerLevel(slog.LevelDebug)
case "warn":
slog.SetLogLoggerLevel(slog.LevelWarn)
case "error":
slog.SetLogLoggerLevel(slog.LevelError)
}
}
// Set sensors context (allows overriding sys location for sensors)
if sysSensors, exists := os.LookupEnv("SYS_SENSORS"); exists { if sysSensors, exists := os.LookupEnv("SYS_SENSORS"); exists {
// log.Println("Using sys location for sensors:", sysSensors) slog.Info("SYS_SENSORS", "path", sysSensors)
a.sensorsContext = context.WithValue(a.sensorsContext, a.sensorsContext = context.WithValue(a.sensorsContext,
common.EnvKey, common.EnvMap{common.HostSysEnvKey: sysSensors}, common.EnvKey, common.EnvMap{common.HostSysEnvKey: sysSensors},
) )

View File

@@ -2,10 +2,9 @@ package agent
import ( import (
"beszel/internal/entities/system" "beszel/internal/entities/system"
"log/slog"
"time" "time"
"fmt"
"log"
"os" "os"
"path/filepath" "path/filepath"
"strings" "strings"
@@ -21,8 +20,9 @@ func (a *Agent) initializeDiskInfo() {
partitions, err := disk.Partitions(false) partitions, err := disk.Partitions(false)
if err != nil { if err != nil {
log.Println("Error getting disk partitions:", err.Error()) slog.Error("Error getting disk partitions", "err", err)
} }
slog.Debug("Disk", "partitions", partitions)
// ioContext := context.WithValue(a.sensorsContext, // ioContext := context.WithValue(a.sensorsContext,
// common.EnvKey, common.EnvMap{common.HostProcEnvKey: "/tmp/testproc"}, // common.EnvKey, common.EnvMap{common.HostProcEnvKey: "/tmp/testproc"},
@@ -31,20 +31,21 @@ func (a *Agent) initializeDiskInfo() {
diskIoCounters, err := disk.IOCounters() diskIoCounters, err := disk.IOCounters()
if err != nil { if err != nil {
log.Println("Error getting diskstats:", err.Error()) slog.Error("Error getting diskstats", "err", err)
} }
slog.Debug("Disk I/O", "diskstats", diskIoCounters)
// Helper function to add a filesystem to fsStats if it doesn't exist // Helper function to add a filesystem to fsStats if it doesn't exist
addFsStat := func(device, mountpoint string, root bool) { addFsStat := func(device, mountpoint string, root bool) {
key := filepath.Base(device) key := filepath.Base(device)
if _, exists := a.fsStats[key]; !exists { if _, exists := a.fsStats[key]; !exists {
if root { if root {
log.Println("Detected root fs:", key) slog.Info("Detected root device", "name", key)
// check if root device is in /proc/diskstats, use fallback if not // check if root device is in /proc/diskstats, use fallback if not
if _, exists := diskIoCounters[key]; !exists { if _, exists := diskIoCounters[key]; !exists {
log.Printf("%s not found in diskstats\n", key) slog.Warn("Device not found in diskstats", "name", key)
key = findFallbackIoDevice(filesystem, diskIoCounters) key = findFallbackIoDevice(filesystem, diskIoCounters)
log.Printf("Using %s for I/O\n", key) slog.Info("Using I/O fallback", "name", key)
} }
} }
a.fsStats[key] = &system.FsStats{Root: root, Mountpoint: mountpoint} a.fsStats[key] = &system.FsStats{Root: root, Mountpoint: mountpoint}
@@ -61,10 +62,7 @@ func (a *Agent) initializeDiskInfo() {
} }
} }
if !hasRoot { if !hasRoot {
log.Printf("Partition details not found for %s\n", filesystem) slog.Warn("Partition details not found", "filesystem", filesystem)
for _, p := range partitions {
fmt.Printf("%+v\n", p)
}
} }
} }
@@ -84,7 +82,7 @@ func (a *Agent) initializeDiskInfo() {
if _, err := disk.Usage(fs); err == nil { if _, err := disk.Usage(fs); err == nil {
addFsStat(filepath.Base(fs), fs, false) addFsStat(filepath.Base(fs), fs, false)
} else { } else {
log.Println(err, fs) slog.Error("Invalid filesystem", "name", fs, "err", err)
} }
} }
} }
@@ -107,7 +105,6 @@ func (a *Agent) initializeDiskInfo() {
// Check all folders in /extra-filesystems and add them if not already present // Check all folders in /extra-filesystems and add them if not already present
if folders, err := os.ReadDir(efPath); err == nil { if folders, err := os.ReadDir(efPath); err == nil {
// log.Printf("Found %d extra filesystems in %s\n", len(folders), efPath)
existingMountpoints := make(map[string]bool) existingMountpoints := make(map[string]bool)
for _, stats := range a.fsStats { for _, stats := range a.fsStats {
existingMountpoints[stats.Mountpoint] = true existingMountpoints[stats.Mountpoint] = true
@@ -115,6 +112,7 @@ func (a *Agent) initializeDiskInfo() {
for _, folder := range folders { for _, folder := range folders {
if folder.IsDir() { if folder.IsDir() {
mountpoint := filepath.Join(efPath, folder.Name()) mountpoint := filepath.Join(efPath, folder.Name())
slog.Debug("/extra-filesystems", "mountpoint", mountpoint)
if !existingMountpoints[mountpoint] { if !existingMountpoints[mountpoint] {
a.fsStats[folder.Name()] = &system.FsStats{Mountpoint: mountpoint} a.fsStats[folder.Name()] = &system.FsStats{Mountpoint: mountpoint}
} }
@@ -125,7 +123,7 @@ func (a *Agent) initializeDiskInfo() {
// If no root filesystem set, use fallback // If no root filesystem set, use fallback
if !hasRoot { if !hasRoot {
rootDevice := findFallbackIoDevice(filepath.Base(filesystem), diskIoCounters) rootDevice := findFallbackIoDevice(filepath.Base(filesystem), diskIoCounters)
log.Printf("Using / as mountpoint and %s for I/O\n", rootDevice) slog.Info("Root disk", "mountpoint", "/", "io", rootDevice)
a.fsStats[rootDevice] = &system.FsStats{Root: true, Mountpoint: "/"} a.fsStats[rootDevice] = &system.FsStats{Root: true, Mountpoint: "/"}
} }
@@ -155,7 +153,7 @@ func (a *Agent) initializeDiskIoStats(diskIoCounters map[string]disk.IOCountersS
// skip if not in diskIoCounters // skip if not in diskIoCounters
d, exists := diskIoCounters[device] d, exists := diskIoCounters[device]
if !exists { if !exists {
log.Println(device, "not found in diskstats") slog.Warn("Device not found in diskstats", "name", device)
continue continue
} }
// populate initial values // populate initial values

View File

@@ -2,7 +2,7 @@ package agent
import ( import (
"context" "context"
"log" "log/slog"
"net" "net"
"net/http" "net/http"
"net/url" "net/url"
@@ -47,7 +47,7 @@ func (a *Agent) initializeNetIoStats() {
continue continue
} }
} }
log.Printf("Detected network interface: %+v (%+v recv, %+v sent)\n", v.Name, v.BytesRecv, v.BytesSent) slog.Info("Detected network interface", "name", v.Name, "sent", v.BytesSent, "recv", v.BytesRecv)
a.netIoStats.BytesSent += v.BytesSent a.netIoStats.BytesSent += v.BytesSent
a.netIoStats.BytesRecv += v.BytesRecv a.netIoStats.BytesRecv += v.BytesRecv
// store as a valid network interface // store as a valid network interface
@@ -73,12 +73,14 @@ func (a *Agent) skipNetworkInterface(v psutilNet.IOCountersStat) bool {
func newDockerClient() *http.Client { func newDockerClient() *http.Client {
dockerHost := "unix:///var/run/docker.sock" dockerHost := "unix:///var/run/docker.sock"
if dockerHostEnv, exists := os.LookupEnv("DOCKER_HOST"); exists { if dockerHostEnv, exists := os.LookupEnv("DOCKER_HOST"); exists {
slog.Info("DOCKER_HOST", "host", dockerHostEnv)
dockerHost = dockerHostEnv dockerHost = dockerHostEnv
} }
parsedURL, err := url.Parse(dockerHost) parsedURL, err := url.Parse(dockerHost)
if err != nil { if err != nil {
log.Fatal("Error parsing DOCKER_HOST: " + err.Error()) slog.Error("Error parsing DOCKER_HOST", "err", err)
os.Exit(1)
} }
transport := &http.Transport{ transport := &http.Transport{
@@ -96,12 +98,12 @@ func newDockerClient() *http.Client {
return (&net.Dialer{}).DialContext(ctx, "unix", parsedURL.Path) return (&net.Dialer{}).DialContext(ctx, "unix", parsedURL.Path)
} }
case "tcp", "http", "https": case "tcp", "http", "https":
log.Println("Using DOCKER_HOST: " + dockerHost)
transport.DialContext = func(ctx context.Context, proto, addr string) (net.Conn, error) { transport.DialContext = func(ctx context.Context, proto, addr string) (net.Conn, error) {
return (&net.Dialer{}).DialContext(ctx, "tcp", parsedURL.Host) return (&net.Dialer{}).DialContext(ctx, "tcp", parsedURL.Host)
} }
default: default:
log.Fatal("Unsupported DOCKER_HOST: " + parsedURL.Scheme) slog.Error("Invalid DOCKER_HOST", "scheme", parsedURL.Scheme)
os.Exit(1)
} }
return &http.Client{ return &http.Client{
@@ -113,7 +115,7 @@ func newDockerClient() *http.Client {
// closes idle connections on timeouts to prevent reuse of stale connections // closes idle connections on timeouts to prevent reuse of stale connections
func (a *Agent) closeIdleConnections(err error) (isTimeout bool) { func (a *Agent) closeIdleConnections(err error) (isTimeout bool) {
if netErr, ok := err.(net.Error); ok && netErr.Timeout() { if netErr, ok := err.(net.Error); ok && netErr.Timeout() {
log.Printf("Closing idle connections. Error: %+v\n", err) slog.Warn("Closing idle connections", "err", err)
a.dockerClient.Transport.(*http.Transport).CloseIdleConnections() a.dockerClient.Transport.(*http.Transport).CloseIdleConnections()
return true return true
} }

View File

@@ -2,7 +2,8 @@ package agent
import ( import (
"encoding/json" "encoding/json"
"log" "log/slog"
"os"
sshServer "github.com/gliderlabs/ssh" sshServer "github.com/gliderlabs/ssh"
) )
@@ -10,22 +11,23 @@ import (
func (a *Agent) startServer() { func (a *Agent) startServer() {
sshServer.Handle(a.handleSession) sshServer.Handle(a.handleSession)
log.Printf("Starting SSH server on %s", a.addr) slog.Info("Starting SSH server", "address", a.addr)
if err := sshServer.ListenAndServe(a.addr, nil, sshServer.NoPty(), if err := sshServer.ListenAndServe(a.addr, nil, sshServer.NoPty(),
sshServer.PublicKeyAuth(func(ctx sshServer.Context, key sshServer.PublicKey) bool { sshServer.PublicKeyAuth(func(ctx sshServer.Context, key sshServer.PublicKey) bool {
allowed, _, _, _, _ := sshServer.ParseAuthorizedKey(a.pubKey) allowed, _, _, _, _ := sshServer.ParseAuthorizedKey(a.pubKey)
return sshServer.KeysEqual(key, allowed) return sshServer.KeysEqual(key, allowed)
}), }),
); err != nil { ); err != nil {
log.Fatal(err) slog.Error("Error starting SSH server", "err", err)
os.Exit(1)
} }
} }
func (a *Agent) handleSession(s sshServer.Session) { func (a *Agent) handleSession(s sshServer.Session) {
stats := a.gatherStats() stats := a.gatherStats()
encoder := json.NewEncoder(s) slog.Debug("Sending stats", "data", stats)
if err := encoder.Encode(stats); err != nil { if err := json.NewEncoder(s).Encode(stats); err != nil {
log.Println("Error encoding stats:", err.Error()) slog.Error("Error encoding stats", "err", err)
s.Exit(1) s.Exit(1)
return return
} }