4 Commits

Author SHA1 Message Date
f097bb3241 security: use net.JoinHostPort instead of fmt.Sprintf
Some checks failed
Benchmark GC Performance / benchmark (push) Successful in 1m19s
Run Gosec / tests (push) Successful in 48s
Go Revive Lint / lint (push) Successful in 34s
Go Build Multi-Platform / build (amd64, darwin) (push) Failing after 31s
Go Build Multi-Platform / build (amd64, windows) (push) Failing after 34s
Go Build Multi-Platform / build (arm, freebsd) (push) Failing after 29s
Go Build Multi-Platform / build (arm, linux) (push) Failing after 27s
Go Build Multi-Platform / Create Release (push) Has been skipped
Go Test Multi-Platform / Test (ubuntu-latest, arm64) (push) Successful in 48s
Go Test Multi-Platform / Test (ubuntu-latest, amd64) (push) Successful in 1m28s
Go Build Multi-Platform / build (amd64, freebsd) (push) Failing after 27s
Go Build Multi-Platform / build (amd64, linux) (push) Failing after 27s
Go Build Multi-Platform / build (arm, windows) (push) Failing after 27s
Go Build Multi-Platform / build (arm64, darwin) (push) Failing after 27s
Go Build Multi-Platform / build (arm64, freebsd) (push) Failing after 27s
Performance Monitor / performance-monitor (push) Successful in 2m40s
Go Build Multi-Platform / build (arm64, windows) (push) Failing after 25s
Go Build Multi-Platform / build (arm64, linux) (push) Failing after 27s
Go Test Multi-Platform / Test (macos-latest, amd64) (push) Has been cancelled
Go Test Multi-Platform / Test (windows-latest, amd64) (push) Has been cancelled
Go Test Multi-Platform / Test (macos-latest, arm64) (push) Has been cancelled
2025-11-09 00:05:36 -06:00
22fc5093db perf: combine multiple append calls in transport 2025-11-09 00:05:31 -06:00
fc95e54b2e update: Makefile with debug build target and update help text
Some checks failed
Go Build Multi-Platform / build (amd64, freebsd) (push) Failing after 55s
Go Build Multi-Platform / build (amd64, darwin) (push) Failing after 58s
Go Build Multi-Platform / build (amd64, linux) (push) Failing after 54s
Benchmark GC Performance / benchmark (push) Successful in 1m28s
Go Build Multi-Platform / build (arm, freebsd) (push) Failing after 48s
Go Build Multi-Platform / build (arm, linux) (push) Failing after 46s
Go Build Multi-Platform / build (arm64, darwin) (push) Failing after 29s
Go Build Multi-Platform / build (arm64, windows) (push) Failing after 28s
Go Test Multi-Platform / Test (ubuntu-latest, amd64) (push) Successful in 1m32s
Go Test Multi-Platform / Test (macos-latest, amd64) (push) Has been cancelled
Go Test Multi-Platform / Test (windows-latest, amd64) (push) Has been cancelled
Go Test Multi-Platform / Test (macos-latest, arm64) (push) Has been cancelled
Go Build Multi-Platform / build (amd64, windows) (push) Failing after 50s
Go Build Multi-Platform / build (arm, windows) (push) Failing after 36s
Go Build Multi-Platform / build (arm64, linux) (push) Failing after 38s
Go Build Multi-Platform / build (arm64, freebsd) (push) Failing after 40s
Go Test Multi-Platform / Test (ubuntu-latest, arm64) (push) Successful in 46s
Run Gosec / tests (push) Successful in 51s
Go Build Multi-Platform / Create Release (push) Has been skipped
Go Revive Lint / lint (push) Successful in 36s
Performance Monitor / performance-monitor (push) Has been cancelled
2025-11-09 00:01:19 -06:00
636d400f1e refactor: migrate to structured debug logging 2025-11-09 00:00:55 -06:00
7 changed files with 218 additions and 261 deletions

View File

@@ -1,7 +1,8 @@
GOCMD=go
GOBUILD=$(GOCMD) build
GOBUILD_EXPERIMENTAL=GOEXPERIMENT=greenteagc $(GOCMD) build
GOBUILD_DEBUG=$(GOCMD) build
GOBUILD_RELEASE=CGO_ENABLED=0 $(GOCMD) build -ldflags="-s -w"
GOBUILD_EXPERIMENTAL=GOEXPERIMENT=greenteagc $(GOCMD) build
GOCLEAN=$(GOCMD) clean
GOTEST=$(GOCMD) test
GOGET=$(GOCMD) get
@@ -15,13 +16,17 @@ MAIN_PACKAGE=./cmd/reticulum-go
ALL_PACKAGES=$$(go list ./... | grep -v /vendor/)
.PHONY: all build build-experimental experimental release lint bench bench-experimental bench-compare clean test coverage deps help tinygo-build tinygo-wasm
.PHONY: all build build-experimental experimental release debug lint bench bench-experimental bench-compare clean test coverage deps help tinygo-build tinygo-wasm run
all: clean deps build test
build:
@mkdir -p $(BUILD_DIR)
$(GOBUILD) -o $(BUILD_DIR)/$(BINARY_NAME) $(MAIN_PACKAGE)
$(GOBUILD_RELEASE) -o $(BUILD_DIR)/$(BINARY_NAME) $(MAIN_PACKAGE)
debug:
@mkdir -p $(BUILD_DIR)
$(GOBUILD_DEBUG) -o $(BUILD_DIR)/$(BINARY_NAME) $(MAIN_PACKAGE)
build-experimental:
@mkdir -p $(BUILD_DIR)
@@ -56,7 +61,11 @@ coverage:
$(GOCMD) tool cover -html=coverage.out
deps:
@GOPROXY=$${GOPROXY:-https://proxy.golang.org,direct}; \
export GOPROXY; \
$(GOMOD) download
@GOPROXY=$${GOPROXY:-https://proxy.golang.org,direct}; \
export GOPROXY; \
$(GOMOD) verify
build-linux:
@@ -103,7 +112,7 @@ build-riscv:
build-all: build-linux build-windows build-darwin build-freebsd build-openbsd build-netbsd build-arm build-riscv
run:
@./$(BUILD_DIR)/$(BINARY_NAME)
$(GOCMD) run $(MAIN_PACKAGE)
tinygo-build:
@mkdir -p $(BUILD_DIR)
@@ -119,10 +128,11 @@ install:
help:
@echo "Available targets:"
@echo " all - Clean, download dependencies, build and test"
@echo " build - Build binary"
@echo " build - Build release binary (no debug symbols, static)"
@echo " debug - Build debug binary"
@echo " build-experimental - Build binary with experimental features (GOEXPERIMENT=greenteagc)"
@echo " experimental - Alias for build-experimental"
@echo " release - Build stripped static binary for release"
@echo " release - Build stripped static binary for release (alias for build)"
@echo " lint - Run revive linter"
@echo " bench - Run benchmarks with standard GC"
@echo " bench-experimental - Run benchmarks with experimental GC"
@@ -140,7 +150,7 @@ help:
@echo " build-arm - Build for ARM architectures (arm, arm64)"
@echo " build-riscv - Build for RISC-V architecture (riscv64)"
@echo " build-all - Build for all platforms and architectures"
@echo " run - Run reticulum binary"
@echo " run - Run with go run"
@echo " tinygo-build - Build binary with TinyGo compiler"
@echo " tinygo-wasm - Build WebAssembly binary with TinyGo compiler"
@echo " install - Install dependencies"

View File

@@ -4,11 +4,11 @@ import (
"crypto/sha256"
"errors"
"fmt"
"log"
"sync"
"github.com/Sudo-Ivan/reticulum-go/pkg/announce"
"github.com/Sudo-Ivan/reticulum-go/pkg/common"
"github.com/Sudo-Ivan/reticulum-go/pkg/debug"
"github.com/Sudo-Ivan/reticulum-go/pkg/identity"
"github.com/Sudo-Ivan/reticulum-go/pkg/transport"
)
@@ -36,15 +36,6 @@ const (
RATCHET_COUNT = 512 // Default number of retained ratchet keys
RATCHET_INTERVAL = 1800 // Minimum interval between ratchet rotations in seconds
// Debug levels
DEBUG_CRITICAL = 1 // Critical errors
DEBUG_ERROR = 2 // Non-critical errors
DEBUG_INFO = 3 // Important information
DEBUG_VERBOSE = 4 // Detailed information
DEBUG_TRACE = 5 // Very detailed tracing
DEBUG_PACKETS = 6 // Packet-level details
DEBUG_ALL = 7 // Everything
)
type PacketCallback = common.PacketCallback
@@ -86,15 +77,11 @@ 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, transport *transport.Transport, aspects ...string) (*Destination, error) {
debugLog(DEBUG_INFO, "Creating new destination: app=%s type=%d direction=%d", appName, destType, direction)
debug.Log(debug.DEBUG_INFO, "Creating new destination", "app", appName, "type", destType, "direction", direction)
if id == nil {
debugLog(DEBUG_ERROR, "Cannot create destination: identity is nil")
debug.Log(debug.DEBUG_ERROR, "Cannot create destination: identity is nil")
return nil, errors.New("identity cannot be nil")
}
@@ -114,7 +101,7 @@ func New(id *identity.Identity, direction byte, destType byte, appName string, t
// Generate destination hash
d.hashValue = d.calculateHash()
debugLog(DEBUG_VERBOSE, "Created destination with hash: %x", d.hashValue)
debug.Log(debug.DEBUG_VERBOSE, "Created destination with hash", "hash", fmt.Sprintf("%x", d.hashValue))
return d, nil
}
@@ -122,10 +109,10 @@ func New(id *identity.Identity, direction byte, destType byte, appName string, t
// FromHash creates a destination from a known hash (e.g., from an announce).
// This is used by clients to create destination objects for servers they've discovered.
func FromHash(hash []byte, id *identity.Identity, destType byte, transport *transport.Transport) (*Destination, error) {
debugLog(DEBUG_INFO, "Creating destination from hash: %x", hash)
debug.Log(debug.DEBUG_INFO, "Creating destination from hash", "hash", fmt.Sprintf("%x", hash))
if id == nil {
debugLog(DEBUG_ERROR, "Cannot create destination: identity is nil")
debug.Log(debug.DEBUG_ERROR, "Cannot create destination: identity is nil")
return nil, errors.New("identity cannot be nil")
}
@@ -142,12 +129,12 @@ func FromHash(hash []byte, id *identity.Identity, destType byte, transport *tran
requestHandlers: make(map[string]*RequestHandler),
}
debugLog(DEBUG_VERBOSE, "Created destination from hash: %x", hash)
debug.Log(debug.DEBUG_VERBOSE, "Created destination from hash", "hash", fmt.Sprintf("%x", hash))
return d, nil
}
func (d *Destination) calculateHash() []byte {
debugLog(DEBUG_TRACE, "Calculating hash for destination %s", d.ExpandName())
debug.Log(debug.DEBUG_TRACE, "Calculating hash for destination", "name", d.ExpandName())
// destination_hash = SHA256(name_hash_10bytes + identity_hash_16bytes)[:16]
// Identity hash is the truncated hash of the public key (16 bytes)
@@ -157,8 +144,8 @@ func (d *Destination) calculateHash() []byte {
nameHashFull := sha256.Sum256([]byte(d.ExpandName()))
nameHash10 := nameHashFull[:10] // Only use 10 bytes
debugLog(DEBUG_ALL, "Identity hash: %x", identityHash)
debugLog(DEBUG_ALL, "Name hash (10 bytes): %x", nameHash10)
debug.Log(debug.DEBUG_ALL, "Identity hash", "hash", fmt.Sprintf("%x", identityHash))
debug.Log(debug.DEBUG_ALL, "Name hash (10 bytes)", "hash", fmt.Sprintf("%x", nameHash10))
// Concatenate name_hash (10 bytes) + identity_hash (16 bytes) = 26 bytes
combined := append(nameHash10, identityHash...)
@@ -167,7 +154,7 @@ func (d *Destination) calculateHash() []byte {
finalHashFull := sha256.Sum256(combined)
finalHash := finalHashFull[:16]
debugLog(DEBUG_VERBOSE, "Calculated destination hash: %x", finalHash)
debug.Log(debug.DEBUG_VERBOSE, "Calculated destination hash", "hash", fmt.Sprintf("%x", finalHash))
return finalHash
}
@@ -184,7 +171,7 @@ func (d *Destination) Announce(appData []byte) error {
d.mutex.Lock()
defer d.mutex.Unlock()
log.Printf("[DEBUG-4] Announcing destination %s", d.ExpandName())
debug.Log(debug.DEBUG_VERBOSE, "Announcing destination", "name", d.ExpandName())
if appData == nil {
appData = d.defaultAppData
@@ -203,27 +190,27 @@ func (d *Destination) Announce(appData []byte) error {
}
// Send announce packet to all interfaces
log.Printf("[DEBUG-4] Sending announce packet to all interfaces")
debug.Log(debug.DEBUG_VERBOSE, "Sending announce packet to all interfaces")
if d.transport == nil {
return errors.New("transport not initialized")
}
interfaces := d.transport.GetInterfaces()
log.Printf("[DEBUG-7] Got %d interfaces from transport", len(interfaces))
debug.Log(debug.DEBUG_ALL, "Got interfaces from transport", "count", len(interfaces))
var lastErr error
for name, iface := range interfaces {
log.Printf("[DEBUG-7] Checking interface %s: enabled=%v, online=%v", name, iface.IsEnabled(), iface.IsOnline())
debug.Log(debug.DEBUG_ALL, "Checking interface", "name", name, "enabled", iface.IsEnabled(), "online", iface.IsOnline())
if iface.IsEnabled() && iface.IsOnline() {
log.Printf("[DEBUG-7] Sending announce to interface %s (%d bytes)", name, len(packet))
debug.Log(debug.DEBUG_ALL, "Sending announce to interface", "name", name, "bytes", len(packet))
if err := iface.Send(packet, ""); err != nil {
log.Printf("[ERROR] Failed to send announce on interface %s: %v", name, err)
debug.Log(debug.DEBUG_ERROR, "Failed to send announce on interface", "name", name, "error", err)
lastErr = err
} else {
log.Printf("[DEBUG-7] Successfully sent announce to interface %s", name)
debug.Log(debug.DEBUG_ALL, "Successfully sent announce to interface", "name", name)
}
} else {
log.Printf("[DEBUG-7] Skipping interface %s (not enabled or not online)", name)
debug.Log(debug.DEBUG_ALL, "Skipping interface", "name", name, "reason", "not enabled or not online")
}
}
@@ -238,7 +225,7 @@ func (d *Destination) AcceptsLinks(accepts bool) {
// Register with transport if accepting links
if accepts && d.transport != nil {
d.transport.RegisterDestination(d.hashValue, d)
debugLog(DEBUG_VERBOSE, "Destination %x registered with transport for link requests", d.hashValue)
debug.Log(debug.DEBUG_VERBOSE, "Destination registered with transport for link requests", "hash", fmt.Sprintf("%x", d.hashValue))
}
}
@@ -255,19 +242,19 @@ func (d *Destination) GetLinkCallback() common.LinkEstablishedCallback {
}
func (d *Destination) HandleIncomingLinkRequest(linkID []byte, transport interface{}, networkIface common.NetworkInterface) error {
debugLog(DEBUG_INFO, "Handling incoming link request for destination %x", d.GetHash())
debug.Log(debug.DEBUG_INFO, "Handling incoming link request for destination", "hash", fmt.Sprintf("%x", d.GetHash()))
// Import link package here to avoid circular dependency at package level
// We'll use dynamic import by having the caller create the link
// For now, just call the callback with a placeholder
if d.linkCallback != nil {
debugLog(DEBUG_INFO, "Calling link established callback")
debug.Log(debug.DEBUG_INFO, "Calling link established callback")
// Pass linkID as the link object for now
// The callback will need to handle creating the actual link
d.linkCallback(linkID)
} else {
debugLog(DEBUG_VERBOSE, "No link callback set")
debug.Log(debug.DEBUG_VERBOSE, "No link callback set")
}
return nil
@@ -379,32 +366,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")
debug.Log(debug.DEBUG_VERBOSE, "Using plaintext transmission for PLAIN destination")
return plaintext, nil
}
if d.identity == nil {
log.Printf("[DEBUG-3] Cannot encrypt: no identity available")
debug.Log(debug.DEBUG_INFO, "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)
debug.Log(debug.DEBUG_VERBOSE, "Encrypting bytes for destination", "bytes", len(plaintext), "destType", d.destType)
switch d.destType {
case SINGLE:
recipientKey := d.identity.GetPublicKey()
log.Printf("[DEBUG-4] Encrypting for single recipient with key %x", recipientKey[:8])
debug.Log(debug.DEBUG_VERBOSE, "Encrypting for single recipient", "key", fmt.Sprintf("%x", 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")
debug.Log(debug.DEBUG_INFO, "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])
debug.Log(debug.DEBUG_VERBOSE, "Encrypting for group with ratchet key", "key", fmt.Sprintf("%x", key[:8]))
return d.identity.EncryptWithHMAC(plaintext, key)
default:
log.Printf("[DEBUG-3] Unsupported destination type %d for encryption", d.destType)
debug.Log(debug.DEBUG_INFO, "Unsupported destination type for encryption", "destType", d.destType)
return nil, errors.New("unsupported destination type for encryption")
}
}

View File

@@ -12,13 +12,13 @@ import (
"errors"
"fmt"
"io"
"log"
"os"
"sync"
"time"
"github.com/Sudo-Ivan/reticulum-go/pkg/common"
"github.com/Sudo-Ivan/reticulum-go/pkg/cryptography"
"github.com/Sudo-Ivan/reticulum-go/pkg/debug"
"golang.org/x/crypto/curve25519"
"golang.org/x/crypto/hkdf"
)
@@ -173,7 +173,7 @@ func GetRandomHash() []byte {
randomData := make([]byte, TRUNCATED_HASHLENGTH/8)
_, err := rand.Read(randomData) // #nosec G104
if err != nil {
log.Printf("[DEBUG-1] Failed to read random data for hash: %v", err)
debug.Log(debug.DEBUG_CRITICAL, "Failed to read random data for hash", "error", err)
return nil // Or handle the error appropriately
}
return TruncatedHash(randomData)
@@ -279,13 +279,13 @@ func (i *Identity) GetCurrentRatchetKey() []byte {
if len(i.ratchets) == 0 {
// If no ratchets exist, generate one.
// This should ideally be handled by an explicit setup process.
log.Println("[DEBUG-5] No ratchets found, generating a new one on-the-fly.")
debug.Log(debug.DEBUG_TRACE, "No ratchets found, generating a new one on-the-fly")
// Temporarily unlock to call RotateRatchet, which locks internally.
i.mutex.RUnlock()
newRatchet, err := i.RotateRatchet()
i.mutex.RLock()
if err != nil {
log.Printf("[DEBUG-1] Failed to generate initial ratchet key: %v", err)
debug.Log(debug.DEBUG_CRITICAL, "Failed to generate initial ratchet key", "error", err)
return nil
}
return newRatchet
@@ -302,7 +302,7 @@ func (i *Identity) GetCurrentRatchetKey() []byte {
}
if latestKey == nil {
log.Printf("[DEBUG-2] Could not determine the latest ratchet key from %d ratchets.", len(i.ratchets))
debug.Log(debug.DEBUG_ERROR, "Could not determine the latest ratchet key", "ratchet_count", len(i.ratchets))
}
return latestKey
@@ -310,13 +310,13 @@ func (i *Identity) GetCurrentRatchetKey() []byte {
func (i *Identity) Decrypt(ciphertextToken []byte, ratchets [][]byte, enforceRatchets bool, ratchetIDReceiver *common.RatchetIDReceiver) ([]byte, error) {
if i.privateKey == nil {
log.Printf("[DEBUG-1] Decryption failed: identity has no private key")
debug.Log(debug.DEBUG_CRITICAL, "Decryption failed: identity has no private key")
return nil, errors.New("decryption failed because identity does not hold a private key")
}
log.Printf("[DEBUG-7] Starting decryption for identity %s", i.GetHexHash())
debug.Log(debug.DEBUG_ALL, "Starting decryption for identity", "hash", i.GetHexHash())
if len(ratchets) > 0 {
log.Printf("[DEBUG-7] Attempting decryption with %d ratchets", len(ratchets))
debug.Log(debug.DEBUG_ALL, "Attempting decryption with ratchets", "count", len(ratchets))
}
if len(ciphertextToken) <= KEYSIZE/8/2 {
@@ -407,7 +407,7 @@ func (i *Identity) Decrypt(ciphertextToken []byte, ratchets [][]byte, enforceRat
ratchetIDReceiver.LatestRatchetID = nil
}
log.Printf("[DEBUG-7] Decryption completed successfully")
debug.Log(debug.DEBUG_ALL, "Decryption completed successfully")
return plaintext[:len(plaintext)-padding], nil
}
@@ -419,7 +419,7 @@ func (i *Identity) tryRatchetDecryption(peerPubBytes, ciphertext, ratchet []byte
// Get ratchet ID
ratchetPubBytes, err := curve25519.X25519(ratchetPriv, cryptography.GetBasepoint())
if err != nil {
log.Printf("[DEBUG-7] Failed to generate ratchet public key: %v", err)
debug.Log(debug.DEBUG_ALL, "Failed to generate ratchet public key", "error", err)
return nil, nil, err
}
ratchetID := i.GetRatchetID(ratchetPubBytes)
@@ -469,12 +469,12 @@ func (i *Identity) DecryptWithHMAC(data []byte, key []byte) ([]byte, error) {
}
func (i *Identity) ToFile(path string) error {
log.Printf("[DEBUG-7] Saving identity %s to file: %s", i.GetHexHash(), path)
debug.Log(debug.DEBUG_ALL, "Saving identity to file", "hash", i.GetHexHash(), "path", path)
// Persist ratchets to a separate file
ratchetPath := path + ".ratchets"
if err := i.saveRatchets(ratchetPath); err != nil {
log.Printf("[DEBUG-1] Failed to save ratchets: %v", err)
debug.Log(debug.DEBUG_CRITICAL, "Failed to save ratchets", "error", err)
// Continue saving the main identity file even if ratchets fail
}
@@ -488,17 +488,17 @@ func (i *Identity) ToFile(path string) error {
file, err := os.Create(path) // #nosec G304
if err != nil {
log.Printf("[DEBUG-1] Failed to create identity file: %v", err)
debug.Log(debug.DEBUG_CRITICAL, "Failed to create identity file", "error", err)
return err
}
defer file.Close()
if err := json.NewEncoder(file).Encode(data); err != nil {
log.Printf("[DEBUG-1] Failed to encode identity data: %v", err)
debug.Log(debug.DEBUG_CRITICAL, "Failed to encode identity data", "error", err)
return err
}
log.Printf("[DEBUG-7] Identity saved successfully")
debug.Log(debug.DEBUG_ALL, "Identity saved successfully")
return nil
}
@@ -510,7 +510,7 @@ func (i *Identity) saveRatchets(path string) error {
return nil // Nothing to save
}
log.Printf("[DEBUG-6] Saving %d ratchets to %s", len(i.ratchets), path)
debug.Log(debug.DEBUG_PACKETS, "Saving ratchets", "count", len(i.ratchets), "path", path)
data := map[string]interface{}{
"ratchets": i.ratchets,
"ratchet_expiry": i.ratchetExpiry,
@@ -526,18 +526,18 @@ func (i *Identity) saveRatchets(path string) error {
}
func RecallIdentity(path string) (*Identity, error) {
log.Printf("[DEBUG-7] Attempting to recall identity from: %s", path)
debug.Log(debug.DEBUG_ALL, "Attempting to recall identity", "path", path)
file, err := os.Open(path) // #nosec G304
if err != nil {
log.Printf("[DEBUG-1] Failed to open identity file: %v", err)
debug.Log(debug.DEBUG_CRITICAL, "Failed to open identity file", "error", err)
return nil, err
}
defer file.Close()
var data map[string]interface{}
if err := json.NewDecoder(file).Decode(&data); err != nil {
log.Printf("[DEBUG-1] Failed to decode identity data: %v", err)
debug.Log(debug.DEBUG_CRITICAL, "Failed to decode identity data", "error", err)
return nil, err
}
@@ -569,11 +569,11 @@ func RecallIdentity(path string) (*Identity, error) {
// Load ratchets if they exist
ratchetPath := path + ".ratchets"
if err := id.loadRatchets(ratchetPath); err != nil {
log.Printf("[DEBUG-2] Could not load ratchets for identity %s: %v", id.GetHexHash(), err)
debug.Log(debug.DEBUG_ERROR, "Could not load ratchets for identity", "hash", id.GetHexHash(), "error", err)
// This is not a fatal error, the identity can still function
}
log.Printf("[DEBUG-7] Successfully recalled identity with hash: %s", id.GetHexHash())
debug.Log(debug.DEBUG_ALL, "Successfully recalled identity", "hash", id.GetHexHash())
return id, nil
}
@@ -584,7 +584,7 @@ func (i *Identity) loadRatchets(path string) error {
file, err := os.Open(path) // #nosec G304
if err != nil {
if os.IsNotExist(err) {
log.Printf("[DEBUG-6] No ratchet file found at %s, skipping.", path)
debug.Log(debug.DEBUG_PACKETS, "No ratchet file found, skipping", "path", path)
return nil
}
return fmt.Errorf("failed to open ratchet file: %w", err)
@@ -612,7 +612,7 @@ func (i *Identity) loadRatchets(path string) error {
}
}
log.Printf("[DEBUG-6] Loaded %d ratchets from %s", len(i.ratchets), path)
debug.Log(debug.DEBUG_PACKETS, "Loaded ratchets", "count", len(i.ratchets), "path", path)
return nil
}
@@ -713,19 +713,19 @@ func (i *Identity) RotateRatchet() ([]byte, error) {
i.mutex.Lock()
defer i.mutex.Unlock()
log.Printf("[DEBUG-7] Rotating ratchet for identity %s", i.GetHexHash())
debug.Log(debug.DEBUG_ALL, "Rotating ratchet for identity", "hash", i.GetHexHash())
// Generate new ratchet key
newRatchet := make([]byte, RATCHETSIZE/8)
if _, err := io.ReadFull(rand.Reader, newRatchet); err != nil {
log.Printf("[DEBUG-1] Failed to generate new ratchet: %v", err)
debug.Log(debug.DEBUG_CRITICAL, "Failed to generate new ratchet", "error", err)
return nil, err
}
// Get public key for ratchet ID
ratchetPub, err := curve25519.X25519(newRatchet, curve25519.Basepoint)
if err != nil {
log.Printf("[DEBUG-1] Failed to generate ratchet public key: %v", err)
debug.Log(debug.DEBUG_CRITICAL, "Failed to generate ratchet public key", "error", err)
return nil, err
}
@@ -736,7 +736,7 @@ func (i *Identity) RotateRatchet() ([]byte, error) {
i.ratchets[string(ratchetID)] = newRatchet
i.ratchetExpiry[string(ratchetID)] = expiry
log.Printf("[DEBUG-7] New ratchet generated with ID: %x, expiry: %d", ratchetID, expiry)
debug.Log(debug.DEBUG_ALL, "New ratchet generated", "id", fmt.Sprintf("%x", ratchetID), "expiry", expiry)
// Cleanup old ratchets if we exceed max retained
if len(i.ratchets) > MAX_RETAINED_RATCHETS {
@@ -752,10 +752,10 @@ func (i *Identity) RotateRatchet() ([]byte, error) {
delete(i.ratchets, oldestID)
delete(i.ratchetExpiry, oldestID)
log.Printf("[DEBUG-7] Cleaned up oldest ratchet with ID: %x", []byte(oldestID))
debug.Log(debug.DEBUG_ALL, "Cleaned up oldest ratchet", "id", fmt.Sprintf("%x", []byte(oldestID)))
}
log.Printf("[DEBUG-7] Current number of active ratchets: %d", len(i.ratchets))
debug.Log(debug.DEBUG_ALL, "Current number of active ratchets", "count", len(i.ratchets))
return newRatchet, nil
}
@@ -763,7 +763,7 @@ func (i *Identity) GetRatchets() [][]byte {
i.mutex.RLock()
defer i.mutex.RUnlock()
log.Printf("[DEBUG-7] Getting ratchets for identity %s", i.GetHexHash())
debug.Log(debug.DEBUG_ALL, "Getting ratchets for identity", "hash", i.GetHexHash())
ratchets := make([][]byte, 0, len(i.ratchets))
now := time.Now().Unix()
@@ -781,7 +781,7 @@ func (i *Identity) GetRatchets() [][]byte {
}
}
log.Printf("[DEBUG-7] Retrieved %d active ratchets, cleaned up %d expired", len(ratchets), expired)
debug.Log(debug.DEBUG_ALL, "Retrieved active ratchets", "active", len(ratchets), "expired", expired)
return ratchets
}
@@ -789,7 +789,7 @@ func (i *Identity) CleanupExpiredRatchets() {
i.mutex.Lock()
defer i.mutex.Unlock()
log.Printf("[DEBUG-7] Starting ratchet cleanup for identity %s", i.GetHexHash())
debug.Log(debug.DEBUG_ALL, "Starting ratchet cleanup for identity", "hash", i.GetHexHash())
now := time.Now().Unix()
cleaned := 0
@@ -801,7 +801,7 @@ func (i *Identity) CleanupExpiredRatchets() {
}
}
log.Printf("[DEBUG-7] Cleaned up %d expired ratchets, %d remaining", cleaned, len(i.ratchets))
debug.Log(debug.DEBUG_ALL, "Cleaned up expired ratchets", "cleaned", cleaned, "remaining", len(i.ratchets))
}
// ValidateAnnounce validates an announce packet's signature

View File

@@ -3,12 +3,12 @@ package interfaces
import (
"encoding/binary"
"fmt"
"log"
"net"
"sync"
"time"
"github.com/Sudo-Ivan/reticulum-go/pkg/common"
"github.com/Sudo-Ivan/reticulum-go/pkg/debug"
)
const (
@@ -26,17 +26,6 @@ const (
TYPE_TCP = 0x02
PROPAGATION_RATE = 0.02 // 2% of interface bandwidth
DEBUG_LEVEL = 4 // Default debug level for interface logging
// Debug levels
DEBUG_CRITICAL = 1
DEBUG_ERROR = 2
DEBUG_INFO = 3
DEBUG_VERBOSE = 4
DEBUG_TRACE = 5
DEBUG_PACKETS = 6
DEBUG_ALL = 7
)
type Interface interface {
@@ -127,7 +116,7 @@ func (i *BaseInterface) ProcessIncoming(data []byte) {
func (i *BaseInterface) ProcessOutgoing(data []byte) error {
if !i.Online || i.Detached {
log.Printf("[DEBUG-1] Interface %s: Cannot process outgoing packet - interface offline or detached", i.Name)
debug.Log(debug.DEBUG_CRITICAL, "Interface cannot process outgoing packet - interface offline or detached", "name", i.Name)
return fmt.Errorf("interface offline or detached")
}
@@ -135,7 +124,7 @@ func (i *BaseInterface) ProcessOutgoing(data []byte) error {
i.TxBytes += uint64(len(data))
i.mutex.Unlock()
log.Printf("[DEBUG-%d] Interface %s: Processed outgoing packet of %d bytes, total TX: %d", DEBUG_LEVEL, i.Name, len(data), i.TxBytes)
debug.Log(debug.DEBUG_VERBOSE, "Interface processed outgoing packet", "name", i.Name, "bytes", len(data), "total_tx", i.TxBytes)
return nil
}
@@ -189,7 +178,7 @@ func (i *BaseInterface) Enable() {
i.Enabled = true
i.Online = true
log.Printf("[DEBUG-%d] Interface %s: State changed - Enabled: %v->%v, Online: %v->%v", DEBUG_INFO, i.Name, prevState, i.Enabled, !i.Online, i.Online)
debug.Log(debug.DEBUG_INFO, "Interface state changed", "name", i.Name, "enabled_prev", prevState, "enabled", i.Enabled, "online_prev", !i.Online, "online", i.Online)
}
func (i *BaseInterface) Disable() {
@@ -197,7 +186,7 @@ func (i *BaseInterface) Disable() {
defer i.mutex.Unlock()
i.Enabled = false
i.Online = false
log.Printf("[DEBUG-2] Interface %s: Disabled and offline", i.Name)
debug.Log(debug.DEBUG_ERROR, "Interface disabled and offline", "name", i.Name)
}
func (i *BaseInterface) GetName() string {
@@ -237,11 +226,11 @@ func (i *BaseInterface) Stop() error {
}
func (i *BaseInterface) Send(data []byte, address string) error {
log.Printf("[DEBUG-%d] Interface %s: Sending %d bytes to %s", DEBUG_LEVEL, i.Name, len(data), address)
debug.Log(debug.DEBUG_VERBOSE, "Interface sending bytes", "name", i.Name, "bytes", len(data), "address", address)
err := i.ProcessOutgoing(data)
if err != nil {
log.Printf("[DEBUG-1] Interface %s: Failed to send data: %v", i.Name, err)
debug.Log(debug.DEBUG_CRITICAL, "Interface failed to send data", "name", i.Name, "error", err)
return err
}
@@ -261,7 +250,7 @@ func (i *BaseInterface) GetBandwidthAvailable() bool {
timeSinceLastTx := now.Sub(i.lastTx)
if timeSinceLastTx > time.Second {
log.Printf("[DEBUG-%d] Interface %s: Bandwidth available (idle for %.2fs)", DEBUG_VERBOSE, i.Name, timeSinceLastTx.Seconds())
debug.Log(debug.DEBUG_VERBOSE, "Interface bandwidth available", "name", i.Name, "idle_seconds", timeSinceLastTx.Seconds())
return true
}
@@ -270,7 +259,7 @@ func (i *BaseInterface) GetBandwidthAvailable() bool {
maxUsage := float64(i.Bitrate) * PROPAGATION_RATE
available := currentUsage < maxUsage
log.Printf("[DEBUG-%d] Interface %s: Bandwidth stats - Current: %.2f bps, Max: %.2f bps, Usage: %.1f%%, Available: %v", DEBUG_VERBOSE, i.Name, currentUsage, maxUsage, (currentUsage/maxUsage)*100, available)
debug.Log(debug.DEBUG_VERBOSE, "Interface bandwidth stats", "name", i.Name, "current_bps", currentUsage, "max_bps", maxUsage, "usage_percent", (currentUsage/maxUsage)*100, "available", available)
return available
}
@@ -282,7 +271,7 @@ func (i *BaseInterface) updateBandwidthStats(bytes uint64) {
i.TxBytes += bytes
i.lastTx = time.Now()
log.Printf("[DEBUG-%d] Interface %s: Updated bandwidth stats - TX bytes: %d, Last TX: %v", DEBUG_LEVEL, i.Name, i.TxBytes, i.lastTx)
debug.Log(debug.DEBUG_VERBOSE, "Interface updated bandwidth stats", "name", i.Name, "tx_bytes", i.TxBytes, "last_tx", i.lastTx)
}
type InterceptedInterface struct {
@@ -305,7 +294,7 @@ func (i *InterceptedInterface) Send(data []byte, addr string) error {
// Call interceptor if provided
if i.interceptor != nil && len(data) > 0 {
if err := i.interceptor(data, i); err != nil {
log.Printf("[DEBUG-2] Failed to intercept outgoing packet: %v", err)
debug.Log(debug.DEBUG_ERROR, "Failed to intercept outgoing packet", "error", err)
}
}

View File

@@ -2,13 +2,13 @@ package interfaces
import (
"fmt"
"log"
"net"
"runtime"
"sync"
"time"
"github.com/Sudo-Ivan/reticulum-go/pkg/common"
"github.com/Sudo-Ivan/reticulum-go/pkg/debug"
)
const (
@@ -106,11 +106,11 @@ func (tc *TCPClientInterface) Start() error {
switch runtime.GOOS {
case "linux":
if err := tc.setTimeoutsLinux(); err != nil {
log.Printf("[DEBUG-2] Failed to set Linux TCP timeouts: %v", err)
debug.Log(debug.DEBUG_ERROR, "Failed to set Linux TCP timeouts", "error", err)
}
case "darwin":
if err := tc.setTimeoutsOSX(); err != nil {
log.Printf("[DEBUG-2] Failed to set OSX TCP timeouts: %v", err)
debug.Log(debug.DEBUG_ERROR, "Failed to set OSX TCP timeouts", "error", err)
}
}
@@ -169,7 +169,7 @@ func (tc *TCPClientInterface) readLoop() {
func (tc *TCPClientInterface) handlePacket(data []byte) {
if len(data) < 1 {
log.Printf("[DEBUG-7] Received invalid packet: empty")
debug.Log(debug.DEBUG_ALL, "Received invalid packet: empty")
return
}
@@ -179,20 +179,20 @@ func (tc *TCPClientInterface) handlePacket(data []byte) {
tc.lastRx = lastRx
tc.mutex.Unlock()
log.Printf("[DEBUG-7] Received packet: type=0x%02x, size=%d bytes", data[0], len(data))
debug.Log(debug.DEBUG_ALL, "Received packet", "type", fmt.Sprintf("0x%02x", data[0]), "size", len(data))
// For RNS packets, call the packet callback directly
if callback := tc.GetPacketCallback(); callback != nil {
log.Printf("[DEBUG-7] Calling packet callback for RNS packet")
debug.Log(debug.DEBUG_ALL, "Calling packet callback for RNS packet")
callback(data, tc)
} else {
log.Printf("[DEBUG-7] No packet callback set for TCP interface")
debug.Log(debug.DEBUG_ALL, "No packet callback set for TCP interface")
}
}
// Send implements the interface Send method for TCP interface
func (tc *TCPClientInterface) Send(data []byte, address string) error {
log.Printf("[DEBUG-7] TCP interface %s: Sending %d bytes", tc.Name, len(data))
debug.Log(debug.DEBUG_ALL, "TCP interface sending bytes", "name", tc.Name, "bytes", len(data))
if !tc.IsEnabled() || !tc.IsOnline() {
return fmt.Errorf("TCP interface %s is not online", tc.Name)
@@ -223,10 +223,10 @@ func (tc *TCPClientInterface) ProcessOutgoing(data []byte) error {
// Update TX stats before sending
tc.UpdateStats(uint64(len(frame)), false)
log.Printf("[DEBUG-7] TCP interface %s: Writing %d bytes to network", tc.Name, len(frame))
debug.Log(debug.DEBUG_ALL, "TCP interface writing to network", "name", tc.Name, "bytes", len(frame))
_, err := tc.conn.Write(frame)
if err != nil {
log.Printf("[DEBUG-1] TCP interface %s: Write failed: %v", tc.Name, err)
debug.Log(debug.DEBUG_CRITICAL, "TCP interface write failed", "name", tc.Name, "error", err)
}
return err
}
@@ -333,7 +333,7 @@ func (tc *TCPClientInterface) reconnect() {
// Log reconnection attempt
fmt.Printf("Failed to reconnect to %s (attempt %d/%d): %v\n",
addr, retries+1, tc.maxReconnectTries, err)
net.JoinHostPort(tc.targetAddr, fmt.Sprintf("%d", tc.targetPort)), retries+1, tc.maxReconnectTries, err)
// Wait with exponential backoff
time.Sleep(backoff)
@@ -354,7 +354,7 @@ func (tc *TCPClientInterface) reconnect() {
// If we've exhausted all retries, perform final teardown
tc.teardown()
fmt.Printf("Failed to reconnect to %s after %d attempts\n",
fmt.Sprintf("%s:%d", tc.targetAddr, tc.targetPort), tc.maxReconnectTries)
net.JoinHostPort(tc.targetAddr, fmt.Sprintf("%d", tc.targetPort)), tc.maxReconnectTries)
}
func (tc *TCPClientInterface) Enable() {
@@ -390,7 +390,7 @@ func (tc *TCPClientInterface) GetRTT() time.Duration {
if err := info.Control(func(fd uintptr) { // #nosec G104
rtt = platformGetRTT(fd)
}); err != nil {
log.Printf("[DEBUG-2] Error in SyscallConn Control: %v", err)
debug.Log(debug.DEBUG_ERROR, "Error in SyscallConn Control", "error", err)
}
}
}
@@ -420,13 +420,11 @@ func (tc *TCPClientInterface) UpdateStats(bytes uint64, isRx bool) {
if isRx {
tc.RxBytes += bytes
tc.lastRx = now
log.Printf("[DEBUG-5] Interface %s RX stats: bytes=%d total=%d last=%v",
tc.Name, bytes, tc.RxBytes, tc.lastRx)
debug.Log(debug.DEBUG_TRACE, "Interface RX stats", "name", tc.Name, "bytes", bytes, "total", tc.RxBytes, "last", tc.lastRx)
} else {
tc.TxBytes += bytes
tc.lastTx = now
log.Printf("[DEBUG-5] Interface %s TX stats: bytes=%d total=%d last=%v",
tc.Name, bytes, tc.TxBytes, tc.lastTx)
debug.Log(debug.DEBUG_TRACE, "Interface TX stats", "name", tc.Name, "bytes", bytes, "total", tc.TxBytes, "last", tc.lastTx)
}
}
@@ -564,7 +562,7 @@ func (ts *TCPServerInterface) Start() error {
ts.mutex.Lock()
defer ts.mutex.Unlock()
addr := fmt.Sprintf("%s:%d", ts.bindAddr, ts.bindPort)
addr := net.JoinHostPort(ts.bindAddr, fmt.Sprintf("%d", ts.bindPort))
listener, err := net.Listen("tcp", addr)
if err != nil {
return fmt.Errorf("failed to start TCP server: %w", err)
@@ -580,7 +578,7 @@ func (ts *TCPServerInterface) Start() error {
if !ts.Online {
return // Normal shutdown
}
log.Printf("[DEBUG-2] Error accepting connection: %v", err)
debug.Log(debug.DEBUG_ERROR, "Error accepting connection", "error", err)
continue
}
@@ -663,8 +661,7 @@ func (ts *TCPServerInterface) ProcessOutgoing(data []byte) error {
for _, conn := range ts.connections {
if _, err := conn.Write(frame); err != nil {
log.Printf("[DEBUG-4] Error writing to connection %s: %v",
conn.RemoteAddr(), err)
debug.Log(debug.DEBUG_VERBOSE, "Error writing to connection", "address", conn.RemoteAddr(), "error", err)
}
}

View File

@@ -2,11 +2,11 @@ package interfaces
import (
"fmt"
"log"
"net"
"sync"
"github.com/Sudo-Ivan/reticulum-go/pkg/common"
"github.com/Sudo-Ivan/reticulum-go/pkg/debug"
)
type UDPInterface struct {
@@ -76,7 +76,7 @@ func (ui *UDPInterface) Detach() {
}
func (ui *UDPInterface) Send(data []byte, addr string) error {
log.Printf("[DEBUG-7] UDP interface %s: Sending %d bytes", ui.Name, len(data))
debug.Log(debug.DEBUG_ALL, "UDP interface sending bytes", "name", ui.Name, "bytes", len(data))
if !ui.IsEnabled() {
return fmt.Errorf("interface not enabled")
@@ -93,9 +93,9 @@ func (ui *UDPInterface) Send(data []byte, addr string) error {
_, err := ui.conn.WriteTo(data, ui.targetAddr)
if err != nil {
log.Printf("[DEBUG-1] UDP interface %s: Write failed: %v", ui.Name, err)
debug.Log(debug.DEBUG_CRITICAL, "UDP interface write failed", "name", ui.Name, "error", err)
} else {
log.Printf("[DEBUG-7] UDP interface %s: Sent %d bytes successfully", ui.Name, len(data))
debug.Log(debug.DEBUG_ALL, "UDP interface sent bytes successfully", "name", ui.Name, "bytes", len(data))
}
return err
}
@@ -195,14 +195,14 @@ func (ui *UDPInterface) readLoop() {
n, remoteAddr, err := ui.conn.ReadFromUDP(buffer)
if err != nil {
if ui.IsOnline() {
log.Printf("Error reading from UDP interface %s: %v", ui.Name, err)
debug.Log(debug.DEBUG_ERROR, "Error reading from UDP interface", "name", ui.Name, "error", err)
}
return
}
ui.mutex.Lock()
if ui.targetAddr == nil {
log.Printf("[DEBUG-7] UDP interface %s discovered peer %s", ui.Name, remoteAddr)
debug.Log(debug.DEBUG_ALL, "UDP interface discovered peer", "name", ui.Name, "peer", remoteAddr.String())
ui.targetAddr = remoteAddr
}
ui.mutex.Unlock()
@@ -213,25 +213,6 @@ func (ui *UDPInterface) readLoop() {
}
}
/*
func (ui *UDPInterface) readLoop() {
buffer := make([]byte, ui.MTU)
for {
n, _, err := ui.conn.ReadFromUDP(buffer)
if err != nil {
if ui.Online {
log.Printf("Error reading from UDP interface %s: %v", ui.Name, err)
ui.Stop() // Consider if stopping is the right action or just log and continue
}
return
}
if ui.packetCallback != nil {
ui.packetCallback(buffer[:n], ui)
}
}
}
*/
func (ui *UDPInterface) IsEnabled() bool {
ui.mutex.RLock()
defer ui.mutex.RUnlock()

View File

@@ -6,7 +6,6 @@ import (
"encoding/binary"
"errors"
"fmt"
"log"
"net"
"reflect"
"sync"
@@ -14,6 +13,7 @@ import (
"github.com/Sudo-Ivan/reticulum-go/pkg/announce"
"github.com/Sudo-Ivan/reticulum-go/pkg/common"
"github.com/Sudo-Ivan/reticulum-go/pkg/debug"
"github.com/Sudo-Ivan/reticulum-go/pkg/identity"
"github.com/Sudo-Ivan/reticulum-go/pkg/interfaces"
"github.com/Sudo-Ivan/reticulum-go/pkg/packet"
@@ -142,7 +142,7 @@ func (t *Transport) RegisterDestination(hash []byte, dest interface{}) {
t.mutex.Lock()
defer t.mutex.Unlock()
t.destinations[string(hash)] = dest
log.Printf("[DEBUG-5] Registered destination %x with transport", hash)
debug.Log(debug.DEBUG_TRACE, "Registered destination with transport", "hash", fmt.Sprintf("%x", hash))
}
// CreateIncomingLink creates a link object for an incoming link request
@@ -151,7 +151,7 @@ func (t *Transport) CreateIncomingLink(dest interface{}, networkIface common.Net
// This function signature uses interface{} to avoid importing link package
// The actual implementation will be in the application code
// For now, return nil to indicate links aren't fully implemented
log.Printf("[DEBUG-5] CreateIncomingLink called (not yet fully implemented)")
debug.Log(debug.DEBUG_TRACE, "CreateIncomingLink called (not yet fully implemented)")
return nil
}
@@ -338,7 +338,7 @@ func (t *Transport) notifyAnnounceHandlers(destHash []byte, identity interface{}
for _, handler := range handlers {
if err := handler.ReceivedAnnounce(destHash, identity, appData); err != nil {
log.Printf("Error in announce handler: %v", err)
debug.Log(debug.DEBUG_ERROR, "Error in announce handler", "error", err)
}
}
}
@@ -417,7 +417,7 @@ func (t *Transport) updatePathUnlocked(destinationHash []byte, nextHop []byte, i
// Direct access to interfaces map since caller holds the lock
iface, exists := t.interfaces[interfaceName]
if !exists {
log.Printf("[DEBUG-3] Interface %s not found", interfaceName)
debug.Log(debug.DEBUG_INFO, "Interface not found", "name", interfaceName)
return
}
@@ -440,8 +440,7 @@ func (t *Transport) HandleAnnounce(data []byte, sourceIface common.NetworkInterf
return fmt.Errorf("announce packet too small: %d bytes", len(data))
}
log.Printf("[DEBUG-7] Transport handling announce of %d bytes from %s",
len(data), sourceIface.GetName())
debug.Log(debug.DEBUG_ALL, "Transport handling announce", "bytes", len(data), "source", sourceIface.GetName())
// Parse announce fields according to RNS spec
destHash := data[1:33]
@@ -455,7 +454,7 @@ func (t *Transport) HandleAnnounce(data []byte, sourceIface common.NetworkInterf
t.mutex.Lock()
if _, seen := t.seenAnnounces[hashStr]; seen {
t.mutex.Unlock()
log.Printf("[DEBUG-7] Ignoring duplicate announce %x", announceHash[:8])
debug.Log(debug.DEBUG_ALL, "Ignoring duplicate announce", "hash", fmt.Sprintf("%x", announceHash[:8]))
return nil
}
t.seenAnnounces[hashStr] = true
@@ -463,7 +462,7 @@ func (t *Transport) HandleAnnounce(data []byte, sourceIface common.NetworkInterf
// Don't forward if max hops reached
if data[0] >= MAX_HOPS {
log.Printf("[DEBUG-7] Announce exceeded max hops: %d", data[0])
debug.Log(debug.DEBUG_ALL, "Announce exceeded max hops", "hops", data[0])
return nil
}
@@ -472,7 +471,7 @@ func (t *Transport) HandleAnnounce(data []byte, sourceIface common.NetworkInterf
b := make([]byte, 8)
_, err := rand.Read(b)
if err != nil {
log.Printf("[DEBUG-7] Failed to generate random delay: %v", err)
debug.Log(debug.DEBUG_ALL, "Failed to generate random delay", "error", err)
delay = time.Duration(0) // Default to no delay on error
} else {
delay = time.Duration(binary.BigEndian.Uint64(b)%2000) * time.Millisecond // #nosec G115
@@ -481,7 +480,7 @@ func (t *Transport) HandleAnnounce(data []byte, sourceIface common.NetworkInterf
// Check bandwidth allocation for announces
if !t.announceRate.Allow() {
log.Printf("[DEBUG-7] Announce rate limit exceeded, queuing...")
debug.Log(debug.DEBUG_ALL, "Announce rate limit exceeded, queuing")
return nil
}
@@ -495,9 +494,9 @@ func (t *Transport) HandleAnnounce(data []byte, sourceIface common.NetworkInterf
continue
}
log.Printf("[DEBUG-7] Forwarding announce on interface %s", name)
debug.Log(debug.DEBUG_ALL, "Forwarding announce on interface", "name", name)
if err := iface.Send(data, ""); err != nil {
log.Printf("[DEBUG-7] Failed to forward announce on %s: %v", name, err)
debug.Log(debug.DEBUG_ALL, "Failed to forward announce", "name", name, "error", err)
lastErr = err
}
}
@@ -649,7 +648,7 @@ func SendAnnounce(packet []byte) error {
func (t *Transport) HandlePacket(data []byte, iface common.NetworkInterface) {
if len(data) < 2 {
log.Printf("[DEBUG-3] Dropping packet: insufficient length (%d bytes)", len(data))
debug.Log(debug.DEBUG_INFO, "Dropping packet: insufficient length", "bytes", len(data))
return
}
@@ -660,37 +659,36 @@ func (t *Transport) HandlePacket(data []byte, iface common.NetworkInterface) {
propType := (headerByte & 0x10) >> 4
destType := (headerByte & 0x0C) >> 2
log.Printf("[DEBUG-3] TRANSPORT: Packet received - Type: 0x%02x, Header: %d, Context: %d, PropType: %d, DestType: %d, Size: %d bytes",
packetType, headerType, contextFlag, propType, destType, len(data))
log.Printf("[DEBUG-5] Interface: %s, Raw header: 0x%02x", iface.GetName(), headerByte)
debug.Log(debug.DEBUG_INFO, "TRANSPORT: Packet received", "type", fmt.Sprintf("0x%02x", packetType), "header", headerType, "context", contextFlag, "propType", propType, "destType", destType, "size", len(data))
debug.Log(debug.DEBUG_TRACE, "Interface and raw header", "name", iface.GetName(), "header", fmt.Sprintf("0x%02x", headerByte))
if tcpIface, ok := iface.(*interfaces.TCPClientInterface); ok {
tcpIface.UpdateStats(uint64(len(data)), true)
log.Printf("[DEBUG-6] Updated TCP interface stats - RX bytes: %d", len(data))
debug.Log(debug.DEBUG_PACKETS, "Updated TCP interface stats", "rx_bytes", len(data))
}
switch packetType {
case PACKET_TYPE_ANNOUNCE:
log.Printf("[DEBUG-4] Processing announce packet")
debug.Log(debug.DEBUG_VERBOSE, "Processing announce packet")
if err := t.handleAnnouncePacket(data, iface); err != nil {
log.Printf("[DEBUG-3] Announce handling failed: %v", err)
debug.Log(debug.DEBUG_INFO, "Announce handling failed", "error", err)
}
case PACKET_TYPE_LINK:
log.Printf("[DEBUG-4] Processing link packet")
debug.Log(debug.DEBUG_VERBOSE, "Processing link packet")
t.handleLinkPacket(data[1:], iface)
case 0x03:
log.Printf("[DEBUG-4] Processing path response")
debug.Log(debug.DEBUG_VERBOSE, "Processing path response")
t.handlePathResponse(data[1:], iface)
case 0x00:
log.Printf("[DEBUG-4] Processing transport packet")
debug.Log(debug.DEBUG_VERBOSE, "Processing transport packet")
t.handleTransportPacket(data[1:], iface)
default:
log.Printf("[DEBUG-3] Unknown packet type 0x%02x from %s", packetType, iface.GetName())
debug.Log(debug.DEBUG_INFO, "Unknown packet type", "type", fmt.Sprintf("0x%02x", packetType), "source", iface.GetName())
}
}
func (t *Transport) handleAnnouncePacket(data []byte, iface common.NetworkInterface) error {
log.Printf("[DEBUG-3] Processing announce packet, length: %d bytes", len(data))
debug.Log(debug.DEBUG_INFO, "Processing announce packet", "length", len(data))
if len(data) < 2 {
return fmt.Errorf("packet too small for header")
}
@@ -707,8 +705,7 @@ func (t *Transport) handleAnnouncePacket(data []byte, iface common.NetworkInterf
destType := (headerByte1 & 0x0C) >> 2 // Destination type in next 2 bits
packetType := headerByte1 & 0x03 // Packet type in lowest 2 bits
log.Printf("[DEBUG-5] Announce header: IFAC=%d, headerType=%d, context=%d, propType=%d, destType=%d, packetType=%d",
ifacFlag, headerType, contextFlag, propType, destType, packetType)
debug.Log(debug.DEBUG_TRACE, "Announce header", "ifac", ifacFlag, "headerType", headerType, "context", contextFlag, "propType", propType, "destType", destType, "packetType", packetType)
// Skip IFAC code if present
startIdx := 2
@@ -733,9 +730,9 @@ func (t *Transport) handleAnnouncePacket(data []byte, iface common.NetworkInterf
context := data[startIdx+addrSize]
payload := data[startIdx+addrSize+1:]
log.Printf("[DEBUG-3] Addresses: %x (len=%d)", addresses, len(addresses))
log.Printf("[DEBUG-3] Context: %02x, Payload length: %d", context, len(payload))
log.Printf("[DEBUG-3] Packet total length: %d", len(data))
debug.Log(debug.DEBUG_INFO, "Addresses", "addresses", fmt.Sprintf("%x", addresses), "len", len(addresses))
debug.Log(debug.DEBUG_INFO, "Context and payload", "context", fmt.Sprintf("%02x", context), "payload_len", len(payload))
debug.Log(debug.DEBUG_INFO, "Packet total length", "length", len(data))
// Parse announce packet according to RNS specification
// All announce packets have the same format:
@@ -747,7 +744,7 @@ func (t *Transport) handleAnnouncePacket(data []byte, iface common.NetworkInterf
minAnnounceSize := 64 + 10 + 10 + 64 // pubKey + nameHash + randomHash + signature
if len(payload) < minAnnounceSize {
log.Printf("[DEBUG-3] Payload too small for announce: %d bytes, minimum %d", len(payload), minAnnounceSize)
debug.Log(debug.DEBUG_INFO, "Payload too small for announce", "bytes", len(payload), "minimum", minAnnounceSize)
return fmt.Errorf("payload too small for announce")
}
@@ -782,16 +779,15 @@ func (t *Transport) handleAnnouncePacket(data []byte, iface common.NetworkInterf
} else {
ratchetHex = "(empty)"
}
log.Printf("[DEBUG-3] Parsed announce: pubKey=%x, nameHash=%x, randomHash=%x, ratchet=%s, appData len=%d",
pubKey[:8], nameHash, randomHash, ratchetHex, len(appData))
debug.Log(debug.DEBUG_INFO, "Parsed announce", "pubKey", fmt.Sprintf("%x", pubKey[:8]), "nameHash", fmt.Sprintf("%x", nameHash), "randomHash", fmt.Sprintf("%x", randomHash), "ratchet", ratchetHex, "appData_len", len(appData))
// Create identity from public key
id = identity.FromPublicKey(pubKey)
if id == nil {
log.Printf("[DEBUG-3] Failed to create identity from public key")
debug.Log(debug.DEBUG_INFO, "Failed to create identity from public key")
return fmt.Errorf("invalid identity")
}
log.Printf("[DEBUG-3] Successfully created identity")
debug.Log(debug.DEBUG_INFO, "Successfully created identity")
// For announce packets, use destination hash from packet header (first 16 bytes of addresses)
// This matches the RNS validate_announce logic
@@ -807,7 +803,7 @@ func (t *Transport) handleAnnouncePacket(data []byte, iface common.NetworkInterf
}
signData = append(signData, appData...)
log.Printf("[DEBUG-3] Verifying signature with data len: %d", len(signData))
debug.Log(debug.DEBUG_INFO, "Verifying signature", "data_len", len(signData))
// Check if this passes full RNS validation (signature + destination hash check)
hashMaterial := make([]byte, 0)
@@ -816,38 +812,38 @@ func (t *Transport) handleAnnouncePacket(data []byte, iface common.NetworkInterf
expectedHashFull := sha256.Sum256(hashMaterial)
expectedHash := expectedHashFull[:16]
log.Printf("[DEBUG-3] Destination hash from packet: %x", destinationHash)
log.Printf("[DEBUG-3] Expected destination hash: %x", expectedHash)
log.Printf("[DEBUG-3] Hash match: %t", string(destinationHash) == string(expectedHash))
debug.Log(debug.DEBUG_INFO, "Destination hash from packet", "hash", fmt.Sprintf("%x", destinationHash))
debug.Log(debug.DEBUG_INFO, "Expected destination hash", "hash", fmt.Sprintf("%x", expectedHash))
debug.Log(debug.DEBUG_INFO, "Hash match", "match", string(destinationHash) == string(expectedHash))
hasAppData := len(appData) > 0
if !id.Verify(signData, signature) {
if hasAppData {
log.Printf("[DEBUG-3] Announce packet has app_data, signature failed but accepting")
debug.Log(debug.DEBUG_INFO, "Announce packet has app_data, signature failed but accepting")
} else {
log.Printf("[DEBUG-3] Signature verification failed - announce rejected")
debug.Log(debug.DEBUG_INFO, "Signature verification failed - announce rejected")
return fmt.Errorf("invalid announce signature")
}
} else {
log.Printf("[DEBUG-3] Signature verification successful")
debug.Log(debug.DEBUG_INFO, "Signature verification successful")
}
if string(destinationHash) != string(expectedHash) {
if hasAppData {
log.Printf("[DEBUG-3] Announce packet has app_data, destination hash mismatch but accepting")
debug.Log(debug.DEBUG_INFO, "Announce packet has app_data, destination hash mismatch but accepting")
} else {
log.Printf("[DEBUG-3] Destination hash mismatch - announce rejected")
debug.Log(debug.DEBUG_INFO, "Destination hash mismatch - announce rejected")
return fmt.Errorf("destination hash mismatch")
}
} else {
log.Printf("[DEBUG-3] Destination hash validation successful")
debug.Log(debug.DEBUG_INFO, "Destination hash validation successful")
}
log.Printf("[DEBUG-3] Signature and destination hash verified successfully")
debug.Log(debug.DEBUG_INFO, "Signature and destination hash verified successfully")
// Log app_data content for accepted announces
if len(appData) > 0 {
log.Printf("[DEBUG-3] Accepted announce app_data: %x (%q)", appData, string(appData))
debug.Log(debug.DEBUG_INFO, "Accepted announce app_data", "data", fmt.Sprintf("%x", appData), "string", string(appData))
}
// Store the identity for later recall
@@ -857,18 +853,18 @@ func (t *Transport) handleAnnouncePacket(data []byte, iface common.NetworkInterf
announceHash := sha256.Sum256(data)
hashStr := string(announceHash[:])
log.Printf("[DEBUG-3] Announce hash: %x", announceHash[:8])
debug.Log(debug.DEBUG_INFO, "Announce hash", "hash", fmt.Sprintf("%x", announceHash[:8]))
t.mutex.Lock()
if _, seen := t.seenAnnounces[hashStr]; seen {
t.mutex.Unlock()
log.Printf("[DEBUG-3] Ignoring duplicate announce %x", announceHash[:8])
debug.Log(debug.DEBUG_INFO, "Ignoring duplicate announce", "hash", fmt.Sprintf("%x", announceHash[:8]))
return nil
}
t.seenAnnounces[hashStr] = true
t.mutex.Unlock()
log.Printf("[DEBUG-3] Processing new announce")
debug.Log(debug.DEBUG_INFO, "Processing new announce")
// Register the path from this announce
// The destination is reachable via the interface that received this announce
@@ -877,34 +873,34 @@ func (t *Transport) handleAnnouncePacket(data []byte, iface common.NetworkInterf
t.mutex.Lock()
t.updatePathUnlocked(destinationHash, nil, iface.GetName(), hopCount)
t.mutex.Unlock()
log.Printf("[DEBUG-3] Registered path to %x via %s (%d hops)", destinationHash, iface.GetName(), hopCount)
debug.Log(debug.DEBUG_INFO, "Registered path", "hash", fmt.Sprintf("%x", destinationHash), "interface", iface.GetName(), "hops", hopCount)
}
// Notify handlers first, regardless of forwarding limits
log.Printf("[DEBUG-3] Notifying announce handlers: destHash=%x, appDataLen=%d", addresses[:16], len(appData))
debug.Log(debug.DEBUG_INFO, "Notifying announce handlers", "destHash", fmt.Sprintf("%x", addresses[:16]), "appDataLen", len(appData))
t.notifyAnnounceHandlers(addresses[:16], id, appData)
log.Printf("[DEBUG-3] Announce handlers notified")
debug.Log(debug.DEBUG_INFO, "Announce handlers notified")
// Don't forward if max hops reached
if hopCount >= MAX_HOPS {
log.Printf("[DEBUG-3] Announce exceeded max hops: %d", hopCount)
debug.Log(debug.DEBUG_INFO, "Announce exceeded max hops", "hops", hopCount)
return nil
}
log.Printf("[DEBUG-3] Hop count OK: %d", hopCount)
debug.Log(debug.DEBUG_INFO, "Hop count OK", "hops", hopCount)
// Check bandwidth allocation for announces
if !t.announceRate.Allow() {
log.Printf("[DEBUG-3] Announce rate limit exceeded, not forwarding...")
debug.Log(debug.DEBUG_INFO, "Announce rate limit exceeded, not forwarding")
return nil
}
log.Printf("[DEBUG-3] Bandwidth check passed")
debug.Log(debug.DEBUG_INFO, "Bandwidth check passed")
// Add random delay before retransmission (0-2 seconds)
var delay time.Duration
b := make([]byte, 8)
_, err := rand.Read(b)
if err != nil {
log.Printf("[DEBUG-7] Failed to generate random delay: %v", err)
debug.Log(debug.DEBUG_ALL, "Failed to generate random delay", "error", err)
delay = time.Duration(0) // Default to no delay on error
} else {
delay = time.Duration(binary.BigEndian.Uint64(b)%2000) * time.Millisecond // #nosec G115
@@ -921,9 +917,9 @@ func (t *Transport) handleAnnouncePacket(data []byte, iface common.NetworkInterf
continue
}
log.Printf("[DEBUG-7] Forwarding announce on interface %s", name)
debug.Log(debug.DEBUG_ALL, "Forwarding announce on interface", "name", name)
if err := outIface.Send(data, ""); err != nil {
log.Printf("[DEBUG-7] Failed to forward announce on %s: %v", name, err)
debug.Log(debug.DEBUG_ALL, "Failed to forward announce", "name", name, "error", err)
lastErr = err
}
}
@@ -932,13 +928,13 @@ func (t *Transport) handleAnnouncePacket(data []byte, iface common.NetworkInterf
}
func (t *Transport) handleLinkPacket(data []byte, iface common.NetworkInterface) {
log.Printf("[DEBUG-5] Handling link packet (%d bytes)", len(data))
debug.Log(debug.DEBUG_TRACE, "Handling link packet", "bytes", len(data))
// Parse the packet - need to prepend the packet type byte that was stripped
fullData := append([]byte{PACKET_TYPE_LINK}, data...)
pkt := &packet.Packet{Raw: fullData}
if err := pkt.Unpack(); err != nil {
log.Printf("[DEBUG-3] Failed to unpack link packet: %v", err)
debug.Log(debug.DEBUG_INFO, "Failed to unpack link packet", "error", err)
return
}
@@ -947,11 +943,11 @@ func (t *Transport) handleLinkPacket(data []byte, iface common.NetworkInterface)
destHash = destHash[:16]
}
log.Printf("[DEBUG-5] Link packet for destination: %x, context: 0x%02x", destHash, pkt.Context)
debug.Log(debug.DEBUG_TRACE, "Link packet for destination", "hash", fmt.Sprintf("%x", destHash), "context", fmt.Sprintf("0x%02x", pkt.Context))
// Check if this is a link request (initial link establishment)
if pkt.Context == packet.ContextLinkIdentify {
log.Printf("[DEBUG-4] Received link request for destination %x", destHash)
debug.Log(debug.DEBUG_VERBOSE, "Received link request for destination", "hash", fmt.Sprintf("%x", destHash))
// Look up the destination
t.mutex.RLock()
@@ -959,11 +955,11 @@ func (t *Transport) handleLinkPacket(data []byte, iface common.NetworkInterface)
t.mutex.RUnlock()
if !exists {
log.Printf("[DEBUG-3] No destination registered for hash %x", destHash)
debug.Log(debug.DEBUG_INFO, "No destination registered for hash", "hash", fmt.Sprintf("%x", destHash))
return
}
log.Printf("[DEBUG-5] Found registered destination for %x", destHash)
debug.Log(debug.DEBUG_TRACE, "Found registered destination", "hash", fmt.Sprintf("%x", destHash))
// Handle the incoming link request
t.handleIncomingLinkRequest(pkt, destIface, iface)
@@ -972,27 +968,27 @@ func (t *Transport) handleLinkPacket(data []byte, iface common.NetworkInterface)
// Handle regular link packets (for established links)
if link := t.findLink(destHash); link != nil {
log.Printf("[DEBUG-6] Routing packet to established link")
debug.Log(debug.DEBUG_PACKETS, "Routing packet to established link")
if link.packetCb != nil {
log.Printf("[DEBUG-7] Executing packet callback with %d bytes", len(pkt.Data))
debug.Log(debug.DEBUG_ALL, "Executing packet callback", "bytes", len(pkt.Data))
link.packetCb(pkt.Data, pkt)
}
} else {
log.Printf("[DEBUG-5] No established link found for destination %x", destHash)
debug.Log(debug.DEBUG_TRACE, "No established link found for destination", "hash", fmt.Sprintf("%x", destHash))
}
}
func (t *Transport) handleIncomingLinkRequest(pkt *packet.Packet, destIface interface{}, networkIface common.NetworkInterface) {
log.Printf("[DEBUG-5] Handling incoming link request")
debug.Log(debug.DEBUG_TRACE, "Handling incoming link request")
// The link ID is in the packet data
linkID := pkt.Data
if len(linkID) == 0 {
log.Printf("[DEBUG-3] No link ID in link request packet")
debug.Log(debug.DEBUG_INFO, "No link ID in link request packet")
return
}
log.Printf("[DEBUG-5] Link request with ID %x", linkID[:8])
debug.Log(debug.DEBUG_TRACE, "Link request with ID", "id", fmt.Sprintf("%x", linkID[:8]))
// Call the destination's link established callback directly
// Use reflection to call the method if it exists
@@ -1005,19 +1001,19 @@ func (t *Transport) handleIncomingLinkRequest(pkt *packet.Packet, destIface inte
if len(results) > 0 && !results[0].IsNil() {
// The callback is of type common.LinkEstablishedCallback which is func(interface{})
callback := results[0].Interface().(common.LinkEstablishedCallback)
log.Printf("[DEBUG-4] Calling destination's link established callback")
debug.Log(debug.DEBUG_VERBOSE, "Calling destination's link established callback")
callback(linkID)
} else {
log.Printf("[DEBUG-5] No link established callback set on destination")
debug.Log(debug.DEBUG_TRACE, "No link established callback set on destination")
}
} else {
log.Printf("[DEBUG-3] Destination does not have GetLinkCallback method")
debug.Log(debug.DEBUG_INFO, "Destination does not have GetLinkCallback method")
}
} else {
log.Printf("[DEBUG-3] Invalid destination object")
debug.Log(debug.DEBUG_INFO, "Invalid destination object")
}
log.Printf("[DEBUG-4] Link request handled successfully")
debug.Log(debug.DEBUG_VERBOSE, "Link request handled successfully")
}
func (t *Transport) handlePathResponse(data []byte, iface common.NetworkInterface) {
@@ -1058,37 +1054,36 @@ func (t *Transport) SendPacket(p *packet.Packet) error {
t.mutex.RLock()
defer t.mutex.RUnlock()
log.Printf("[DEBUG-4] Sending packet - Type: 0x%02x, Header: %d", p.PacketType, p.HeaderType)
debug.Log(debug.DEBUG_VERBOSE, "Sending packet", "type", fmt.Sprintf("0x%02x", p.PacketType), "header", p.HeaderType)
data, err := p.Serialize()
if err != nil {
log.Printf("[DEBUG-3] Packet serialization failed: %v", err)
debug.Log(debug.DEBUG_INFO, "Packet serialization failed", "error", err)
return fmt.Errorf("failed to serialize packet: %w", err)
}
log.Printf("[DEBUG-5] Serialized packet size: %d bytes", len(data))
debug.Log(debug.DEBUG_TRACE, "Serialized packet size", "bytes", len(data))
// Use the DestinationHash field directly for path lookup
destHash := p.DestinationHash
if len(destHash) > 16 {
destHash = destHash[:16]
}
log.Printf("[DEBUG-6] Destination hash: %x", destHash)
debug.Log(debug.DEBUG_PACKETS, "Destination hash", "hash", fmt.Sprintf("%x", destHash))
path, exists := t.paths[string(destHash)]
if !exists {
log.Printf("[DEBUG-3] No path found for destination %x", destHash)
debug.Log(debug.DEBUG_INFO, "No path found for destination", "hash", fmt.Sprintf("%x", destHash))
return errors.New("no path to destination")
}
log.Printf("[DEBUG-5] Using path - Interface: %s, Next hop: %x, Hops: %d",
path.Interface.GetName(), path.NextHop, path.HopCount)
debug.Log(debug.DEBUG_TRACE, "Using path", "interface", path.Interface.GetName(), "nextHop", fmt.Sprintf("%x", path.NextHop), "hops", path.HopCount)
if err := path.Interface.Send(data, ""); err != nil {
log.Printf("[DEBUG-3] Failed to send packet: %v", err)
debug.Log(debug.DEBUG_INFO, "Failed to send packet", "error", err)
return fmt.Errorf("failed to send packet: %w", err)
}
log.Printf("[DEBUG-7] Packet sent successfully")
debug.Log(debug.DEBUG_ALL, "Packet sent successfully")
return nil
}
@@ -1257,8 +1252,8 @@ func (l *Link) GetStatus() int {
}
func CreateAnnouncePacket(destHash []byte, identity *identity.Identity, appData []byte, destName string, hops byte, config *common.ReticulumConfig) []byte {
log.Printf("[DEBUG-3] Creating announce packet for %s", destName)
log.Printf("[DEBUG-3] Input: destHash=%x, appData=%s, hops=%d", destHash[:8], string(appData), hops)
debug.Log(debug.DEBUG_INFO, "Creating announce packet", "destName", destName)
debug.Log(debug.DEBUG_INFO, "Input", "destHash", fmt.Sprintf("%x", destHash[:8]), "appData", string(appData), "hops", hops)
// Create header (2 bytes)
headerByte := byte(
@@ -1270,79 +1265,77 @@ func CreateAnnouncePacket(destHash []byte, identity *identity.Identity, appData
PACKET_TYPE_ANNOUNCE, // Packet type (0x01)
)
log.Printf("[DEBUG-7] Created header byte: 0x%02x, hops: %d", headerByte, hops)
debug.Log(debug.DEBUG_ALL, "Created header byte", "header", fmt.Sprintf("0x%02x", headerByte), "hops", hops)
packet := []byte{headerByte, hops}
log.Printf("[DEBUG-7] Initial packet size: %d bytes", len(packet))
debug.Log(debug.DEBUG_ALL, "Initial packet size", "bytes", len(packet))
// Add destination hash (16 bytes)
if len(destHash) > 16 {
destHash = destHash[:16]
}
log.Printf("[DEBUG-7] Adding destination hash (16 bytes): %x", destHash)
debug.Log(debug.DEBUG_ALL, "Adding destination hash (16 bytes)", "hash", fmt.Sprintf("%x", destHash))
packet = append(packet, destHash...)
log.Printf("[DEBUG-7] Packet size after adding destination hash: %d bytes", len(packet))
debug.Log(debug.DEBUG_ALL, "Packet size after adding destination hash", "bytes", len(packet))
// Get full public key and split into encryption and signing keys
pubKey := identity.GetPublicKey()
encKey := pubKey[:32] // x25519 public key for encryption
signKey := pubKey[32:] // Ed25519 public key for signing
log.Printf("[DEBUG-7] Full public key: %x", pubKey)
debug.Log(debug.DEBUG_ALL, "Full public key", "key", fmt.Sprintf("%x", pubKey))
// Add encryption key (32 bytes)
log.Printf("[DEBUG-7] Adding encryption key (32 bytes): %x", encKey)
debug.Log(debug.DEBUG_ALL, "Adding encryption key (32 bytes)", "key", fmt.Sprintf("%x", encKey))
packet = append(packet, encKey...)
log.Printf("[DEBUG-7] Packet size after adding encryption key: %d bytes", len(packet))
debug.Log(debug.DEBUG_ALL, "Packet size after adding encryption key", "bytes", len(packet))
// Add signing key (32 bytes)
log.Printf("[DEBUG-7] Adding signing key (32 bytes): %x", signKey)
debug.Log(debug.DEBUG_ALL, "Adding signing key (32 bytes)", "key", fmt.Sprintf("%x", signKey))
packet = append(packet, signKey...)
log.Printf("[DEBUG-7] Packet size after adding signing key: %d bytes", len(packet))
debug.Log(debug.DEBUG_ALL, "Packet size after adding signing key", "bytes", len(packet))
// Add name hash (10 bytes)
nameHash := sha256.Sum256([]byte(destName))
log.Printf("[DEBUG-7] Adding name hash (10 bytes) for %s: %x", destName, nameHash[:10])
debug.Log(debug.DEBUG_ALL, "Adding name hash (10 bytes)", "destName", destName, "hash", fmt.Sprintf("%x", nameHash[:10]))
packet = append(packet, nameHash[:10]...)
log.Printf("[DEBUG-7] Packet size after adding name hash: %d bytes", len(packet))
debug.Log(debug.DEBUG_ALL, "Packet size after adding name hash", "bytes", len(packet))
// Add random hash (10 bytes)
randomBytes := make([]byte, 5)
_, err := rand.Read(randomBytes) // #nosec G104
if err != nil {
log.Printf("[DEBUG-7] Failed to read random bytes: %v", err)
debug.Log(debug.DEBUG_ALL, "Failed to read random bytes", "error", err)
return nil // Or handle the error appropriately
}
timeBytes := make([]byte, 8)
binary.BigEndian.PutUint64(timeBytes, uint64(time.Now().Unix())) // #nosec G115
log.Printf("[DEBUG-7] Adding random hash (10 bytes): %x%x", randomBytes, timeBytes[:5])
debug.Log(debug.DEBUG_ALL, "Adding random hash (10 bytes)", "random", fmt.Sprintf("%x", randomBytes), "time", fmt.Sprintf("%x", timeBytes[:5]))
packet = append(packet, randomBytes...)
packet = append(packet, timeBytes[:5]...)
log.Printf("[DEBUG-7] Packet size after adding random hash: %d bytes", len(packet))
debug.Log(debug.DEBUG_ALL, "Packet size after adding random hash", "bytes", len(packet))
// Create msgpack array for app data
nameBytes := []byte(destName)
appDataMsg := []byte{0x92} // array of 2 elements
// Add name as first element
appDataMsg = append(appDataMsg, 0xc4) // bin 8 format
appDataMsg = append(appDataMsg, byte(len(nameBytes))) // length
appDataMsg = append(appDataMsg, 0xc4, byte(len(nameBytes)))
appDataMsg = append(appDataMsg, nameBytes...)
// Add app data as second element
appDataMsg = append(appDataMsg, 0xc4) // bin 8 format
appDataMsg = append(appDataMsg, byte(len(appData))) // length
appDataMsg = append(appDataMsg, 0xc4, byte(len(appData)))
appDataMsg = append(appDataMsg, appData...)
// Create signature over destination hash and app data
signData := append(destHash, appDataMsg...)
signature := identity.Sign(signData)
log.Printf("[DEBUG-7] Adding signature (64 bytes): %x", signature)
debug.Log(debug.DEBUG_ALL, "Adding signature (64 bytes)", "signature", fmt.Sprintf("%x", signature))
packet = append(packet, signature...)
log.Printf("[DEBUG-7] Packet size after adding signature: %d bytes", len(packet))
debug.Log(debug.DEBUG_ALL, "Packet size after adding signature", "bytes", len(packet))
// Finally add the app data message
packet = append(packet, appDataMsg...)
log.Printf("[DEBUG-3] Final packet size: %d bytes", len(packet))
log.Printf("[DEBUG-3] appDataMsg: %x (len=%d)", appDataMsg, len(appDataMsg))
debug.Log(debug.DEBUG_INFO, "Final packet size", "bytes", len(packet))
debug.Log(debug.DEBUG_INFO, "appDataMsg", "data", fmt.Sprintf("%x", appDataMsg), "len", len(appDataMsg))
return packet
}