Bug 293241 - sys/netpfil/ipfw/log:bpf test fails intermittently in CI
Summary: sys/netpfil/ipfw/log:bpf test fails intermittently in CI
Status: Closed FIXED
Alias: None
Product: Base System
Classification: Unclassified
Component: tests (show other bugs)
Version: 16.0-CURRENT
Hardware: Any Any
: --- Affects Only Me
Assignee: Gleb Smirnoff
URL:
Keywords: regression
Depends on:
Blocks:
 
Reported: 2026-02-17 15:25 UTC by Siva Mahadevan
Modified: 2026-02-19 06:56 UTC (History)
2 users (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Siva Mahadevan freebsd_committer freebsd_triage 2026-02-17 15:25:35 UTC
The 'sys/netpfil/ipfw/log:bpf' testcase fails intermittently in CI:


===> sys/netpfil/ipfw/log:bpf
Result:     atf-check failed; see the output of the test for details
 
Standard output: 
00100 count log udp from any to any 10100
00200 count log udp from any to any 10200
00201 count log udp from any to any 10201
Executing command [ sh -c wait ; exit 0 ]
Executing command [ sh -c wait ; exit 0 ]
Executing command [ sh -c wait ; exit 0 ]
Executing command [ sh -c wait ; exit 0 ]
Executing command [ tcpdump -nr /tmp/kyua.YpTMju/8744/work/100.pcap ]
Cleaning
 
Standard error: 
tcpdump: listening on ipfw100, link-type EN10MB (Ethernet), snapshot length 262144 bytes
tcpdump: listening on ipfw301, link-type EN10MB (Ethernet), snapshot length 262144 bytes
tcpdump: listening on ipfw200, link-type EN10MB (Ethernet), snapshot length 262144 bytes
tcpdump: listening on ipfw201, link-type EN10MB (Ethernet), snapshot length 262144 bytes
1 packet captured
1 packet received by filter
0 packets dropped by kernel
1 packet captured
1 packet received by filter
0 packets dropped by kernel
1 packet captured
1 packet received by filter
0 packets dropped by kernel
Fail: incorrect exit status: 1, expected: 0
stdout:

stderr:
tcpdump: truncated dump file; tried to read 4 file header bytes, only got 0


I have reproduced this error using Bricoler with 100 runs for good measure:

$ bricoler run freebsd-src-regression-suite --param freebsd-src:url=/usr/src --param freebsd-src:branch= --param freebsd-src-regression-suite:hypervisor=bhyve --param freebsd-src-regression-suite:memory=4096 --param freebsd-src-regression-suite:ncpus=2 --param freebsd-src-regression-suite:parallelism=1 --param freebsd-src-regression-suite:count=100 --param freebsd-src-regression-suite:tests='sys/netpfil/ipfw/log:bpf'

@glebius, since you added the test in https://cgit.freebsd.org/src/commit/?id=35caa56a329deb0d13aa48ea1a6f7c1d5ebdb073 (tests/ipfw: add a test for ipfw(4) log rules that write to bpf(4)), please triage as necessary.
Comment 1 Gleb Smirnoff freebsd_committer freebsd_triage 2026-02-17 22:50:08 UTC
I was able to reproduce that. Sometimes one of the 4 tcpdump processes doesn't capture a packet and doesn't write it to file. I have added ktrace to see what's going on. The result is really surprising to me:

  4795 tcpdump  0.026949729 CALL  cap_enter
  4795 tcpdump  0.026952795 RET   cap_enter 0
  4795 tcpdump  0.026955109 CALL  read(0x3,0x2ffc0362a980,0x80000)
  4795 tcpdump  0.054705876 RET   read RESTART
  4795 tcpdump  0.054708762 PSIG  SIGKILL SIG_DFL code=SI_NOINFO

Something immediately kills one of the tcpdumps. Digging further.
Comment 2 Gleb Smirnoff freebsd_committer freebsd_triage 2026-02-18 18:39:46 UTC
It is kyua that kills. I digged down to the fact that sometimes a packet is counted by ipfw(4), but bpf reader (tcpdump) doesn't receive it, hence it keeps sleeping in read(2) until Kyua kills. Digging further...
Comment 3 commit-hook freebsd_committer freebsd_triage 2026-02-19 02:55:50 UTC
A commit in branch main references this bug:

URL: https://cgit.FreeBSD.org/src/commit/?id=38edf96b1787ce3d8c00e4466348dab891c7a9ea

commit 38edf96b1787ce3d8c00e4466348dab891c7a9ea
Author:     Gleb Smirnoff <glebius@FreeBSD.org>
AuthorDate: 2026-02-19 02:39:00 +0000
Commit:     Gleb Smirnoff <glebius@FreeBSD.org>
CommitDate: 2026-02-19 02:53:16 +0000

    tests/ipfw: fix log:bpf test flakyness

    There were several problems:

    o Using 'netstat -B' is not a reliable way to make sure that all tcpdumps
      have attached to bpf(4).  The problem is that tcpdump (via libpcap) does
      several ioctl(2)s after the attach including two BIOCSETF.  Each of them
      flushes the input buffer.  So we can see tcpdump attached in 'netstat -B'
      and start sending packets and the packet will be captured by bpf(4)
      before BIOCSETF and freed and tcpdump won't read anything.  Instead of
      using netstat(1), use ps(1) and make sure each tcpdump is blocked on the
      "bpf" wait channel, which guarantees it is done with ioctl(2)s and is now
      blocked in read(2).
    o Using 'nc -w 0' sets timeout not only on the connect(2) (as documented)
      but also on poll(2), which is not documented.  There is a race in shell
      that will make stdin not yet filled by 'echo foo' when nc(1) does
      poll(2).  With zero timeout, this poll(2) will immediately return and nc
      will exit.
    o The waiting loop had two errors: using wrong variable name as well as
      invoking a subshell, that actually can't wait on the pid.
    o The reading tcpdump was lacking '-q' option, that prevents any protocol
      interpretations.  Sometimes, when random port chosen by nc(1) would
      match some well-known (to tcpdump) port, the output would differ from
      the expected.

    PR:     293241

 tests/sys/netpfil/ipfw/log.sh | 19 +++++++++++--------
 1 file changed, 11 insertions(+), 8 deletions(-)