gossip: Random test failure in gossip test "test filtering values works"

[InKryption]

Description

At random, this line in the referenced test will fail:

sig/src/gossip/pull_response.zig

Line 143 in a5d1f34

try std.testing.expect(values.items.len > 0);

I currently do not have a stacktrace demonstrating this behavior, because I do not know the circumstances under which this failure occurs.

How to Reproduce the Bug

run zig build test -Dfilter="gossip.pull_response: test filtering values works" and pray

Additional Context

It should be noted that the function being tested, named filterSignedGossipDatas, currently instantiates and uses a PRNG seeded with std.time.milliTimeStamp(), which could explain its seemingly random and unreproducible behavior.

What would be ideal is capturing a stack trace of this occurring, as well as the exact or approximate timestamp at which this failure occurs, to diagnose what random values can cause such a failure, and identify what circumstances they lead to which must be guarded against.

At the time of writing I plan on pushing a change which would help in the above goals, without needing to actively search for this mythical seed.

[InKryption]

Sorry, I'd like to keep this open until we actually have it solved. The code for helping us solve it is in place, it just needs to randomly occur at some point, or the code needs to fundamentally change such that we can guarantee it won't.

[0xNineteen]

just hit it - The failing seed is: '1718031575764'

[InKryption]

Can confirm that using '1718031575764' as the seed consistently reproduces the failure state.

[dnut]

another one: (first in list below)

EDIT: i'll keep adding them to this list as i see them:

• 1718158590375
• 1718222336881 - https://github.com/Syndica/sig/actions/runs/9488897880/job/26148935704?pr=169
• 1719352543210
• 1722821236448
• 1723807968723
• 1723808235839
• 1724081935104
• 1724091552560
• 1725458185024 673b49b
• 1725487805635 45dab91
• 1727471104408 37b55a7 https://github.com/Syndica/sig/actions/runs/11077669767/job/30783449012?pr=278
• https://github.com/Syndica/sig/actions/runs/11470631449/job/31920161135?pr=329

[InKryption]

Can't reproduce the behavior using '1718158590375'.

[InKryption]

I just noticed there's another non-deterministic element, the filter parameter:

sig/src/gossip/pull_response.zig

Line 136 in 488fb37

&filter,

generated here:

sig/src/gossip/pull_response.zig

Lines 102 to 110 in 488fb37

	var filters = try buildGossipPullFilters(
	std.testing.allocator,
	&gossip_table_rw,
	&failed_pull_hashes,
	max_bytes,
	100,
	);
	defer deinitGossipPullFilters(&filters);
	var filter = filters.items[0];

is random as well, because of this chain of code:

• buildGossipPullFilters calls:

  sig/src/gossip/pull_request.zig

  Line 37 in 94f2212

  var filter_set = try GossipPullFilterSet.init(alloc, num_items, bloom_size);

• GossipPullFilterSet.init calls:

  sig/src/gossip/pull_request.zig

  Lines 102 to 107 in 94f2212

  	const filter = try Bloom.random(
  	alloc,
  	@intFromFloat(max_items),
  	FALSE_RATE,
  	@intFromFloat(bloom_size_bits),
  	);

• Bloom.random does this:

  sig/src/bloom/bloom.zig

  Lines 94 to 101 in 94f2212

  	const seed = @as(u64, @intCast(std.time.milliTimestamp()));
  	var rnd = RndGen.init(seed);
  	var keys = try ArrayList(u64).initCapacity(alloc, n_keys);
  	for (0..n_keys) |_| {
  	const v = rnd.random().int(u64);
  	keys.appendAssumeCapacity(v);
  	}

which means there's another source of RNG also based on std.time.milliTimestamp.

I think we should do an audit on this, and overall replace all uses of std.time.milliTimestamp as a seed that aren't obviously at the highest level of code, with a std.Random interface parameter, or a pointer to a concrete PRNG implementation if specific random behavior is desired/required.

[0xNineteen]

yeah pulling out the random seeds to deterministic would be good - we can create a ticket - kind of low priority right now

https://github.com/orgs/Syndica/projects/2/views/1?pane=issue&itemId=67168458

[InKryption]

New failing seed caught in CI:
https://github.com/Syndica/sig/actions/runs/9811929838/job/27094994026?pr=189
Seed number is '1720202203195'.

[InKryption]

https://github.com/Syndica/sig/actions/runs/9897406056/job/27341819918#step:4:1

We got another one: '1720726415143'

[dnut]

This is still a problem. I saw a failure on the latest commit for seed 1725458185024. See my comment above for a list I'll keep updating as I see more failures.