Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

cmd/reticulum-go: use slog for logging #1

Open
wants to merge 3 commits into
base: main
Choose a base branch
from
Open

cmd/reticulum-go: use slog for logging #1

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
d185806
cmd/reticulum-go: use slog for logging
holiman Jan 17, 2025
4691a7f
pkg/transport: log -> slog conversions in progress
holiman Jan 31, 2025
54f2418
pkg: replace log with slog
holiman Feb 21, 2025
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
157 changes: 73 additions & 84 deletions cmd/reticulum-go/main.go
View file
Open in desktop

Large diffs are not rendered by default.

61 changes: 33 additions & 28 deletions pkg/announce/announce.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -4,9 +4,10 @@ import (
"crypto/rand"
"crypto/sha256"
"encoding/binary"
"encoding/hex"
"errors"
"fmt"
"log"
"log/slog"
"sync"
"time"

Expand Down Expand Up @@ -113,34 +114,32 @@ func (a *Announce) Propagate(interfaces []common.NetworkInterface) error {
a.mutex.RLock()
defer a.mutex.RUnlock()

log.Printf("[DEBUG-7] Propagating announce across %d interfaces", len(interfaces))
slog.Debug("Propagating announce", "#interfaces", len(interfaces))

var packet []byte
if a.packet != nil {
log.Printf("[DEBUG-7] Using cached packet (%d bytes)", len(a.packet))
packet = a.packet
slog.Debug("Using cached packet", "size", len(a.packet))
} else {
log.Printf("[DEBUG-7] Creating new packet")
packet = a.CreatePacket()
a.packet = packet
slog.Debug("Creating new packet")
a.packet = a.CreatePacket()
}
var packet = a.packet

for _, iface := range interfaces {
if !iface.IsEnabled() {
log.Printf("[DEBUG-7] Skipping disabled interface: %s", iface.GetName())
slog.Debug("Skipping disabled interface", "interface", iface.GetName())
continue
}
if !iface.GetBandwidthAvailable() {
log.Printf("[DEBUG-7] Skipping interface with insufficient bandwidth: %s", iface.GetName())
slog.Debug("Skipping interface with insufficient bandwidth:", "interface", iface.GetName())
continue
}

log.Printf("[DEBUG-7] Sending announce on interface %s", iface.GetName())
slog.Debug("Sending announce on interface", "interface", iface.GetName())
if err := iface.Send(packet, ""); err != nil {
log.Printf("[DEBUG-7] Failed to send on interface %s: %v", iface.GetName(), err)
slog.Warn("Failed to send on interface", "interface", iface.GetName(), "err", err)
return fmt.Errorf("failed to propagate on interface %s: %w", iface.GetName(), err)
}
log.Printf("[DEBUG-7] Successfully sent announce on interface %s", iface.GetName())
slog.Debug("Successfully sent announce", "interface", iface.GetName())
}

return nil
Expand All @@ -167,12 +166,12 @@ func (a *Announce) HandleAnnounce(data []byte) error {
a.mutex.Lock()
defer a.mutex.Unlock()

log.Printf("[DEBUG-7] Handling announce packet of %d bytes", len(data))
slog.Debug("Handling announce packet", "length", len(data))

// Minimum packet size validation (header(2) + desthash(16) + enckey(32) + signkey(32) + namehash(10) +
// randomhash(10) + signature(64) + min app data(3))
if len(data) < 169 {
log.Printf("[DEBUG-7] Invalid announce data length: %d bytes", len(data))
slog.Debug("Invalid announce data length", "length", len(data))
return errors.New("invalid announce data length")
}

Expand All @@ -187,13 +186,15 @@ func (a *Announce) HandleAnnounce(data []byte) error {
signature := data[102:166]
appData := data[166:]

log.Printf("[DEBUG-7] Announce fields: destHash=%x, encKey=%x, signKey=%x",
destHash, encKey, signKey)
log.Printf("[DEBUG-7] Name hash=%x, random hash=%x", nameHash, randomHash)
slog.Debug("Announce fields", "destHash", hex.EncodeToString(destHash),
"encKey", hex.EncodeToString(encKey),
"signKey", hex.EncodeToString(signKey),
"nameHash", hex.EncodeToString(nameHash),
"randomHash", hex.EncodeToString(randomHash))

// Validate hop count
if hopCount > MAX_HOPS {
log.Printf("[DEBUG-7] Announce exceeded max hops: %d", hopCount)
slog.Debug("Announce exceeded max hops: %d", hopCount)
return errors.New("announce exceeded maximum hop count")
}

Expand Down Expand Up @@ -287,7 +288,7 @@ func (a *Announce) CreatePacket() []byte {
// Create validation data for signature
validationData := make([]byte, 0)
validationData = append(validationData, a.destinationHash...)
validationData = append(validationData, pubKey[:32]...) // Encryption key
validationData = append(validationData, pubKey[:32]...) // Encryption key
validationData = append(validationData, pubKey[32:]...) // Signing key
validationData = append(validationData, nameHash[:10]...)
validationData = append(validationData, randomBytes...)
Expand Down Expand Up @@ -336,11 +337,14 @@ func NewAnnouncePacket(pubKey []byte, appData []byte, announceID []byte) *Announ

// NewAnnounce creates a new announce packet for a destination
func NewAnnounce(identity *identity.Identity, appData []byte, ratchetID []byte, pathResponse bool, config *common.ReticulumConfig) (*Announce, error) {
log.Printf("[DEBUG-7] Creating new announce: appDataLen=%d, hasRatchet=%v, pathResponse=%v",
len(appData), ratchetID != nil, pathResponse)

slog.Debug("Creating new announce",
"appDataLen", len(appData),
"hasRatchet", ratchetID != nil,
"pathResponse", pathResponse)

if identity == nil {
log.Printf("[DEBUG-7] Error: nil identity provided")
slog.Warn("Error: nil identity provided")
return nil, errors.New("identity cannot be nil")
}

Expand All @@ -349,7 +353,7 @@ func NewAnnounce(identity *identity.Identity, appData []byte, ratchetID []byte,
}

destHash := identity.Hash()
log.Printf("[DEBUG-7] Generated destination hash: %x", destHash)
slog.Debug("Generated destination", "hash", hex.EncodeToString(destHash))

a := &Announce{
identity: identity,
Expand All @@ -363,16 +367,17 @@ func NewAnnounce(identity *identity.Identity, appData []byte, ratchetID []byte,
config: config,
}

log.Printf("[DEBUG-7] Created announce object: destHash=%x, hops=%d",
a.destinationHash, a.hops)

// Create initial packet
packet := a.CreatePacket()
a.packet = packet

// Generate hash
hash := a.Hash()
log.Printf("[DEBUG-7] Generated announce hash: %x", hash)

slog.Debug("Created announce object",
"destHash", hex.EncodeToString(a.destinationHash),
"hops", a.hops,
"announce hash", hex.EncodeToString(hash))

return a, nil
}
Expand Down
76 changes: 35 additions & 41 deletions pkg/destination/destination.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -3,9 +3,9 @@ package destination
import (
"crypto/sha256"
"encoding/binary"
"encoding/hex"
"errors"
"fmt"
"log"
"log/slog"
"sync"

"github.com/Sudo-Ivan/reticulum-go/pkg/common"
Expand Down Expand Up @@ -80,15 +80,10 @@ type Destination struct {
requestHandlers map[string]*RequestHandler
}

func debugLog(level int, format string, v ...interface{}) {
log.Printf("[DEBUG-%d] %s", level, fmt.Sprintf(format, v...))
}

func New(id *identity.Identity, direction byte, destType byte, appName string, aspects ...string) (*Destination, error) {
debugLog(DEBUG_INFO, "Creating new destination: app=%s type=%d direction=%d", appName, destType, direction)

slog.Info("Creating new destination", "app", appName, "type", destType, "direction", direction)
if id == nil {
debugLog(DEBUG_ERROR, "Cannot create destination: identity is nil")
slog.Error("Cannot create destination: identity is nil")
return nil, errors.New("identity cannot be nil")
}

Expand All @@ -107,26 +102,24 @@ func New(id *identity.Identity, direction byte, destType byte, appName string, a

// Generate destination hash
d.hashValue = d.calculateHash()
debugLog(DEBUG_VERBOSE, "Created destination with hash: %x", d.hashValue)
slog.Debug("Created destination", "hash", hex.EncodeToString(d.hashValue))

return d, nil
}

func (d *Destination) calculateHash() []byte {
debugLog(DEBUG_TRACE, "Calculating hash for destination %s", d.ExpandName())

nameHash := sha256.Sum256([]byte(d.ExpandName()))
identityHash := sha256.Sum256(d.identity.GetPublicKey())

debugLog(DEBUG_ALL, "Name hash: %x", nameHash)
debugLog(DEBUG_ALL, "Identity hash: %x", identityHash)

combined := append(nameHash[:], identityHash[:]...)
finalHash := sha256.Sum256(combined)

truncated := finalHash[:16]
debugLog(DEBUG_VERBOSE, "Calculated destination hash: %x", truncated)

var (
nameHash = sha256.Sum256([]byte(d.ExpandName()))
identityHash = sha256.Sum256(d.identity.GetPublicKey())
combined = append(nameHash[:], identityHash[:]...)
finalHash = sha256.Sum256(combined)
truncated = finalHash[:16]
)
slog.Debug("Calculated hashes",
"destination", d.ExpandName(),
"namehash", hex.EncodeToString(nameHash[:]),
"identityHash", hex.EncodeToString(identityHash[:]),
"hash", hex.EncodeToString(truncated))
return truncated
}

Expand All @@ -142,11 +135,11 @@ func (d *Destination) Announce(appData []byte) error {
d.mutex.Lock()
defer d.mutex.Unlock()

log.Printf("[DEBUG-4] Creating announce packet for destination %s", d.ExpandName())
slog.Info("Creating announce packet", "destination", d.ExpandName())

// If no specific appData provided, use default
if appData == nil {
log.Printf("[DEBUG-4] Using default app data for announce")
slog.Info("Using default app data for announce")
appData = d.defaultAppData
}

Expand All @@ -159,30 +152,32 @@ func (d *Destination) Announce(appData []byte) error {

// Add destination hash (16 bytes)
packet = append(packet, d.hashValue...)
log.Printf("[DEBUG-4] Added destination hash %x to announce", d.hashValue[:8])

// Add identity public key (32 bytes)
pubKey := d.identity.GetPublicKey()
packet = append(packet, pubKey...)
log.Printf("[DEBUG-4] Added public key %x to announce", pubKey[:8])

// Add app data with length prefix
appDataLen := make([]byte, 2)
binary.BigEndian.PutUint16(appDataLen, uint16(len(appData)))
packet = append(packet, appDataLen...)
packet = append(packet, appData...)
log.Printf("[DEBUG-4] Added %d bytes of app data to announce", len(appData))

slog.Debug("Building announce",
"desthash", hex.EncodeToString(d.hashValue[:8]),
"pubkey", hex.EncodeToString(pubKey[:8]),
"appdata length", len(appData))

// Add ratchet data if enabled
if d.ratchetsEnabled {
log.Printf("[DEBUG-4] Adding ratchet data to announce")
slog.Info("Adding ratchet data to announce")
ratchetKey := d.identity.GetCurrentRatchetKey()
if ratchetKey == nil {
log.Printf("[DEBUG-3] Failed to get current ratchet key")
slog.Warn("Failed to get current ratchet key")
return errors.New("failed to get current ratchet key")
}
packet = append(packet, ratchetKey...)
log.Printf("[DEBUG-4] Added ratchet key %x to announce", ratchetKey[:8])
slog.Info("Added ratchet announce", "key", hex.EncodeToString(ratchetKey[:8]))
}

// Sign the announce packet (64 bytes)
Expand All @@ -192,10 +187,9 @@ func (d *Destination) Announce(appData []byte) error {
}
signature := d.identity.Sign(signData)
packet = append(packet, signature...)
log.Printf("[DEBUG-4] Added signature to announce packet (total size: %d bytes)", len(packet))

// Send announce packet through transport
log.Printf("[DEBUG-4] Sending announce packet through transport layer")
slog.Info("[DEBUG-4] Sending announce packet through transport layer", "size", len(packet))
return transport.SendAnnounce(packet)
}

Expand Down Expand Up @@ -317,32 +311,32 @@ func (d *Destination) DeregisterRequestHandler(path string) bool {

func (d *Destination) Encrypt(plaintext []byte) ([]byte, error) {
if d.destType == PLAIN {
log.Printf("[DEBUG-4] Using plaintext transmission for PLAIN destination")
slog.Info("Using plaintext transmission for PLAIN destination")
return plaintext, nil
}

if d.identity == nil {
log.Printf("[DEBUG-3] Cannot encrypt: no identity available")
slog.Warn("Cannot encrypt: no identity available")
return nil, errors.New("no identity available for encryption")
}

log.Printf("[DEBUG-4] Encrypting %d bytes for destination type %d", len(plaintext), d.destType)
slog.Info("Encrypting data ", "size", len(plaintext), "destination type", d.destType)

switch d.destType {
case SINGLE:
recipientKey := d.identity.GetPublicKey()
log.Printf("[DEBUG-4] Encrypting for single recipient with key %x", recipientKey[:8])
slog.Info("Encrypting for single recipient", "key", hex.EncodeToString(recipientKey[:8]))
return d.identity.Encrypt(plaintext, recipientKey)
case GROUP:
key := d.identity.GetCurrentRatchetKey()
if key == nil {
log.Printf("[DEBUG-3] Cannot encrypt: no ratchet key available")
slog.Warn("Cannot encrypt: no ratchet key available")
return nil, errors.New("no ratchet key available")
}
log.Printf("[DEBUG-4] Encrypting for group with ratchet key %x", key[:8])
slog.Info("Encrypting for group with ratchet", "key", hex.EncodeToString(key[:8]))
return d.identity.EncryptWithHMAC(plaintext, key)
default:
log.Printf("[DEBUG-3] Unsupported destination type %d for encryption", d.destType)
slog.Warn("Unsupported destination type for encryption", "type", d.destType)
return nil, errors.New("unsupported destination type for encryption")
}
}
Expand Down
Loading