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.

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

improve(trace): incorporate the new logger #277

Merged
merged 138 commits into from
Oct 8, 2024
Merged
Show file tree
Hide file tree
Changes from 105 commits
Commits
Show all changes
138 commits
Select commit Hold shift + click to select a range
8afbc2f
Exploring new tracing
dadepo Aug 25, 2024
2330ef6
Committed files
dadepo Aug 25, 2024
6558f7a
How polymorphism via a vtable might look
dadepo Aug 26, 2024
5c233e7
Added multiple methods
dadepo Aug 27, 2024
e163930
Run log through channel
dadepo Aug 28, 2024
7176238
Switch to RecycleFBA
dadepo Aug 29, 2024
73c9148
Run logWithFields through channel
dadepo Aug 29, 2024
fdd78f8
Moved all methods
dadepo Aug 29, 2024
c0e98ba
Fix garbled text
dadepo Aug 29, 2024
211ad58
Remove chaining implementation
dadepo Aug 29, 2024
8a1091e
Use allocated memory to also construct key value
dadepo Aug 30, 2024
da350df
Some renaming
dadepo Aug 30, 2024
bde034c
Seitching scope
dadepo Aug 30, 2024
10a883e
Partial fix of leak
dadepo Aug 30, 2024
7085987
Fix leak
dadepo Sep 1, 2024
1825d74
Add level guard
dadepo Sep 1, 2024
e31caf5
Remove todo
dadepo Sep 1, 2024
d5ad7a1
Added static dispatch polymorphism
dadepo Sep 1, 2024
852c407
Rename variable
dadepo Sep 1, 2024
4a7c0f1
Allocate based on size of fmt message
dadepo Sep 1, 2024
74ef498
Pass log message as a reference
dadepo Sep 2, 2024
1dec7e2
Added test logger that tests formats of log message
dadepo Sep 2, 2024
49aa9a4
Move struct used for testing inside testing block
dadepo Sep 3, 2024
cd663e2
Merge branch 'main' into dade/trace-ng
dadepo Sep 3, 2024
7443030
Reset alloc_allocator on print
dadepo Sep 3, 2024
e0b38ab
Pass log message as a value and not reference
dadepo Sep 3, 2024
e111011
Fmt
dadepo Sep 3, 2024
b4f0e83
Snake case for variable
dadepo Sep 3, 2024
41cf812
Take the scope as a string
dadepo Sep 4, 2024
52229ab
Use if expressions
dadepo Sep 4, 2024
3089747
Renaming
dadepo Sep 4, 2024
fda382a
Move custom logic from interface into implementation
dadepo Sep 4, 2024
d164389
Have the union fields as pointers and removed use of ptrCast
dadepo Sep 4, 2024
847553e
Removed use of @ptrCast in test logger
dadepo Sep 5, 2024
826eb0d
Made scoping function public
dadepo Sep 5, 2024
bff2d81
Remove the recycle_fba allocator from the test allocator
dadepo Sep 5, 2024
5c47daa
Merge branch 'main' into dade/trace-ng
dadepo Sep 5, 2024
862dfc3
Removed recyclefba from test logger
dadepo Sep 5, 2024
c4b59af
Switch to use updated API for RecycleFBA
dadepo Sep 5, 2024
ff57936
Do not panic in standard logger but ignore the errors
dadepo Sep 5, 2024
1b52a7f
Drop the spawn method
dadepo Sep 5, 2024
6f2bcd4
Return error on inti instead of panic
dadepo Sep 5, 2024
26f97ba
Add methods
dadepo Sep 5, 2024
dd1e13b
Fix warnfWithFields
dadepo Sep 6, 2024
06d3257
Estimate field size and not hardcode to 512
dadepo Sep 6, 2024
7c233b8
Fmt
dadepo Sep 6, 2024
81d38a6
Removed unused line
dadepo Sep 6, 2024
0be2b8a
Test logger does not need the max_buffer
dadepo Sep 6, 2024
2c6d054
Removed last @ptrCast and some minor clean ups
dadepo Sep 8, 2024
792e8bb
Implementation out of the union
dadepo Sep 8, 2024
33a9877
Removed unintended diff
dadepo Sep 8, 2024
eeb08bd
Hack to ensure child logs show up in std err
dadepo Sep 8, 2024
615f5c2
Ensure the test logger is only used in tests
dadepo Sep 8, 2024
fa0d2bf
Remove panic from unscoped and scope
dadepo Sep 8, 2024
890133f
Do not ignore errors but fallback to std.debug.print
dadepo Sep 9, 2024
990c827
Typo
dadepo Sep 10, 2024
0a52225
Fixed hidden broken compilation
dadepo Sep 10, 2024
460cf27
Have implementation as struct instead of type functions
dadepo Sep 10, 2024
3c23009
Limit the scope of holding the lock on std err
dadepo Sep 10, 2024
822c6c3
Remove the sleep
dadepo Sep 10, 2024
610ec6a
Switched to pattern of concrete instance turning itself to interface
dadepo Sep 11, 2024
45c4535
Moved the write out of the loop
dadepo Sep 11, 2024
7d576d4
Typo
dadepo Sep 11, 2024
5d929f1
Update scope switch test
dadepo Sep 11, 2024
3f957bd
First batch of changes
dadepo Sep 25, 2024
bc8e087
Another batch of integrating the new logger
dadepo Sep 26, 2024
c4f1089
Remove instances of the old trace module
dadepo Sep 26, 2024
7adc6ae
fmt
dadepo Sep 26, 2024
2eba6ac
Renamed trace_ng to trace
dadepo Sep 26, 2024
44ba2e0
Check in trace_ng renamed to trace
dadepo Sep 26, 2024
867fe81
Remove listing error sets
dadepo Sep 26, 2024
e6f3f13
Pass the Logger by value
dadepo Sep 27, 2024
dce2620
clean up in db.zig
dadepo Sep 27, 2024
08ef07e
clean up in fuzz.zig
dadepo Sep 27, 2024
3749449
clean up in cmd.zig
dadepo Sep 27, 2024
45f5e4d
Update test assertion
dadepo Sep 27, 2024
f635331
clean up in hard_forks.zig
dadepo Sep 27, 2024
c81ffe7
clean up in shred.zig
dadepo Sep 27, 2024
073efd3
clean up in fuzz_service.zig
dadepo Sep 27, 2024
9f9ab97
clean up in fuzz_table.zig
dadepo Sep 27, 2024
8506384
clean up in fuzz.zig
dadepo Sep 27, 2024
5d2e570
clean up in service.zig
dadepo Sep 28, 2024
47c7520
clean up in database.zig
dadepo Sep 28, 2024
934bc7a
clean up in insert_shred.zig
dadepo Sep 28, 2024
6ecc150
clean up in socket_utils.zig
dadepo Sep 28, 2024
46f37a6
clean up in repair_service.zig
dadepo Sep 28, 2024
7c5c933
clean up in shred_tracker.zig
dadepo Sep 28, 2024
adf356b
clean up in estimate.zig
dadepo Sep 28, 2024
1de8e7c
errdefer instead of defer
dadepo Sep 29, 2024
bddfd5a
Switch API to support chaining for fields
dadepo Oct 3, 2024
7729aaa
Fix up
dadepo Oct 3, 2024
8140b79
No need to have nooLoop var
dadepo Oct 3, 2024
714203e
Update comment
dadepo Oct 3, 2024
ca4f401
Remove the need for fmt
dadepo Oct 3, 2024
372b431
Merge branch 'main' into dade/trace-ng-incorporated
dadepo Oct 3, 2024
45f370c
Fixes after merge
dadepo Oct 3, 2024
a0709e3
Merge branch 'main' into dade/trace-ng-incorporated
dadepo Oct 3, 2024
f711750
Remove unused
dadepo Oct 3, 2024
92c9193
Tem comment out code
dadepo Oct 3, 2024
b973626
Compile fix
dadepo Oct 4, 2024
dc73e6d
Renaming
dadepo Oct 4, 2024
333ec70
Use Config only ChannelPrintLogger
dadepo Oct 4, 2024
df7c40b
Pass by value for Entry instead of allocating
dadepo Oct 4, 2024
5c0d6b6
Rename variable
dadepo Oct 4, 2024
6b4f83c
deinit the entry after logging
dadepo Oct 4, 2024
c169ada
Fix bus error
dadepo Oct 4, 2024
27dbee6
Switching to init the noop logger by variant
dadepo Oct 4, 2024
f0dab3b
Merge branch 'main' into dade/trace-ng-incorporated
dadepo Oct 4, 2024
b1cf3dd
Remove unused import
dadepo Oct 4, 2024
4d11e71
Fix .noop
dadepo Oct 4, 2024
0521d9e
Fix test
dadepo Oct 4, 2024
38f6b45
Set max_buffer to 1GB
dadepo Oct 4, 2024
7858152
Pull out import
dadepo Oct 5, 2024
022d191
Do not redefine std.ArrayList(u8) as Fields
dadepo Oct 5, 2024
9626fb3
Rename exit_sig to exit
dadepo Oct 5, 2024
0652a39
Revert commented out tests
dadepo Oct 5, 2024
4e7da44
Have fields show in logs
dadepo Oct 5, 2024
8df4876
Merge branch 'main' into dade/trace-ng-incorporated
dadepo Oct 7, 2024
15dcfda
Elide union name when setting the noop variant
dadepo Oct 7, 2024
2b3fc8a
Move Self alias to after fields
dadepo Oct 7, 2024
dc7e69a
Fixes after merge conflict
dadepo Oct 7, 2024
c5a2545
Replace places where empty format args are used in logs
dadepo Oct 7, 2024
753d17e
Added trace
dadepo Oct 7, 2024
4e0edfa
Create the writer in same scope as the lock
dadepo Oct 7, 2024
cef4177
Newline between method definition
dadepo Oct 7, 2024
4339d4b
Print the fallthrough type using any
dadepo Oct 7, 2024
aee8d3c
No need to capture logger as a pointer in deinit
dadepo Oct 7, 2024
3d822fc
Return DirectPrintLogger by value
dadepo Oct 8, 2024
a6174ff
use same branch for test logger and noop
dadepo Oct 8, 2024
d660e48
Merge branch 'main' into dade/trace-ng-incorporated
dadepo Oct 8, 2024
3ce117b
More removal of empty fmt args after merge
dadepo Oct 8, 2024
1f87c92
Remove unused variables
dadepo Oct 8, 2024
6e7d706
Fixes after merge conflict
dadepo Oct 8, 2024
2460920
fix(trace): require comptime message for log to avoid lifetime issues
dnut Oct 8, 2024
2869887
perf(trace): reduce allocations when formatting fields
dnut Oct 8, 2024
a60d760
fix(trace): warn bug, and don't print in tests
dnut Oct 8, 2024
8c1837f
refactor(trace): consistent names for direct and channel print loggers
dnut Oct 8, 2024
ea98bbd
fix(trace): use after free when log message is freed before being sen…
dnut Oct 8, 2024
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
121 changes: 62 additions & 59 deletions src/accountsdb/db.zig

Large diffs are not rendered by default.

33 changes: 20 additions & 13 deletions src/accountsdb/download.zig
Original file line number Diff line number Diff line change
Expand Up @@ -164,7 +164,9 @@ pub fn downloadSnapshotsFromGossip(
output_dir: std.fs.Dir,
min_mb_per_sec: usize,
) !void {
logger.infof("starting snapshot download with min download speed: {d} MB/s", .{min_mb_per_sec});
logger
.info()
.logf("starting snapshot download with min download speed: {d} MB/s", .{min_mb_per_sec});

// TODO: maybe make this bigger? or dynamic?
var contact_info_buf: [1_000]ThreadSafeContactInfo = undefined;
Expand Down Expand Up @@ -208,7 +210,9 @@ pub fn downloadSnapshotsFromGossip(
i += r.len;
}
}
logger.infof("searched for snapshot peers: {s}", .{write_buf[0..i]});
logger
.info()
.logf("searched for snapshot peers: {s}", .{write_buf[0..i]});
}

for (available_snapshot_peers.items) |peer| {
Expand All @@ -230,7 +234,10 @@ pub fn downloadSnapshotsFromGossip(
});
defer allocator.free(snapshot_url);

logger.infof("downloading full_snapshot from: {s}", .{snapshot_url});
logger
.info()
.logf("downloading full_snapshot from: {s}", .{snapshot_url});

downloadFile(
allocator,
logger,
Expand All @@ -244,11 +251,11 @@ pub fn downloadSnapshotsFromGossip(
// downloadFile function
error.Unexpected => {},
error.TooSlow => {
logger.infof("peer is too slow, skipping", .{});
logger.info().logf("peer is too slow, skipping", .{});
try slow_peer_pubkeys.append(peer.contact_info.pubkey);
},
else => {
logger.infof("failed to download full_snapshot: {s}", .{@errorName(err)});
logger.info().logf("failed to download full_snapshot: {s}", .{@errorName(err)});
},
}
continue;
Expand All @@ -271,7 +278,7 @@ pub fn downloadSnapshotsFromGossip(
});
defer allocator.free(inc_snapshot_url);

logger.infof("downloading inc_snapshot from: {s}", .{inc_snapshot_url});
logger.info().logf("downloading inc_snapshot from: {s}", .{inc_snapshot_url});
_ = downloadFile(
allocator,
logger,
Expand All @@ -282,13 +289,13 @@ pub fn downloadSnapshotsFromGossip(
null,
) catch |err| {
// failure here is ok (for now?)
logger.warnf("failed to download inc_snapshot: {s}", .{@errorName(err)});
logger.warn().logf("failed to download inc_snapshot: {s}", .{@errorName(err)});
return;
};
}

// success
logger.infof("snapshot downloaded finished", .{});
logger.info().logf("snapshot downloaded finished", .{});
return;
}
}
Expand Down Expand Up @@ -359,7 +366,7 @@ const DownloadProgress = struct {
// each MB
const mb_read = self.bytes_read / 1024 / 1024;
if (mb_read == 0) {
self.logger.infof("download speed is too slow (<1MB/s) -- disconnecting", .{});
self.logger.info().logf("download speed is too slow (<1MB/s) -- disconnecting", .{});
return 0;
}

Expand All @@ -379,14 +386,14 @@ const DownloadProgress = struct {
self.has_checked_speed = true;
if (mb_per_second < self.min_mb_per_second.?) {
// not fast enough => abort
self.logger.infof("[download progress]: speed is too slow ({d} MB/s) -- disconnecting", .{mb_per_second});
self.logger.info().logf("[download progress]: speed is too slow ({d} MB/s) -- disconnecting", .{mb_per_second});
return 0;
} else {
self.logger.infof("[download progress]: speed is ok ({d} MB/s) -- maintaining", .{mb_per_second});
self.logger.info().logf("[download progress]: speed is ok ({d} MB/s) -- maintaining", .{mb_per_second});
}
}

self.logger.infof("[download progress]: {d}% done ({d} MB/s - {d}/{d}) (time left: {d})", .{
self.logger.info().logf("[download progress]: {d}% done ({d} MB/s - {d}/{d}) (time left: {d})", .{
self.file_memory_index * 100 / self.download_size,
mb_per_second,
self.file_memory_index,
Expand Down Expand Up @@ -437,7 +444,7 @@ pub fn downloadFile(
if (try head_resp.getHeader("content-length")) |content_length| {
download_size = try std.fmt.parseInt(usize, content_length.get(), 10);
} else {
logger.debugf("header request didnt have content-length...", .{});
logger.debug().logf("header request didnt have content-length...", .{});
dnut marked this conversation as resolved.
Show resolved Hide resolved
return error.NoContentLength;
}

Expand Down
26 changes: 16 additions & 10 deletions src/accountsdb/fuzz.zig
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,8 @@ const zstd = @import("zstd");

const AccountsDB = sig.accounts_db.AccountsDB;
const Logger = sig.trace.Logger;
const StandardErrLogger = sig.trace.ChannelPrintLogger;
const Level = sig.trace.Level;
const Account = sig.core.Account;
const Slot = sig.core.time.Slot;
const Pubkey = sig.core.pubkey.Pubkey;
Expand Down Expand Up @@ -55,9 +57,14 @@ pub fn run(seed: u64, args: *std.process.ArgIterator) !void {
defer _ = gpa_state.deinit();
const allocator = gpa_state.allocator();

const logger = Logger.init(allocator, .debug);
defer logger.deinit();
logger.spawn();
var std_logger = StandardErrLogger.init(.{
.allocator = allocator,
.max_level = Level.debug,
.max_buffer = 2048,
}) catch @panic("Logger init failed");
defer std_logger.deinit();

const logger = std_logger.logger();

const use_disk = rand.boolean();

Expand Down Expand Up @@ -248,14 +255,14 @@ pub fn run(seed: u64, args: *std.process.ArgIterator) !void {

try sig.accounts_db.snapshots.parallelUnpackZstdTarBall(
allocator,
.noop,
Logger{ .noop = {} },
archive_file,
alternative_snapshot_dir,
5,
true,
);

logger.infof("fuzz[validate]: unpacked full snapshot at slot: {}", .{snapshot_info.slot});
logger.info().logf("fuzz[validate]: unpacked full snapshot at slot: {}", .{snapshot_info.slot});
var snapshot_files: sig.accounts_db.SnapshotFiles = .{
.full_snapshot = .{
.hash = snapshot_info.hash,
Expand Down Expand Up @@ -296,16 +303,15 @@ pub fn run(seed: u64, args: *std.process.ArgIterator) !void {

const inc_archive_file = try alternative_snapshot_dir.openFile(inc_archive_name.slice(), .{});
defer inc_archive_file.close();

try sig.accounts_db.snapshots.parallelUnpackZstdTarBall(
allocator,
.noop,
Logger{ .noop = {} },
inc_archive_file,
alternative_snapshot_dir,
5,
true,
);
logger.infof("fuzz[validate]: unpacked inc snapshot at slot: {}", .{inc_snapshot_info.slot});
logger.info().logf("fuzz[validate]: unpacked inc snapshot at slot: {}", .{inc_snapshot_info.slot});

snapshot_files.incremental_snapshot = .{
.base_slot = inc_snapshot_info.base_slot,
Expand All @@ -323,12 +329,12 @@ pub fn run(seed: u64, args: *std.process.ArgIterator) !void {
);
defer snapshot_fields.deinit(allocator);

var alt_accounts_db = try AccountsDB.init(allocator, .noop, alternative_snapshot_dir, accounts_db.config, null);
var alt_accounts_db = try AccountsDB.init(allocator, Logger{ .noop = {} }, alternative_snapshot_dir, accounts_db.config, null);
defer alt_accounts_db.deinit();

_ = try alt_accounts_db.loadWithDefaults(allocator, &snapshot_fields, 1, true, 1_500);
const maybe_inc_slot = if (snapshot_files.incremental_snapshot) |inc| inc.slot else null;
logger.infof("loaded and validated snapshot at slot: {} (and inc snapshot @ slot {any})", .{ snapshot_info.slot, maybe_inc_slot });
logger.info().logf("loaded and validated snapshot at slot: {} (and inc snapshot @ slot {any})", .{ snapshot_info.slot, maybe_inc_slot });
}
}

Expand Down
6 changes: 3 additions & 3 deletions src/accountsdb/snapshots.zig
Original file line number Diff line number Diff line change
Expand Up @@ -1745,7 +1745,7 @@ pub const AllSnapshotFields = struct {
const rel_path_bounded = sig.utils.fmt.boundedFmt("snapshots/{0}/{0}", .{files.full_snapshot.slot});
const rel_path = rel_path_bounded.constSlice();

logger.infof("reading snapshot fields from: {s}", .{sig.utils.fmt.tryRealPath(snapshot_dir, rel_path)});
logger.info().logf("reading snapshot fields from: {s}", .{sig.utils.fmt.tryRealPath(snapshot_dir, rel_path)});

const full_file = try snapshot_dir.openFile(rel_path, .{});
defer full_file.close();
Expand All @@ -1759,7 +1759,7 @@ pub const AllSnapshotFields = struct {
const rel_path_bounded = sig.utils.fmt.boundedFmt("snapshots/{0}/{0}", .{incremental_snapshot_path.slot});
const rel_path = rel_path_bounded.constSlice();

logger.infof("reading inc snapshot fields from: {s}", .{sig.utils.fmt.tryRealPath(snapshot_dir, rel_path)});
logger.info().logf("reading inc snapshot fields from: {s}", .{sig.utils.fmt.tryRealPath(snapshot_dir, rel_path)});

const incremental_file = try snapshot_dir.openFile(rel_path, .{});
defer incremental_file.close();
Expand All @@ -1769,7 +1769,7 @@ pub const AllSnapshotFields = struct {

break :blk incremental_fields;
} else {
logger.info("no incremental snapshot fields found");
logger.info().log("no incremental snapshot fields found");
break :blk null;
}
};
Expand Down
1 change: 0 additions & 1 deletion src/benchmarks.zig
Original file line number Diff line number Diff line change
Expand Up @@ -12,7 +12,6 @@ const meta = std.meta;
/// zig build benchmark -- gossip
pub fn main() !void {
const allocator = std.heap.c_allocator;
logger.default_logger.* = logger.Logger.init(allocator, .debug);

if (builtin.mode == .Debug) std.debug.print("warning: running benchmark in Debug mode\n", .{});

Expand Down
Loading
Loading