Project

General

Profile

Actions

Bug #6254

closed

Error: threads: thread "FB" failed to start in time: flags 0003

Added by Vincent Li over 1 year ago. Updated 5 months ago.

Status:
Closed
Priority:
Normal
Assignee:
Target version:
Affected Versions:
Effort:
Difficulty:
Label:

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]

Actions

Also available in: Atom PDF