read_bbrlog

This utility is designed to read data generated by BBR and placed into the black box. It by default will read from the black box logging directory and process record files in sucession for the selected flow (generated by tcplog_dumper). It generates a textual file that describes the events and processes that BBR went through during processing of a connection.

Build instruction

Need bbparse library. From a recent FreeBSD head|current:

pkg install bbparse
make

Usage example

Files generated by tcplog_dumper have the name format following this example:

UNKNOWN_5201_172.16.18.20_14257.514.pcapng.xz

On this example, we can instruct read_bbrlog to display the BBR event related to the file serie ID 'UNKNOWN_5201_172.16.18.20_14257' with this command line:

# read_bbrlog -i UNKNOWN_5201_172.16.18.20_14257 -d /var/log/tcplog_dumps


30161875 0 [+5] IN         Acks 0 (ACK:251963130) [Nsegs:1] off:32 out:0 len_in:1448 avail:0 cw:14480 rw:65728 ts:4 (spa:5 ip:1 ack:251963130) st:0 loss:0
530161875 0 [+0] TIMERCANC  type:KEEP lineno:8699 for 12 usecs cw:14480 e:1935 pe:0 bbr_state:1-0 st:0
530161875 0 [+0] BBR_RTT_SHRINKS  RTTS Was Idle(11114) flt:0 pg:739 [Time Since PRTT 2.286]
530161875 0 [+0] TIMERSTAR  type:DACK(timer) lineno:6 for 100000(0)  cw:14480 pg:739 cg:739 pe:0 del:0 lost:0 f2:0x5000
530161875 0 [+0] BBRSND     DR:0.00 bps ltbw:14600000 rttProp:1000 sent:0 pacing_slot:0 out:0 flight:0 cw:14480 line:6 (ip:1 ii:0 ult:0)
530161875 0 [+0] DOSEG_DONE DR:0.00 bps cDR:0.00 bps do:0 np:0 wo:0 in_per:0 tmrs:DACK(0x1) cw:14480 rw:65728 ( 0) flt:0
530161879 0 [+4] IN         Acks 0 (ACK:251963130) [Nsegs:1] off:32 out:0 len_in:1448 avail:0 cw:14480 rw:65728 ts:4 (spa:4 ip:1 ack:251963130) st:0 loss:0
530161879 0 [+0] BBR_RTT_SHRINKS  RTTS Was Idle(11114) flt:0 pg:739 [Time Since PRTT 2.286]
530161879 0 [+0] TIMERCANC  type:DACK lineno:12175 for 6 usecs cw:14480 e:1935 pe:0 bbr_state:1-0 st:0
530161879 0 [+0] PKT_OUT    Sent(e:0) 251963130:0  (ACK:0) flt:0 avail:0 (spo:8 ip:0 ii:0 rdhu:0x0 116.80 Mbps(14600000) pg:739 piw:0 pd:0 d:0)
530161879 0 [+0] TIMERSTAR  type:KEEP(timer) lineno:12 for 2147483646(0)  cw:14480 pg:739 cg:739 pe:0 del:0 lost:0 f2:0x5000
530161879 0 [+0] BBRSND     DR:0.00 bps ltbw:14600000 rttProp:1000 sent:0 pacing_slot:0 out:0 flight:0 cw:14480 line:12 (ip:1 ii:0 ult:0)
530161879 0 [+0] DOSEG_DONE DR:0.00 bps cDR:0.00 bps do:1 np:0 wo:0 in_per:0 tmrs:KEEP(0x20) cw:14480 rw:65728 ( 0) flt:0
530161883 0 [+4] IN         Acks 0 (ACK:251963130) [Nsegs:1] off:32 out:0 len_in:1448 avail:0 cw:14480 rw:65728 ts:4 (spa:4 ip:^C [+0] BBRSND     DR:0.00 bps ltbw:14600000 rttProp:1000 sent:0 pacing_slot:0 out:0 flight:0 cw:14480 line:6 (ip:1 ii:0 ult:0)