Hitting Error Dictionary insertion distance too far: 65535

Zeek
1

Hello everyone,

I’m new to Zeek, and I’m trying to process large pcap files using zeek -r <pcap>. Currently, since my pcap file too large to process in one run, I’m using editcap to split them into manageable chunks that are a few gigabytes each. However, when I run Zeek, I get this specific error:

  • Dictionary (size 30158043) insertion distance too far: 65535

I haven’t changed the default configurations for Zeek, and this seems like an internal hash table issue in the C++ code. I read through the Zeek changelog and found this comment for version 4.1.0-dev.554:

When choosing poor/aggressive values for `table_expire_interval`,
    `table_expire_delay`, and/or `table_incremental_step` that tend to
    leave tables in state of constant table-expiry-iteration, the underlying
    Dictionary is never allowed the chance to complete remapping operations
    which re-position entries to more ideal locations (e.g. after
    reallocating the table to be able to store more entries).

I haven’t changed any of the values for the above mentioned variables, so I’m curious what I can do to mitigate or resolve this error and get a little more background on it, or if I have to adjust my approach/settings. Any help to understand/resolve this issue better would be very much appreciated!

2

Hey @rachit - thanks a lot for the report. Are you able to reliably reproduce this?

That message/crash should produce a coredump. Are you in a position to run gdb on it and could share a backtrace?

(gdb) bt -full

Remove the -full if it’s too much data, or sanitize if it looks like it contains sensitive data. The -full flag might help to grasp what’s going on better.

~30 mio entries is fairly large. Maybe the backtrace allows to figure out which table is involved. It shouldn’t ever result in an abort like that though.

If you’re on Ubuntu/Debian/Fedora Linux, easiest these days is probably to install systemd-coredump, run your pipeline to the crash, then coredumpctl list + coredumpctl debug to work with the coredumps.

Curious what you’ll report!

Here’s a link from a while back - mostly for reference: copy() of table with 10mio (and 5.0mio and 2.3mio) entries: fatal error: Dictionary (size 1452082) insertion distance too far: 65535 · Issue #2386 · zeek/zeek · GitHub

3

While trying to repro this I ran into a probably orthogonal issue.

Possibly related, there seem to be issues when dictionaries grow large.

event zeek_init()
	{
	local xs: table[count] of count;

	local i = 0;
	while ( i < 100000000 )
		{
		xs[i] = i;
		++i;
		}
	}

For me eventually this fails in a Debug build with

32786296
32786297
32786298
32786299

Thread 1 "zeek" received signal SIGSEGV, Segmentation fault.
zeek::detail::DictEntry<zeek::TableEntryVal>::Empty (this=0x8000003c0) at /root/src/zeek/src/include/zeek/Dict.h:130
130         bool Empty() const { return distance == TOO_FAR_TO_REACH; }

Interestingly, memory usage seems to go up slowly at first, but quickly shoots up towards the end.

#0  zeek::detail::DictEntry<zeek::TableEntryVal>::Empty (this=0x8000003c0) at /root/src/zeek/src/include/zeek/Dict.h:130
No locals.
#1  0x0000555557e4a762 in zeek::Dictionary<zeek::TableEntryVal>::Remap (this=0x555559df80d0) at /root/src/zeek/src/include/zeek/Dict.h:1370
        left = 16
#2  0x0000555557e4a30d in zeek::Dictionary<zeek::TableEntryVal>::Insert (this=0x555559df80d0, key=0x5555f6e62e20, key_size=8, hash=12684133978465182291, val=0x5555f6e62d80, copy_key=false, iterators_invalidated=0x7fffffffb387) at /root/src/zeek/src/include/zeek/Dict.h:647
        v = 0x0
        insert_position = 18220270
        insert_distance = 31
        position = -1
#3  0x0000555557e31556 in zeek::Dictionary<zeek::TableEntryVal>::Insert (this=0x555559df80d0, key=0x55555a529750, val=0x5555f6e62d80, iterators_invalidated=0x7fffffffb387) at /root/src/zeek/src/include/zeek/Dict.h:549
No locals.
#4  0x0000555557e1d942 in zeek::TableVal::Assign (this=0x555559df8b40, index=..., k=std::unique_ptr<zeek::detail::HashKey> = {...}, new_val=..., broker_forward=true, iterators_invalidated=0x7fffffffb387) at /root/src/zeek/src/Val.cc:1834
        is_set = false
        new_entry_val = 0x5555f6e62d80
        k_copy = {key_u = {b = 240, i = -21008, bi = 140737488334320, bu = 140737488334320, u32 = 4294946288, d = 6.9533558067970712e-310, p = 0x7fffffffadf0}, key = 0x5555f6e62dd0 "{G\364\001", hash = 12684133978465182291, key_size = 8, is_our_dynamic = true, write_size = 8, read_size = 0}
        old_entry_val = 0x5555f6e62df0
#5  0x0000555557e1a6ce in zeek::TableVal::Assign (this=0x555559df8b40, index=..., new_val=..., broker_forward=true, iterators_invalidated=0x7fffffffb387) at /root/src/zeek/src/Val.cc:1822
        k = std::unique_ptr<zeek::detail::HashKey> = {get() = 0x0}
#6  0x0000555557c995ec in zeek::detail::assign_to_index (v1=..., v2=..., v3=..., iterators_invalidated=@0x7fffffffb387: false) at /root/src/zeek/src/Expr.cc:320
        v_extra = {ptr_ = 0x5555f6e62df0}
#7  0x0000555557c98cd0 in zeek::detail::Expr::AssignToIndex (this=0x55555a2956d0, v1=..., v2=..., v3=...) at /root/src/zeek/src/Expr.cc:248
        iterators_invalidated = false
        error_msg = 0x5555f6e62df0 "p\245sXUU"
#8  0x0000555557cac4f9 in zeek::detail::IndexExpr::Assign (this=0x55555a2956d0, f=0x7fffffffbb40, v=...) at /root/src/zeek/src/Expr.cc:2784
        v1 = {ptr_ = 0x555559df8b40}
        v2 = {ptr_ = 0x555559df7db0}
#9  0x0000555557ca8317 in zeek::detail::RefExpr::Assign (this=0x55555a295850, f=0x7fffffffbb40, v=...) at /root/src/zeek/src/Expr.cc:2267
No locals.
#10 0x0000555557ca99e5 in zeek::detail::AssignExpr::Eval (this=0x55555a295800, f=0x7fffffffbb40) at /root/src/zeek/src/Expr.cc:2442
        v = {ptr_ = 0x5555f6e62df0}
#11 0x0000555557dcd5f5 in zeek::detail::ExprStmt::Exec (this=0x55555a295930, f=0x7fffffffbb40, flow=@0x7fffffffba5f: zeek::detail::FLOW_NEXT) at /root/src/zeek/src/Stmt.cc:380
        v = {ptr_ = 0x5555576f44d9 <_ZN9__gnu_cxxeqIPN4zeek12IntrusivePtrINS1_6detail4StmtEEESt6vectorIS5_SaIS5_EEEEbRKNS_17__normal_iteratorIT_T0_EESF_QrqXeqcldtfp_4baseEcldtfp0_4baseERSt14convertible_toIbEE+41>}
#12 0x0000555557dd466d in zeek::detail::StmtList::Exec (this=0x55555a295060, f=0x7fffffffbb40, flow=@0x7fffffffba5f: zeek::detail::FLOW_NEXT) at /root/src/zeek/src/Stmt.cc:1426
        stmt = 0x55555a295930
        result = {ptr_ = 0x0}
        stmt_ptr = @0x55555a29be98: {ptr_ = 0x55555a295930}
        __range2 = std::vector of length 3, capacity 4 = {{ptr_ = 0x55555a295350}, {ptr_ = 0x55555a295930}, {ptr_ = 0x55555a295b60}}
        __begin2 = {ptr_ = 0x55555a295930}
        __end2 = {ptr_ = 0x7963696c6f}
#13 0x0000555557dd15fd in zeek::detail::WhileStmt::Exec (this=0x55555a295c10, f=0x7fffffffbb40, flow=@0x7fffffffba5f: zeek::detail::FLOW_NEXT) at /root/src/zeek/src/Stmt.cc:1000
        cond = {ptr_ = 0x55555888def0}
        rval = {ptr_ = 0x0}
#14 0x0000555557dd466d in zeek::detail::StmtList::Exec (this=0x5555595427a0, f=0x7fffffffbb40, flow=@0x7fffffffba5f: zeek::detail::FLOW_NEXT) at /root/src/zeek/src/Stmt.cc:1426
        stmt = 0x55555a295c10
        result = {ptr_ = 0x0}
        stmt_ptr = @0x555559541da0: {ptr_ = 0x55555a295c10}
        __range2 = std::vector of length 3, capacity 4 = {{ptr_ = 0x555559542620}, {ptr_ = 0x55555a294e10}, {ptr_ = 0x55555a295c10}}
        __begin2 = {ptr_ = 0x55555a295c10}
        __end2 = {ptr_ = 0x0}
#15 0x0000555557dd466d in zeek::detail::StmtList::Exec (this=0x55555a295cf0, f=0x7fffffffbb40, flow=@0x7fffffffba5f: zeek::detail::FLOW_NEXT) at /root/src/zeek/src/Stmt.cc:1426
        stmt = 0x5555595427a0
        result = {ptr_ = 0x0}
        stmt_ptr = @0x55555a295e78: {ptr_ = 0x5555595427a0}
Quit
#0  zeek::detail::DictEntry<zeek::TableEntryVal>::Empty (this=0x8000003c0) at /root/src/zeek/src/include/zeek/Dict.h:130
No locals.
#1  0x0000555557e4a762 in zeek::Dictionary<zeek::TableEntryVal>::Remap (this=0x555559df80d0) at /root/src/zeek/src/include/zeek/Dict.h:1370
        left = 16
#2  0x0000555557e4a30d in zeek::Dictionary<zeek::TableEntryVal>::Insert (this=0x555559df80d0, key=0x5555f6e62e20, key_size=8, hash=12684133978465182291, val=0x5555f6e62d80, copy_key=false, iterators_invalidated=0x7fffffffb387) at /root/src/zeek/src/include/zeek/Dict.h:647
        v = 0x0
        insert_position = 18220270
        insert_distance = 31
        position = -1
#3  0x0000555557e31556 in zeek::Dictionary<zeek::TableEntryVal>::Insert (this=0x555559df80d0, key=0x55555a529750, val=0x5555f6e62d80, iterators_invalidated=0x7fffffffb387) at /root/src/zeek/src/include/zeek/Dict.h:549
No locals.
#4  0x0000555557e1d942 in zeek::TableVal::Assign (this=0x555559df8b40, index=..., k=std::unique_ptr<zeek::detail::HashKey> = {...}, new_val=..., broker_forward=true, iterators_invalidated=0x7fffffffb387) at /root/src/zeek/src/Val.cc:1834
        is_set = false
        new_entry_val = 0x5555f6e62d80
        k_copy = {key_u = {b = 240, i = -21008, bi = 140737488334320, bu = 140737488334320, u32 = 4294946288, d = 6.9533558067970712e-310, p = 0x7fffffffadf0}, key = 0x5555f6e62dd0 "{G\364\001", hash = 12684133978465182291, key_size = 8, is_our_dynamic = true, write_size = 8, read_size = 0}
        old_entry_val = 0x5555f6e62df0
#5  0x0000555557e1a6ce in zeek::TableVal::Assign (this=0x555559df8b40, index=..., new_val=..., broker_forward=true, iterators_invalidated=0x7fffffffb387) at /root/src/zeek/src/Val.cc:1822
        k = std::unique_ptr<zeek::detail::HashKey> = {get() = 0x0}
#6  0x0000555557c995ec in zeek::detail::assign_to_index (v1=..., v2=..., v3=..., iterators_invalidated=@0x7fffffffb387: false) at /root/src/zeek/src/Expr.cc:320
        v_extra = {ptr_ = 0x5555f6e62df0}
#7  0x0000555557c98cd0 in zeek::detail::Expr::AssignToIndex (this=0x55555a2956d0, v1=..., v2=..., v3=...) at /root/src/zeek/src/Expr.cc:248
        iterators_invalidated = false
        error_msg = 0x5555f6e62df0 "p\245sXUU"
#8  0x0000555557cac4f9 in zeek::detail::IndexExpr::Assign (this=0x55555a2956d0, f=0x7fffffffbb40, v=...) at /root/src/zeek/src/Expr.cc:2784
        v1 = {ptr_ = 0x555559df8b40}
        v2 = {ptr_ = 0x555559df7db0}
#9  0x0000555557ca8317 in zeek::detail::RefExpr::Assign (this=0x55555a295850, f=0x7fffffffbb40, v=...) at /root/src/zeek/src/Expr.cc:2267
No locals.
#10 0x0000555557ca99e5 in zeek::detail::AssignExpr::Eval (this=0x55555a295800, f=0x7fffffffbb40) at /root/src/zeek/src/Expr.cc:2442
        v = {ptr_ = 0x5555f6e62df0}
#11 0x0000555557dcd5f5 in zeek::detail::ExprStmt::Exec (this=0x55555a295930, f=0x7fffffffbb40, flow=@0x7fffffffba5f: zeek::detail::FLOW_NEXT) at /root/src/zeek/src/Stmt.cc:380
        v = {ptr_ = 0x5555576f44d9 <_ZN9__gnu_cxxeqIPN4zeek12IntrusivePtrINS1_6detail4StmtEEESt6vectorIS5_SaIS5_EEEEbRKNS_17__normal_iteratorIT_T0_EESF_QrqXeqcldtfp_4baseEcldtfp0_4baseERSt14convertible_toIbEE+41>}
#12 0x0000555557dd466d in zeek::detail::StmtList::Exec (this=0x55555a295060, f=0x7fffffffbb40, flow=@0x7fffffffba5f: zeek::detail::FLOW_NEXT) at /root/src/zeek/src/Stmt.cc:1426
        stmt = 0x55555a295930
        result = {ptr_ = 0x0}
        stmt_ptr = @0x55555a29be98: {ptr_ = 0x55555a295930}
        __range2 = std::vector of length 3, capacity 4 = {{ptr_ = 0x55555a295350}, {ptr_ = 0x55555a295930}, {ptr_ = 0x55555a295b60}}
        __begin2 = {ptr_ = 0x55555a295930}
        __end2 = {ptr_ = 0x7963696c6f}
#13 0x0000555557dd15fd in zeek::detail::WhileStmt::Exec (this=0x55555a295c10, f=0x7fffffffbb40, flow=@0x7fffffffba5f: zeek::detail::FLOW_NEXT) at /root/src/zeek/src/Stmt.cc:1000
        cond = {ptr_ = 0x55555888def0}
        rval = {ptr_ = 0x0}
#14 0x0000555557dd466d in zeek::detail::StmtList::Exec (this=0x5555595427a0, f=0x7fffffffbb40, flow=@0x7fffffffba5f: zeek::detail::FLOW_NEXT) at /root/src/zeek/src/Stmt.cc:1426
        stmt = 0x55555a295c10
        result = {ptr_ = 0x0}
        stmt_ptr = @0x555559541da0: {ptr_ = 0x55555a295c10}
        __range2 = std::vector of length 3, capacity 4 = {{ptr_ = 0x555559542620}, {ptr_ = 0x55555a294e10}, {ptr_ = 0x55555a295c10}}
        __begin2 = {ptr_ = 0x55555a295c10}
        __end2 = {ptr_ = 0x0}
#15 0x0000555557dd466d in zeek::detail::StmtList::Exec (this=0x55555a295cf0, f=0x7fffffffbb40, flow=@0x7fffffffba5f: zeek::detail::FLOW_NEXT) at /root/src/zeek/src/Stmt.cc:1426
        stmt = 0x5555595427a0
        result = {ptr_ = 0x0}
        stmt_ptr = @0x55555a295e78: {ptr_ = 0x5555595427a0}
Quit
Continuing.
Couldn't get registers: No such process.
[Thread 0x7fffe1ffb6c0 (LWP 11554) exited]
[Thread 0x7fffe27fc6c0 (LWP 11553) exited]
[Thread 0x7fffe2ffd6c0 (LWP 11552) exited]
[Thread 0x7fffe37fe6c0 (LWP 11551) exited]
[Thread 0x7fffe3fff6c0 (LWP 11550) exited]
[Thread 0x7ffff08f66c0 (LWP 11549) exited]
[Thread 0x7ffff10f76c0 (LWP 11548) exited]
[Thread 0x7ffff18f86c0 (LWP 11547) exited]
[Thread 0x7ffff29ff6c0 (LWP 11546) exited]
Quit

Program terminated with signal SIGSEGV, Segmentation fault.
The program no longer exists.
Quit
quit
4

Hi @awelzel,

I don’t think I’m currently in a position to run gdb and perform a backtrace. I’m running this on a HPC, currently takes about ~3 hours to split the pcap I am trying to process into smaller pcaps, which are approx. ~380 gb in size and processed for another ~1.5 hours before crashing. I’m thinking it may be an issue where there is too much data to process.

5

It seems to consistently fail after 30 million entries, I believe I could have more data than that in each of my files.

6

I’m curious which table this is about. I’m attaching a script below that introduces a new log that periodically reports the “footprints” (i.e., approximate sizes) of global containers in the script layer. You could try that one and see if one works its way up to those ~30M entries.

(Btw, I think we should get that log/script into the Zeek tree — we’ve been handing that out somewhat regularly.)

footprints.zeek.gz (615 Bytes)

7

I ran the footprints.zeek on my pcap and what’s interesting is that I don’t see a table that goes all the way up to 30M entries. I’ve uploaded the file here in case anyone is able to spot and see an issue, but this is puzzling. The max table size I’m seeing is ~18000 items, so now I’m a little confused.

footprints.log.zip (4.1 KB) Expanded: 15KB

8

The max table size I’m seeing is ~18000 items

This is actually the footprint, not the number of entries. Can be a bit confusing. The highest values are all from const tables that aren’t expected to grow at runtime.

1747313999.999999  zeek  SSL::cipher_desc                             1920
1747313999.999999  zeek  SSL::root_certs                              5553
1747313999.999999  zeek  SMB::statuses                                17282
1747313999.999999  zeek  DCE_RPC::operations                          17998

It is very likely that it is a table/set that is attached to a particular connection instead. There is a zeek-conn-footprint package that produces a conn_footprint.log for tracking the size/state attached to individual connections. Could you install this one and see if any particular connections shows as very large. I’m fairly sure a 30M table entry attached to a connection will be visible. Would be interesting which protocol is involved, etc to possibly make a reproducer easier.