Skip to content

Commit c1bf7d4

Browse files
Add tiered debug logging to NUClearNet
Introduce Log.hpp/Log.cpp with off-through-trace levels and instrument Discovery and NUClearNet for handshake, wire, and lifecycle events. Windows WSABUF/sendmsg and socket rebind behaviour are unchanged. Co-authored-by: Cursor <cursoragent@cursor.com>
1 parent 38a3f2d commit c1bf7d4

5 files changed

Lines changed: 323 additions & 2 deletions

File tree

src/nuclearnet/Discovery.cpp

Lines changed: 56 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -29,15 +29,27 @@
2929
#include <map>
3030
#include <mutex>
3131
#include <set>
32+
#include <sstream>
3233
#include <string>
3334
#include <utility>
3435
#include <vector>
3536

37+
#include "Log.hpp"
3638
#include "wire_protocol.hpp"
3739

3840
namespace NUClear {
3941
namespace network {
4042

43+
namespace {
44+
45+
std::string connect_flags_str(uint8_t flags) {
46+
std::ostringstream msg;
47+
msg << "SYN=" << ((flags & SYN) != 0 ? '1' : '0') << " ACK=" << ((flags & CON_ACK) != 0 ? '1' : '0');
48+
return msg.str();
49+
}
50+
51+
} // namespace
52+
4153
Discovery::Discovery(std::chrono::steady_clock::duration peer_timeout) : peer_timeout(peer_timeout) {}
4254

4355
void Discovery::set_join_callback(JoinCallback cb) {
@@ -109,6 +121,10 @@
109121

110122
// Minimum size: header(5) + name_length(2) + num_subscriptions(2) = 9
111123
if (length < sizeof(PacketHeader) + sizeof(uint16_t) + sizeof(uint16_t)) {
124+
if (should_log(LogLevel::Warn)) {
125+
log(LogLevel::Warn, "discovery",
126+
"short ANNOUNCE from " + sock_str(source) + " len=" + std::to_string(length));
127+
}
112128
return announce_result;
113129
}
114130

@@ -168,6 +184,10 @@
168184
// New peer — record with announce_heard = true and initiate handshake
169185
announce_result.is_new = true;
170186
announce_result.response_flags = SYN;
187+
if (should_log(LogLevel::Debug)) {
188+
log(LogLevel::Debug, "discovery",
189+
"new peer from announce name=" + name + " " + sock_str(source));
190+
}
171191
PeerInfo info;
172192
info.name = name;
173193
info.address = source;
@@ -190,6 +210,10 @@
190210
if (peer.subscriptions != subscriptions) {
191211
peer.subscriptions = std::move(subscriptions);
192212
subs_changed = true;
213+
if (should_log(LogLevel::Debug)) {
214+
log(LogLevel::Debug, "discovery",
215+
"subscriptions changed for " + peer.name + " " + sock_str(source));
216+
}
193217
}
194218

195219
// Mark announce as heard (may trigger connection if data was already confirmed)
@@ -221,6 +245,10 @@
221245

222246
// Fire callbacks outside the lock
223247
if (fire_join && join_callback) {
248+
if (should_log(LogLevel::Debug)) {
249+
log(LogLevel::Debug, "discovery",
250+
"join (announce path) name=" + join_info.name + " " + sock_str(join_info.address));
251+
}
224252
join_callback(join_info);
225253
}
226254
if (subs_changed && subscription_change_callback) {
@@ -259,6 +287,10 @@
259287

260288
// Only fire leave callback for peers that completed the handshake
261289
if (was_connected && leave_callback) {
290+
if (should_log(LogLevel::Debug)) {
291+
log(LogLevel::Debug, "discovery",
292+
"leave (packet) name=" + removed.name + " " + sock_str(source));
293+
}
262294
leave_callback(removed);
263295
}
264296
}
@@ -288,6 +320,7 @@
288320

289321
const bool has_syn = (flags & SYN) != 0;
290322
const bool has_ack = (flags & CON_ACK) != 0;
323+
const auto old_state = peer.handshake;
291324

292325
switch (peer.handshake) {
293326
case HandshakeState::IDLE:
@@ -350,10 +383,25 @@
350383
}
351384
break;
352385
}
386+
387+
if (should_log(LogLevel::Debug) && peer.handshake != old_state) {
388+
std::ostringstream msg;
389+
msg << "handshake " << sock_str(source);
390+
if (!peer.name.empty()) {
391+
msg << " name=" << peer.name;
392+
}
393+
msg << ' ' << handshake_str(old_state) << " -> " << handshake_str(peer.handshake) << " ("
394+
<< connect_flags_str(flags) << ')';
395+
log(LogLevel::Debug, "discovery", msg.str());
396+
}
353397
}
354398

355399
// Fire join callback outside the lock
356400
if (fire_join && join_callback) {
401+
if (should_log(LogLevel::Debug)) {
402+
log(LogLevel::Debug, "discovery",
403+
"join (connect path) name=" + info.name + " " + sock_str(info.address));
404+
}
357405
join_callback(info);
358406
}
359407

@@ -365,6 +413,10 @@
365413
auto it = peers.find(address);
366414
if (it != peers.end() && it->second.handshake == HandshakeState::IDLE) {
367415
it->second.handshake = HandshakeState::SYN_SENT;
416+
if (should_log(LogLevel::Debug)) {
417+
log(LogLevel::Debug, "discovery",
418+
"handshake " + sock_str(address) + " IDLE -> SYN_SENT (sent SYN)");
419+
}
368420
}
369421
}
370422

@@ -406,6 +458,10 @@
406458
// Fire leave callbacks outside the lock
407459
if (leave_callback) {
408460
for (const auto& peer : removed) {
461+
if (should_log(LogLevel::Info)) {
462+
log(LogLevel::Info, "discovery",
463+
"peer timeout name=" + peer.name + " " + sock_str(peer.address));
464+
}
409465
leave_callback(peer);
410466
}
411467
}

src/nuclearnet/Log.cpp

Lines changed: 85 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,85 @@
1+
/*
2+
* MIT License
3+
*
4+
* Copyright (c) 2025 NUClear Contributors
5+
*
6+
* This file is part of the NUClear codebase.
7+
* See https://github.com/Fastcode/NUClear for further info.
8+
*
9+
* Permission is hereby granted, free of charge, to any person obtaining a copy of this software and associated
10+
* documentation files (the "Software"), to deal in the Software without restriction, including without limitation the
11+
* rights to use, copy, modify, merge, publish, distribute, sublicense, and/or sell copies of the Software, and to
12+
* permit persons to whom the Software is furnished to do so, subject to the following conditions:
13+
*
14+
* The above copyright notice and this permission notice shall be included in all copies or substantial portions of the
15+
* Software.
16+
*
17+
* THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE
18+
* WARRANTIES OF MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR
19+
* COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR
20+
* OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.
21+
*/
22+
23+
#include "Log.hpp"
24+
25+
#include <cstdio>
26+
#include <iostream>
27+
28+
namespace NUClear {
29+
namespace network {
30+
31+
namespace {
32+
33+
std::atomic<int> g_log_level{static_cast<int>(LogLevel::Off)};
34+
35+
const char* level_name(LogLevel level) {
36+
switch (level) {
37+
case LogLevel::Error: return "error";
38+
case LogLevel::Warn: return "warn";
39+
case LogLevel::Info: return "info";
40+
case LogLevel::Debug: return "debug";
41+
case LogLevel::Trace: return "trace";
42+
default: return "off";
43+
}
44+
}
45+
46+
} // namespace
47+
48+
void set_log_level(LogLevel level) {
49+
g_log_level.store(static_cast<int>(level), std::memory_order_relaxed);
50+
}
51+
52+
LogLevel get_log_level() {
53+
return static_cast<LogLevel>(g_log_level.load(std::memory_order_relaxed));
54+
}
55+
56+
void log(LogLevel level, const char* component, const std::string& message) {
57+
if (!should_log(level)) {
58+
return;
59+
}
60+
std::cerr << "[NUClearNet:" << component << "] " << level_name(level) << " " << message << std::endl;
61+
}
62+
63+
std::string hash_hex(uint64_t hash) {
64+
char buf[19];
65+
std::snprintf(buf, sizeof(buf), "0x%016llx", static_cast<unsigned long long>(hash));
66+
return buf;
67+
}
68+
69+
std::string sock_str(const util::network::sock_t& address) {
70+
const auto addr = address.address();
71+
return addr.first + ":" + std::to_string(addr.second);
72+
}
73+
74+
const char* handshake_str(HandshakeState state) {
75+
switch (state) {
76+
case HandshakeState::IDLE: return "IDLE";
77+
case HandshakeState::SYN_SENT: return "SYN_SENT";
78+
case HandshakeState::SYN_RECEIVED: return "SYN_RECEIVED";
79+
case HandshakeState::CONFIRMED: return "CONFIRMED";
80+
}
81+
return "UNKNOWN";
82+
}
83+
84+
} // namespace network
85+
} // namespace NUClear

src/nuclearnet/Log.hpp

Lines changed: 61 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,61 @@
1+
/*
2+
* MIT License
3+
*
4+
* Copyright (c) 2025 NUClear Contributors
5+
*
6+
* This file is part of the NUClear codebase.
7+
* See https://github.com/Fastcode/NUClear for further info.
8+
*
9+
* Permission is hereby granted, free of charge, to any person obtaining a copy of this software and associated
10+
* documentation files (the "Software"), to deal in the Software without restriction, including without limitation the
11+
* rights to use, copy, modify, merge, publish, distribute, sublicense, and/or sell copies of the Software, and to
12+
* permit persons to whom the Software is furnished to do so, subject to the following conditions:
13+
*
14+
* The above copyright notice and this permission notice shall be included in all copies or substantial portions of the
15+
* Software.
16+
*
17+
* THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE
18+
* WARRANTIES OF MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR
19+
* COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR
20+
* OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.
21+
*/
22+
23+
#ifndef NUCLEAR_NETWORK_LOG_HPP
24+
#define NUCLEAR_NETWORK_LOG_HPP
25+
26+
#include <atomic>
27+
#include <cstdint>
28+
#include <string>
29+
30+
#include "../util/network/sock_t.hpp"
31+
#include "Discovery.hpp"
32+
33+
namespace NUClear {
34+
namespace network {
35+
36+
enum class LogLevel : int {
37+
Off = 0,
38+
Error = 1,
39+
Warn = 2,
40+
Info = 3,
41+
Debug = 4,
42+
Trace = 5,
43+
};
44+
45+
void set_log_level(LogLevel level);
46+
LogLevel get_log_level();
47+
48+
inline bool should_log(LogLevel level) {
49+
return static_cast<int>(level) <= static_cast<int>(get_log_level());
50+
}
51+
52+
void log(LogLevel level, const char* component, const std::string& message);
53+
54+
std::string hash_hex(uint64_t hash);
55+
std::string sock_str(const util::network::sock_t& address);
56+
const char* handshake_str(HandshakeState state);
57+
58+
} // namespace network
59+
} // namespace NUClear
60+
61+
#endif // NUCLEAR_NETWORK_LOG_HPP

0 commit comments

Comments
 (0)