Bug #6254
closedError: threads: thread "FB" failed to start in time: flags 0003
Description
suricata 7.0.0 and above thread fail to start with error below, this is when bypass set to yes as config below:
Error: threads: thread "FB" failed to start in time: flags 0003 [TmThreadWaitOnThreadRunning:tm-threads.c:1831]
af-packet: - interface: eno1 threads: 1 cluster-id: 99 cluster-type: cluster_flow defrag: yes copy-mode: ips copy-iface: eno2 xdp-mode: driver pinned-maps: true pinned-maps-name: flow_table_v4 xdp-filter-file: /usr/libexec/suricata/ebpf/xdp_filter.bpf bypass: yes use-mmap: yes ring-size: 200000 - interface: eno2 threads: 1 cluster-id: 100 cluster-type: cluster_flow defrag: yes copy-mode: ips copy-iface: eno1 xdp-mode: driver pinned-maps: true pinned-maps-name: flow_table_v4 xdp-filter-file: /usr/libexec/suricata/ebpf/xdp_filter.bpf bypass: yes use-mmap: yes ring-size: 200000
I tested suricata 6.0.9, the threads started fine with same configuration
Note to reproduce the issue, I need to have https://github.com/OISF/suricata/pull/9334 to convert legacy ebpf map to BTF ebpf map, otherwise, suricata would fail to load the xdp_filter.bpf before even get to the stage of starting the thread
one way to repro thread failure:
1 install libbpf 1.0+
2 install suricata 7.0.0/master with https://github.com/OISF/suricata/pull/9334 change
another way to repro thread failure:
1 install libbpf version 0.7
2 install suricata 7.0.0/master with https://github.com/OISF/suricata/pull/9334 change
thread working conditions:
1 install libbpf version 0.7
2 install suricata 6.0.9 with https://github.com/OISF/suricata/pull/9334 change
I have not tried libbpf 1.0+ with suricata 6.0.9, I think it should work because I suspect the bug is changes in suricata 7.0.0 and above, irrelevant to libbpf or xdp_filter code.
below is the full verbose log when thread failed to start
root@r210:/home/vincent/go/src/github.com/vincentmli/suricata# suricata -c ./suricata-ebpf.yaml --af-packet -vvv Info: conf-yaml-loader: Configuration node 'stream' redefined. [ConfYamlParse:conf-yaml-loader.c:329] Notice: suricata: This is Suricata version 7.0.1-dev (e055846c4 2023-08-03) running in SYSTEM mode [LogVersion:suricata.c:1154] Info: cpu: CPUs/cores online: 8 [UtilCpuPrintSummary:util-cpu.c:182] Config: device: Adding interface eno1 from config file [LiveBuildDeviceListCustom:util-device.c:295] Config: device: Adding interface eno2 from config file [LiveBuildDeviceListCustom:util-device.c:295] Info: af-packet: Setting IPS mode [AFPRunModeEnableIPS:runmode-af-packet.c:151] Info: exception-policy: master exception-policy set to: auto [ExceptionPolicyMasterParse:util-exception-policy.c:200] Config: exception-policy: app-layer.error-policy: drop-flow (defined via 'exception-policy' master switch) [ExceptionPolicyGetDefault:util-exception-policy.c:220] Config: app-layer-htp: 'default' server has 'request-body-minimal-inspect-size' set to 31893 and 'request-body-inspect-window' set to 4059 after randomization. [HTPConfigSetDefaultsPhase2:app-layer-htp.c:2567] Config: app-layer-htp: 'default' server has 'response-body-minimal-inspect-size' set to 41706 and 'response-body-inspect-window' set to 16429 after randomization. [HTPConfigSetDefaultsPhase2:app-layer-htp.c:2580] Config: smb: read: max record size: 16777216, max queued chunks 64, max queued size 67108864 [suricata::smb::smb::rs_smb_register_parser:smb.rs:2428] Config: smb: write: max record size: 16777216, max queued chunks 64, max queued size 67108864 [suricata::smb::smb::rs_smb_register_parser:smb.rs:2430] Config: app-layer-enip: Protocol detection and parser disabled for enip protocol. [RegisterENIPUDPParsers:app-layer-enip.c:539] Config: app-layer-dnp3: Protocol detection and parser disabled for DNP3. [RegisterDNP3Parsers:app-layer-dnp3.c:1565] Info: ioctl: eno1: MTU 1500 [GetIfaceMTU:util-ioctl.c:110] Info: ioctl: eno2: MTU 1500 [GetIfaceMTU:util-ioctl.c:110] Config: host: allocated 262144 bytes of memory for the host hash... 4096 buckets of size 64 [HostInitConfig:host.c:259] Config: host: preallocated 1000 hosts of size 136 [HostInitConfig:host.c:283] Config: host: host memory usage: 398144 bytes, maximum: 33554432 [HostInitConfig:host.c:285] Config: coredump-config: Core dump size set to unlimited. [CoredumpLoadConfig:util-coredump-config.c:155] Config: exception-policy: defrag.memcap-policy: drop-packet (defined via 'exception-policy' master switch) [ExceptionPolicyGetDefault:util-exception-policy.c:220] Config: defrag-hash: allocated 3670016 bytes of memory for the defrag hash... 65536 buckets of size 56 [DefragInitConfig:defrag-hash.c:254] Config: defrag-hash: preallocated 65535 defrag trackers of size 160 [DefragInitConfig:defrag-hash.c:281] Config: defrag-hash: defrag memory usage: 14155616 bytes, maximum: 33554432 [DefragInitConfig:defrag-hash.c:288] Config: exception-policy: flow.memcap-policy: drop-packet (defined via 'exception-policy' master switch) [ExceptionPolicyGetDefault:util-exception-policy.c:220] Config: flow: flow size 304, memcap allows for 441505 flows. Per hash row in perfect conditions 6 [FlowInitConfig:flow.c:674] Config: stream-tcp: stream "prealloc-sessions": 2048 (per thread) [StreamTcpInitConfig:stream-tcp.c:393] Config: stream-tcp: stream "memcap": 67108864 [StreamTcpInitConfig:stream-tcp.c:412] Config: stream-tcp: stream "midstream" session pickups: disabled [StreamTcpInitConfig:stream-tcp.c:420] Config: stream-tcp: stream "async-oneside": disabled [StreamTcpInitConfig:stream-tcp.c:428] Config: stream-tcp: stream "checksum-validation": enabled [StreamTcpInitConfig:stream-tcp.c:445] Config: exception-policy: stream.memcap-policy: drop-flow (defined via 'exception-policy' master switch) [ExceptionPolicyGetDefault:util-exception-policy.c:220] Config: exception-policy: stream.reassembly.memcap-policy: drop-flow (defined via 'exception-policy' master switch) [ExceptionPolicyGetDefault:util-exception-policy.c:220] Config: exception-policy: stream.midstream-policy: drop-flow (defined via 'exception-policy' master switch) [ExceptionPolicyGetDefault:util-exception-policy.c:220] Config: stream-tcp: stream."inline": enabled [StreamTcpInitConfig:stream-tcp.c:477] Config: stream-tcp: stream "bypass": disabled [StreamTcpInitConfig:stream-tcp.c:490] Config: stream-tcp: stream "max-syn-queued": 10 [StreamTcpInitConfig:stream-tcp.c:512] Config: stream-tcp: stream "max-synack-queued": 5 [StreamTcpInitConfig:stream-tcp.c:525] Config: stream-tcp: stream.reassembly "memcap": 268435456 [StreamTcpInitConfig:stream-tcp.c:547] Config: stream-tcp: stream.reassembly "depth": 1048576 [StreamTcpInitConfig:stream-tcp.c:565] Config: stream-tcp: stream.reassembly "toserver-chunk-size": 2670 [StreamTcpInitConfig:stream-tcp.c:638] Config: stream-tcp: stream.reassembly "toclient-chunk-size": 2468 [StreamTcpInitConfig:stream-tcp.c:640] Config: stream-tcp: stream.reassembly.raw: enabled [StreamTcpInitConfig:stream-tcp.c:652] Config: stream-tcp: stream.liberal-timestamps: disabled [StreamTcpInitConfig:stream-tcp.c:661] Config: stream-tcp-reassemble: stream.reassembly "segment-prealloc": 2048 [StreamTcpReassemblyConfig:stream-tcp-reassemble.c:491] Config: stream-tcp-reassemble: stream.reassembly "max-regions": 8 [StreamTcpReassemblyConfig:stream-tcp-reassemble.c:514] Info: conf: Running in live mode, activating unix socket [ConfUnixSocketIsEnable:util-conf.c:163] Info: logopenfile: fast output device (regular) initialized: fast.log [SCConfLogOpenGeneric:util-logopenfile.c:618] Info: logopenfile: eve-log output device (regular) initialized: eve.json [SCConfLogOpenGeneric:util-logopenfile.c:618] Config: runmodes: enabling 'eve-log' module 'alert' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'frame' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'anomaly' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'http' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'dns' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'tls' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'files' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'smtp' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'ftp' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'rdp' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'nfs' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'smb' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'tftp' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'ike' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'dcerpc' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'krb5' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'bittorrent-dht' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'snmp' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'rfb' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'sip' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'quic' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'dhcp' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'ssh' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'mqtt' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'http2' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'pgsql' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'stats' [RunModeInitializeEveOutput:runmodes.c:706] Config: runmodes: enabling 'eve-log' module 'flow' [RunModeInitializeEveOutput:runmodes.c:706] Info: logopenfile: stats output device (regular) initialized: stats.log [SCConfLogOpenGeneric:util-logopenfile.c:618] Config: landlock: Landlock is not enabled in configuration [LandlockSandboxing:util-landlock.c:183] Config: suricata: Delayed detect disabled [SetupDelayedDetect:suricata.c:2416] Config: detect: pattern matchers: MPM: ac, SPM: bm [DetectEngineCtxInitReal:detect-engine.c:2493] Config: detect: grouping: tcp-whitelist (default) 53, 80, 139, 443, 445, 1433, 3306, 3389, 6666, 6667, 8080 [DetectEngineCtxLoadConf:detect-engine.c:2904] Config: detect: grouping: udp-whitelist (default) 53, 135, 5060 [DetectEngineCtxLoadConf:detect-engine.c:2930] Config: detect: prefilter engines: MPM [DetectEngineCtxLoadConf:detect-engine.c:2960] Config: reputation: IP reputation disabled [SRepInit:reputation.c:611] Warning: detect: No rule files match the pattern /var/lib/suricata/rules/suricata.rules [ProcessSigFiles:detect-engine-loader.c:242] Config: detect: No rules loaded from suricata.rules. [SigLoadSignatures:detect-engine-loader.c:330] Warning: detect: 1 rule files specified, but no rules were loaded! [SigLoadSignatures:detect-engine-loader.c:356] Info: threshold-config: Threshold config parsed: 0 rule(s) found [SCThresholdConfParseFile:util-threshold-config.c:1112] Info: detect: 0 signatures processed. 0 are IP-only rules, 0 are inspecting packet payload, 0 inspect application layer, 0 are decoder event only [SigAddressPrepareStage1:detect-engine-build.c:1504] Config: detect: building signature grouping structure, stage 1: preprocessing rules... complete [SigAddressPrepareStage1:detect-engine-build.c:1507] Perf: detect: TCP toserver: 0 port groups, 0 unique SGH's, 0 copies [RulesGroupByPorts:detect-engine-build.c:1297] Perf: detect: TCP toclient: 0 port groups, 0 unique SGH's, 0 copies [RulesGroupByPorts:detect-engine-build.c:1297] Perf: detect: UDP toserver: 0 port groups, 0 unique SGH's, 0 copies [RulesGroupByPorts:detect-engine-build.c:1297] Perf: detect: UDP toclient: 0 port groups, 0 unique SGH's, 0 copies [RulesGroupByPorts:detect-engine-build.c:1297] Perf: detect: OTHER toserver: 0 proto groups, 0 unique SGH's, 0 copies [RulesGroupByProto:detect-engine-build.c:1051] Perf: detect: OTHER toclient: 0 proto groups, 0 unique SGH's, 0 copies [RulesGroupByProto:detect-engine-build.c:1084] Perf: detect: Unique rule groups: 0 [SigAddressPrepareStage4:detect-engine-build.c:1861] Perf: detect: Builtin MPM "toserver TCP packet": 0 [MpmStoreReportStats:detect-engine-mpm.c:1480] Perf: detect: Builtin MPM "toclient TCP packet": 0 [MpmStoreReportStats:detect-engine-mpm.c:1480] Perf: detect: Builtin MPM "toserver TCP stream": 0 [MpmStoreReportStats:detect-engine-mpm.c:1480] Perf: detect: Builtin MPM "toclient TCP stream": 0 [MpmStoreReportStats:detect-engine-mpm.c:1480] Perf: detect: Builtin MPM "toserver UDP packet": 0 [MpmStoreReportStats:detect-engine-mpm.c:1480] Perf: detect: Builtin MPM "toclient UDP packet": 0 [MpmStoreReportStats:detect-engine-mpm.c:1480] Perf: detect: Builtin MPM "other IP packet": 0 [MpmStoreReportStats:detect-engine-mpm.c:1480] Info: af-packet: eno1: AF_PACKET IPS mode activated eno1->eno2 [ParseAFPConfig:runmode-af-packet.c:344] Config: af-packet: eno1: using flow cluster mode for AF_PACKET [ParseAFPConfig:runmode-af-packet.c:388] Config: af-packet: eno1: using defrag kernel functionality for AF_PACKET [ParseAFPConfig:runmode-af-packet.c:391] Config: af-packet: eno1: using pinned maps [ParseAFPConfig:runmode-af-packet.c:445] Config: af-packet: eno1: using bypass kernel functionality for AF_PACKET [ParseAFPConfig:runmode-af-packet.c:521] Config: ebpf: Pinning: 8 to flow_table_v4 [EBPFLoadFile:util-ebpf.c:430] Config: ebpf: Pinning: 9 to flow_table_v6 [EBPFLoadFile:util-ebpf.c:430] Config: ebpf: Pinning: 10 to cpu_map [EBPFLoadFile:util-ebpf.c:430] Config: ebpf: Pinning: 11 to cpus_available [EBPFLoadFile:util-ebpf.c:430] Config: ebpf: Pinning: 12 to cpus_count [EBPFLoadFile:util-ebpf.c:430] Config: ebpf: Pinning: 13 to tx_peer [EBPFLoadFile:util-ebpf.c:430] Config: ebpf: Pinning: 14 to tx_peer_int [EBPFLoadFile:util-ebpf.c:430] Info: ebpf: Successfully loaded eBPF file '/usr/libexec/suricata/ebpf/xdp_filter.bpf' on 'eno1' [EBPFLoadFile:util-ebpf.c:461] Perf: ioctl: eno1: disabling gro offloading [DisableIfaceOffloadingLinux:util-ioctl.c:426] Perf: ioctl: eno1: disabling tso offloading [DisableIfaceOffloadingLinux:util-ioctl.c:433] Perf: ioctl: eno1: disabling gso offloading [DisableIfaceOffloadingLinux:util-ioctl.c:440] Perf: ioctl: eno1: disabling sg offloading [DisableIfaceOffloadingLinux:util-ioctl.c:447] Info: runmodes: eno1: creating 1 thread [RunModeSetLiveCaptureWorkersForDevice:util-runmodes.c:255] Info: af-packet: eno2: AF_PACKET IPS mode activated eno2->eno1 [ParseAFPConfig:runmode-af-packet.c:344] Config: af-packet: eno2: using flow cluster mode for AF_PACKET [ParseAFPConfig:runmode-af-packet.c:388] Config: af-packet: eno2: using defrag kernel functionality for AF_PACKET [ParseAFPConfig:runmode-af-packet.c:391] Config: af-packet: eno2: using pinned maps [ParseAFPConfig:runmode-af-packet.c:445] Config: af-packet: eno2: using bypass kernel functionality for AF_PACKET [ParseAFPConfig:runmode-af-packet.c:521] Config: ebpf: Pinning: 17 to flow_table_v4 [EBPFLoadFile:util-ebpf.c:430] Config: ebpf: Pinning: 18 to flow_table_v6 [EBPFLoadFile:util-ebpf.c:430] Config: ebpf: Pinning: 19 to cpu_map [EBPFLoadFile:util-ebpf.c:430] Config: ebpf: Pinning: 20 to cpus_available [EBPFLoadFile:util-ebpf.c:430] Config: ebpf: Pinning: 21 to cpus_count [EBPFLoadFile:util-ebpf.c:430] Config: ebpf: Pinning: 22 to tx_peer [EBPFLoadFile:util-ebpf.c:430] Config: ebpf: Pinning: 23 to tx_peer_int [EBPFLoadFile:util-ebpf.c:430] Info: ebpf: Successfully loaded eBPF file '/usr/libexec/suricata/ebpf/xdp_filter.bpf' on 'eno2' [EBPFLoadFile:util-ebpf.c:461] Perf: ioctl: eno2: disabling gro offloading [DisableIfaceOffloadingLinux:util-ioctl.c:426] Perf: ioctl: eno2: disabling tso offloading [DisableIfaceOffloadingLinux:util-ioctl.c:433] Perf: ioctl: eno2: disabling gso offloading [DisableIfaceOffloadingLinux:util-ioctl.c:440] Perf: ioctl: eno2: disabling sg offloading [DisableIfaceOffloadingLinux:util-ioctl.c:447] Info: runmodes: eno2: creating 1 thread [RunModeSetLiveCaptureWorkersForDevice:util-runmodes.c:255] Info: ioctl: eno2: MTU 1500 [GetIfaceMTU:util-ioctl.c:110] Info: ioctl: eno1: MTU 1500 [GetIfaceMTU:util-ioctl.c:110] Config: flow-manager: using 1 flow manager threads [FlowManagerThreadSpawn:flow-manager.c:948] Config: flow-manager: using 1 flow recycler threads [FlowRecyclerThreadSpawn:flow-manager.c:1154] Info: ebpf: IPv4 bypassed flow table size: 0 [EBPFForEachFlowV4Table:util-ebpf.c:782] Info: ebpf: IPv6 bypassed flow table size: 0 [EBPFForEachFlowV6Table:util-ebpf.c:901] Info: ebpf: IPv4 bypassed flow table size: 0 [EBPFForEachFlowV4Table:util-ebpf.c:782] Info: unix-manager: unix socket '/var/run/suricata/suricata-command.socket' [UnixNew:unix-manager.c:136] Info: ebpf: IPv6 bypassed flow table size: 0 [EBPFForEachFlowV6Table:util-ebpf.c:901] Info: ebpf: IPv4 bypassed flow table size: 0 [EBPFForEachFlowV4Table:util-ebpf.c:782] Info: ebpf: IPv6 bypassed flow table size: 0 [EBPFForEachFlowV6Table:util-ebpf.c:901] Info: ebpf: IPv4 bypassed flow table size: 0 [EBPFForEachFlowV4Table:util-ebpf.c:782] Info: ebpf: IPv6 bypassed flow table size: 0 [EBPFForEachFlowV6Table:util-ebpf.c:901] Perf: af-packet: eno1: rx ring: block_size=32768 block_nr=10001 frame_size=1600 frame_nr=200020 [AFPComputeRingParams:source-af-packet.c:1596] Perf: af-packet: eno2: rx ring: block_size=32768 block_nr=10001 frame_size=1600 frame_nr=200020 [AFPComputeRingParams:source-af-packet.c:1596] Error: threads: thread "FB" failed to start in time: flags 0003 [TmThreadWaitOnThreadRunning:tm-threads.c:1831]