Add extensive logging to networking package

This commit is contained in:
NeilClack
2026-06-24 21:32:14 -05:00
parent 953d0d8bc9
commit a7f551ccca
+35 -15
View File
@@ -5,7 +5,6 @@ package network
import (
"errors"
"fmt"
"log"
"net"
"sort"
"strings"
@@ -13,6 +12,7 @@ import (
"github.com/godbus/dbus/v5"
"github.com/google/uuid"
"rhemawavetech.com/rhemawave/internal/logger"
)
// --- D-Bus NetworkManager Constants ---
@@ -30,11 +30,11 @@ const (
APFlagsPrivacy uint32 = 0x00000001 // Equivalent to NM_802_11_AP_FLAGS_PRIVACY
// Device states (from NM spec)
nmDeviceStateUnknown uint32 = 0
nmDeviceStateUnmanaged uint32 = 10
nmDeviceStateUnavailable uint32 = 20
nmDeviceStateDisconnected uint32 = 30
nmDeviceStateFailed uint32 = 120
// nmDeviceStateUnknown uint32 = 0
nmDeviceStateUnmanaged uint32 = 10
nmDeviceStateUnavailable uint32 = 20
// nmDeviceStateDisconnected uint32 = 30
nmDeviceStateFailed uint32 = 120
// AP Security Flags (from NM_802_11_AP_SEC_*)
APFlagsWpaPsk uint32 = 0x00000100 // WPA-Personal
@@ -105,31 +105,44 @@ type AccessPoint struct {
// New creates a new network Manager and connects to the system D-Bus.
func New() (*Manager, error) {
logger.Info("[NET-001] Initializing NetworkManager client")
logger.Debug("[NET-002] Connecting to system D-Bus")
conn, err := dbus.ConnectSystemBus()
if err != nil {
logger.Error("failed to connect to system bus: %v", err)
return nil, fmt.Errorf("failed to connect to system bus: %w", err)
}
nmObject := conn.Object(nmService, nmPath)
logger.Debug("network manager created")
return &Manager{conn: conn, nmObject: nmObject}, nil
}
// Conn returns the underlying dbus.Conn for advanced queries.
func (m *Manager) Conn() *dbus.Conn {
logger.Debug("[NET-010] Returning underlying D-Bus connection")
logger.Debug("Conn() returning m.conn")
return m.conn
}
// Close disconnects from the D-Bus.
func (m *Manager) Close() {
logger.Info("[NET-020] Closing NetworkManager client")
logger.Debug("Disconnecting from the D-Bus")
if m.conn != nil {
m.conn.Close()
logger.Debug("Disconnected")
}
logger.Debug("Nothing to disconnect!")
}
// FindDevices scans the system for all available network devices (Ethernet and Wi-Fi).
func (m *Manager) FindDevices() error {
logger.Info("[NET-030] Starting network device discovery")
logger.Debug("Searching for network devices")
var devicePaths []dbus.ObjectPath
call := m.nmObject.Call(nmInterface+".GetDevices", 0)
if call.Err != nil {
logger.Error("GetDevices D-Bus call failed: %w", call.Err)
return fmt.Errorf("GetDevices D-Bus call failed: %w", call.Err)
}
if err := call.Store(&devicePaths); err != nil {
@@ -141,12 +154,12 @@ func (m *Manager) FindDevices() error {
deviceObj := m.conn.Object(nmService, path)
typeVariant, err := deviceObj.GetProperty(nmDeviceInterface + ".DeviceType")
if err != nil {
log.Printf("network: Skipping device %s, could not get DeviceType: %v", path, err)
logger.Warning("[NET-031] Skipping device %s because DeviceType could not be read: %v", path, err)
continue
}
deviceType, ok := typeVariant.Value().(uint32)
if !ok {
log.Printf("network: Skipping device %s, invalid DeviceType", path)
logger.Warning("[NET-032] Skipping device %s because DeviceType was invalid", path)
continue
}
@@ -165,22 +178,22 @@ func (m *Manager) FindDevices() error {
// Safely get Interface property
ifaceVariant, err := deviceObj.GetProperty(nmDeviceInterface + ".Interface")
if err != nil {
log.Printf("network: Skipping device %s, could not get Interface: %v", path, err)
logger.Warning("[NET-033] Skipping device %s because Interface property could not be read: %v", path, err)
continue
}
if newDevice.InterfaceName, ok = ifaceVariant.Value().(string); !ok {
log.Printf("network: Skipping device %s, invalid Interface", path)
logger.Warning("[NET-034] Skipping device %s because Interface property was invalid", path)
continue
}
// Safely get State property
stateVariant, err := deviceObj.GetProperty(nmDeviceInterface + ".State")
if err != nil {
log.Printf("network: Skipping device %s, could not get State: %v", path, err)
logger.Warning("[NET-035] Skipping device %s because State property could not be read: %v", path, err)
continue
}
if newDevice.State, ok = stateVariant.Value().(uint32); !ok {
log.Printf("network: Skipping device %s, invalid State", path)
logger.Warning("[NET-036] Skipping device %s because State property was invalid", path)
continue
}
@@ -191,6 +204,7 @@ func (m *Manager) FindDevices() error {
// CheckInternetConnection performs a check for an active internet connection.
func (m *Manager) CheckInternetConnection() (*ConnectionStatus, error) {
logger.Debug("[NET-040] Checking internet connectivity")
if err := m.FindDevices(); err != nil {
return &ConnectionStatus{StatusError, "Failed to scan devices"}, err
}
@@ -221,6 +235,7 @@ func (m *Manager) CheckInternetConnection() (*ConnectionStatus, error) {
// StartScan performs a Wi-Fi scan asynchronously. The optional stopChan can be used to abort.
func (m *Manager) StartScan(resultsChan chan<- []AccessPoint, errorChan chan<- error, stopChan <-chan struct{}) {
logger.Info("[NET-050] Starting Wi‑Fi scan")
var wifiDevice *Device
for i := range m.Devices {
if m.Devices[i].Type == TypeWifi {
@@ -289,12 +304,13 @@ func (m *Manager) StartScan(resultsChan chan<- []AccessPoint, errorChan chan<- e
// scanAccessPoints filters and sorts the raw list of D-Bus AP paths.
func (m *Manager) scanAccessPoints(apPaths []dbus.ObjectPath) ([]AccessPoint, error) {
logger.Debug("[NET-060] Processing %d access points", len(apPaths))
tempNetworkMap := make(map[string]AccessPoint)
for _, apPath := range apPaths {
apObj := m.conn.Object(nmService, apPath)
props, err := m.getAllProperties(apObj, nmAPInterface)
if err != nil {
log.Printf("network: Failed to get properties for AP %s: %v", apPath, err)
logger.Warning("[NET-061] Failed to read access point properties for %s: %v", apPath, err)
continue
}
@@ -366,6 +382,7 @@ func (m *Manager) scanAccessPoints(apPaths []dbus.ObjectPath) ([]AccessPoint, er
// Connect attempts to connect a Wi-Fi device to a given access point.
func (m *Manager) Connect(wifiDevice Device, ap AccessPoint, passphrase string) error {
logger.Info("[NET-070] Connection requested for SSID %q using adapter %q", ap.SSID, wifiDevice.InterfaceName)
if wifiDevice.Type != TypeWifi {
return fmt.Errorf("cannot connect: provided device is not a Wi-Fi device")
}
@@ -412,11 +429,11 @@ func (m *Manager) Connect(wifiDevice Device, ap AccessPoint, passphrase string)
if err != nil {
// THIS IS THE LOG YOU NEED TO SEE IN SSH
log.Printf("NETWORK MANAGER FAIL: %v", err)
logger.Error("[NET-071] NetworkManager rejected the connection request: %v", err)
return fmt.Errorf("AddAndActivateConnection failed: %w", err)
}
log.Printf("Connection created: %s, Active path: %s", connectionPath, activeConnectionPath)
logger.Info("[NET-072] Connection created successfully. Connection=%s Active=%s", connectionPath, activeConnectionPath)
// Wait for the connection to be fully established
if _, err := m.WaitForInternet(30*time.Second, 5*time.Second); err != nil {
@@ -428,6 +445,7 @@ func (m *Manager) Connect(wifiDevice Device, ap AccessPoint, passphrase string)
// pingTest with a short timeout to prevent the UI loop from hanging
func pingTest() bool {
logger.Debug("[NET-080] Beginning internet reachability test")
targets := []string{
"1.1.1.1:53", // Cloudflare DNS
"8.8.8.8:53", // Google DNS
@@ -448,6 +466,7 @@ func pingTest() bool {
// getAllProperties is a helper to fetch all properties for a D-Bus object interface.
func (m *Manager) getAllProperties(obj dbus.BusObject, iface string) (map[string]dbus.Variant, error) {
logger.Debug("[NET-090] Fetching all D‑Bus properties for interface %s", iface)
var props map[string]dbus.Variant
call := obj.Call("org.freedesktop.DBus.Properties.GetAll", 0, iface)
if call.Err != nil {
@@ -463,6 +482,7 @@ func (m *Manager) getAllProperties(obj dbus.BusObject, iface string) (map[string
// or until maxWait elapses. When it first sees "up", it requires that state
// to be stable for at least 'stableFor' before returning success to avoid flapping.
func (m *Manager) WaitForInternet(maxWait, stableFor time.Duration) (*ConnectionStatus, error) {
logger.Info("[NET-100] Waiting for internet connectivity (maxWait=%s stableFor=%s)", maxWait, stableFor)
deadline := time.Now().Add(maxWait)
var lastErr error
var lastStatus *ConnectionStatus