Package: firehol
Version: 3.1.7+ds-2
Severity: normal

Dear Maintainer,

At each system boot, Firehol takes a full minute to initialise, and makes the
boot process hang for some of that time.

Looking at the system log (attached), it isn't obvious why Firehol takes just
over
1 minute to complete, or why nothing seems to happen between 19:49:40 and
19:50:08, during which a console message is displayed saying that the boot
process is waiting for Firehol to finish.

The command 'firehol restart' takes very little time to complete once the
system is up and running. This indicates that something is wrong at boot time,
and that Firehol is presumably waiting for something else to complete.

I would have expected Firehol to initialise quickly during boot, and not to
hang the boot process.


I attach the journalctl output, from Firehol start to Firehol completion:


-- System Information:
Debian Release: 11.0
  APT prefers stable-security
  APT policy: (500, 'stable-security'), (500, 'stable')
Architecture: amd64 (x86_64)

Kernel: Linux 5.10.0-8-amd64 (SMP w/4 CPU threads)
Kernel taint flags: TAINT_OOT_MODULE, TAINT_UNSIGNED_MODULE
Locale: LANG=en_GB.UTF-8, LC_CTYPE=en_GB.UTF-8 (charmap=UTF-8),
LANGUAGE=en_GB:en
Shell: /bin/sh linked to /usr/bin/dash
Init: systemd (via /run/systemd/system)
LSM: AppArmor: enabled

Versions of packages firehol depends on:
ii  firehol-common       3.1.7+ds-2
ii  init-system-helpers  1.60
ii  lsb-base             11.1.0

Versions of packages firehol recommends:
ii  fireqos  3.1.7+ds-2

Versions of packages firehol suggests:
ii  firehol-doc    3.1.7+ds-2
pn  firehol-tools  <none>
pn  ulogd2         <none>

-- Configuration Files:
/etc/default/firehol changed:
START_FIREHOL=YES
WAIT_FOR_IFACE="enp2s0"
FIREHOL_ESTABLISHED_ACTIVATION_ACCEPT=0

/etc/firehol/firehol.conf changed:
version 6
stewjar=192.168.178.100
local="192.168.178.101 192.168.178.102 192.168.178.103"
m2885fw=192.168.178.90
interface4 enp2s0 ethernet
        # The default policy is DROP. You can be more polite with REJECT.
        # Prefer to be polite on your own clients to prevent timeouts.
        policy drop
        # Protect from the internet.
        protection strong
        # The following means that this machine can REQUEST anything via
enp2s0.
        client all accept
        # Specific services that this machine needs to request via enp2s0.
        client multicast accept
        client dhcp accept
        # Services that this machine offers to local network.
        server ping accept src "$local"
        server ssh accept src "$local"
        server cups accept src "$local"
        # Samsung M2885FW printer (needs both client and server)
        # The script 'scanner-enable' must be run after Firehol, to fix
        # iptables entries to allow SNMP to work properly.
        client snmp accept dst $m2885fw
        server snmp accept src $m2885fw
        server samba accept
        # The following enp2s0 server ports are not known by FireHOL:
        #  tcp/45485 tcp/49074 tcp/7741 udp/32768 udp/32769 udp/517 udp/518
udp/5353 udp/7741 udp/972
        # TODO: If you need any of them, you should define new services.
        #       (see Adding Services at the web site - http://firehol.sf.net).
interface usb0 usb
        policy accept
Aug 30 19:49:07 desktop systemd[1]: Starting Set console font and keymap...
Aug 30 19:49:07 desktop systemd[1]: Starting Firehol stateful packet filtering 
firewall for humans...
Aug 30 19:49:07 desktop systemd[1]: Starting Tell Plymouth To Write Out Runtime 
Data...
Aug 30 19:49:07 desktop systemd[1]: Condition check resulted in Store a System 
Token in an EFI Variable being skipped.
Aug 30 19:49:07 desktop systemd[1]: Condition check resulted in Commit a 
transient machine-id on disk being skipped.
Aug 30 19:49:07 desktop systemd[1]: Received SIGRTMIN+20 from PID 174 
(plymouthd).
Aug 30 19:49:07 desktop systemd[1]: Finished Tell Plymouth To Write Out Runtime 
Data.
Aug 30 19:49:07 desktop systemd[1]: Finished Set console font and keymap.
Aug 30 19:49:07 desktop systemd[1]: Finished Flush Journal to Persistent 
Storage.
Aug 30 19:49:07 desktop systemd[1]: Starting Create Volatile Files and 
Directories...
Aug 30 19:49:07 desktop systemd[1]: Condition check resulted in Dispatch 
Password Requests to Console Directory Watch being skipped.
Aug 30 19:49:07 desktop systemd[1]: Condition check resulted in Set Up 
Additional Binary Formats being skipped.
Aug 30 19:49:07 desktop systemd[1]: Condition check resulted in Store a System 
Token in an EFI Variable being skipped.
Aug 30 19:49:07 desktop systemd[1]: Condition check resulted in Rebuild 
Hardware Database being skipped.
Aug 30 19:49:07 desktop systemd[1]: Condition check resulted in Commit a 
transient machine-id on disk being skipped.
Aug 30 19:49:07 desktop systemd[1]: Condition check resulted in Platform 
Persistent Storage Archival being skipped.
Aug 30 19:49:08 desktop systemd[1]: Finished Create Volatile Files and 
Directories.
Aug 30 19:49:08 desktop systemd[1]: Starting Network Time Synchronization...
Aug 30 19:49:08 desktop systemd[1]: Starting Update UTMP about System 
Boot/Shutdown...
Aug 30 19:49:08 desktop systemd[1]: Finished Load AppArmor profiles.
Aug 30 19:49:08 desktop systemd[1]: Started Entropy Daemon based on the HAVEGE 
algorithm.
Aug 30 19:49:08 desktop systemd[1]: Finished Update UTMP about System 
Boot/Shutdown.
Aug 30 19:49:08 desktop systemd[1]: Started Network Time Synchronization.
Aug 30 19:49:08 desktop systemd[1]: Reached target System Initialization.
Aug 30 19:49:08 desktop systemd[1]: Started CUPS Scheduler.
Aug 30 19:49:08 desktop systemd[1]: Started Daily Cleanup of Temporary 
Directories.
Aug 30 19:49:08 desktop anacron[721]: Anacron 2.3 started on 2021-08-30
Aug 30 19:49:08 desktop haveged[699]: haveged: ver: 1.9.14; arch: x86; vend: 
GenuineIntel; build: (gcc 10.2.1 ITV); collect: 128K
Aug 30 19:49:08 desktop haveged[699]: haveged: cpu: (L4 VC); data: 32K (L4 V); 
inst: 32K (L4 V); idx: 24/40; sz: 32154/54019
Aug 30 19:49:08 desktop haveged[699]: haveged: tot tests(BA8): A:1/1 B:1/1 
continuous tests(B):  last entropy estimate 8.00104
Aug 30 19:49:08 desktop haveged[699]: haveged: fills: 0, generated: 0
Aug 30 19:49:08 desktop systemd[1]: Reached target Paths.
Aug 30 19:49:08 desktop systemd[1]: Reached target System Time Set.
Aug 30 19:49:08 desktop systemd[1]: Reached target System Time Synchronized.
Aug 30 19:49:08 desktop FireHOL[740]: FireHOL started from '/' with: 
/usr/sbin/firehol start
Aug 30 19:49:08 desktop firehol[567]: FireHOL: Saving active firewall to a 
temporary file...  OK
Aug 30 19:49:08 desktop systemd[1]: Started Trigger anacron every hour.
Aug 30 19:49:08 desktop FireHOL[742]: Saving active firewall to a temporary 
file started
Aug 30 19:49:08 desktop systemd[1]: Started Daily apt download activities.
Aug 30 19:49:08 desktop FireHOL[754]: Saving active firewall to a temporary 
file succeeded
Aug 30 19:49:08 desktop systemd[1]: Started Daily apt upgrade and clean 
activities.
Aug 30 19:49:08 desktop FireHOL[755]: Processing file 
'/etc/firehol/firehol.conf' started
Aug 30 19:49:08 desktop systemd[1]: Started Periodic ext4 Online Metadata Check 
for All Filesystems.
Aug 30 19:49:08 desktop systemd[1]: Started Discard unused blocks once a week.
Aug 30 19:49:08 desktop systemd[1]: Started Daily rotation of log files.
Aug 30 19:49:08 desktop systemd[1]: Started Daily man-db regeneration.
Aug 30 19:49:08 desktop systemd[1]: Reached target Timers.
Aug 30 19:49:08 desktop systemd[1]: Listening on Avahi mDNS/DNS-SD Stack 
Activation Socket.
Aug 30 19:49:08 desktop systemd[1]: Listening on CUPS Scheduler.
Aug 30 19:49:08 desktop systemd[1]: Listening on D-Bus System Message Bus 
Socket.
Aug 30 19:49:08 desktop systemd[1]: Reached target Sockets.
Aug 30 19:49:08 desktop systemd[1]: Reached target Basic System.
Aug 30 19:49:08 desktop systemd[1]: Starting Accounts Service...
Aug 30 19:49:08 desktop systemd[1]: Condition check resulted in Manage Sound 
Card State (restore and store) being skipped.
Aug 30 19:49:08 desktop systemd[1]: Starting Save/Restore Sound Card State...
Aug 30 19:49:08 desktop systemd[1]: Started Run anacron jobs.
Aug 30 19:49:08 desktop systemd[1]: Starting Avahi mDNS/DNS-SD Stack...
Aug 30 19:49:08 desktop systemd[1]: Starting Bluetooth service...
Aug 30 19:49:08 desktop anacron[721]: Will run job `cron.daily' in 5 min.
Aug 30 19:49:08 desktop systemd[1]: Started Regular background program 
processing daemon.
Aug 30 19:49:08 desktop anacron[721]: Will run job `cron.weekly' in 10 min.
Aug 30 19:49:08 desktop sensors[766]: acpitz-acpi-0
Aug 30 19:49:08 desktop sensors[766]: Adapter: ACPI interface
Aug 30 19:49:08 desktop sensors[766]: temp1:        +27.8°C  (crit = +105.0°C)
Aug 30 19:49:08 desktop sensors[766]: temp2:        +29.8°C  (crit = +105.0°C)
Aug 30 19:49:08 desktop sensors[766]: coretemp-isa-0000
Aug 30 19:49:08 desktop sensors[766]: Adapter: ISA adapter
Aug 30 19:49:08 desktop sensors[766]: Package id 0:  +29.0°C  (high = +80.0°C, 
crit = +100.0°C)
Aug 30 19:49:08 desktop sensors[766]: Core 0:        +26.0°C  (high = +80.0°C, 
crit = +100.0°C)
Aug 30 19:49:08 desktop sensors[766]: Core 1:        +29.0°C  (high = +80.0°C, 
crit = +100.0°C)
Aug 30 19:49:08 desktop sensors[766]: Core 2:        +27.0°C  (high = +80.0°C, 
crit = +100.0°C)
Aug 30 19:49:08 desktop sensors[766]: Core 3:        +26.0°C  (high = +80.0°C, 
crit = +100.0°C)
Aug 30 19:49:08 desktop systemd[1]: Started D-Bus System Message Bus.
Aug 30 19:49:08 desktop anacron[721]: Jobs will be executed sequentially
Aug 30 19:49:08 desktop systemd[1]: Starting Remove Stale Online ext4 Metadata 
Check Snapshots...
Aug 30 19:49:08 desktop cron[725]: (CRON) INFO (pidfile fd = 3)
Aug 30 19:49:08 desktop systemd[1]: Condition check resulted in getty on 
tty2-tty6 if dbus and logind are not available being skipped.
Aug 30 19:49:08 desktop cron[725]: (CRON) INFO (Running @reboot jobs)
Aug 30 19:49:08 desktop systemd[1]: Starting Initialize hardware monitoring 
sensors...
Aug 30 19:49:08 desktop systemd[1]: Starting Authorization Manager...
Aug 30 19:49:08 desktop systemd[1]: Starting System Logging Service...
Aug 30 19:49:08 desktop systemd[1]: Starting Self Monitoring and Reporting 
Technology (SMART) Daemon...
Aug 30 19:49:08 desktop systemd[1]: Starting User Login Management...
Aug 30 19:49:08 desktop systemd[1]: Starting Disk Manager...
Aug 30 19:49:08 desktop smartd[760]: smartd 7.2 2020-12-30 r5155 
[x86_64-linux-5.10.0-8-amd64] (local build)
Aug 30 19:49:08 desktop systemd[1]: Starting WPA supplicant...
Aug 30 19:49:08 desktop smartd[760]: Copyright (C) 2002-20, Bruce Allen, 
Christian Franke, www.smartmontools.org
Aug 30 19:49:08 desktop systemd[1]: Finished Save/Restore Sound Card State.
Aug 30 19:49:08 desktop avahi-daemon[722]: Found user 'avahi' (UID 109) and 
group 'avahi' (GID 116).
Aug 30 19:49:08 desktop systemd[1]: e2scrub_reap.service: Succeeded.
Aug 30 19:49:08 desktop avahi-daemon[722]: Successfully dropped root privileges.
Aug 30 19:49:08 desktop systemd[1]: Finished Remove Stale Online ext4 Metadata 
Check Snapshots.
Aug 30 19:49:08 desktop avahi-daemon[722]: avahi-daemon 0.8 starting up.
Aug 30 19:49:08 desktop systemd[1]: Reached target Sound Card.
Aug 30 19:49:09 desktop smartd[760]: Opened configuration file /etc/smartd.conf
Aug 30 19:49:08 desktop systemd[1]: Finished Initialize hardware monitoring 
sensors.
Aug 30 19:49:09 desktop smartd[760]: Drive: DEVICESCAN, implied '-a' Directive 
on line 21 of file /etc/smartd.conf
Aug 30 19:49:09 desktop smartd[760]: Configuration file /etc/smartd.conf was 
parsed, found DEVICESCAN, scanning devices
Aug 30 19:49:09 desktop smartd[760]: Device: /dev/sda, type changed from 'scsi' 
to 'sat'
Aug 30 19:49:09 desktop smartd[760]: Device: /dev/sda [SAT], opened
Aug 30 19:49:09 desktop smartd[760]: Device: /dev/sda [SAT], WDC 
WD20EZRX-00D8PB0, S/N:WD-WMC4M0HALFVF, WWN:5-0014ee-059550a5a, FW:80.00A80, 
2.00 TB
Aug 30 19:49:09 desktop systemd-logind[761]: New seat seat0.
Aug 30 19:49:09 desktop smartd[760]: Device: /dev/sda [SAT], found in smartd 
database: Western Digital Green
Aug 30 19:49:09 desktop udisksd[762]: udisks daemon version 2.9.2 starting
Aug 30 19:49:09 desktop systemd-logind[761]: Watching system buttons on 
/dev/input/event2 (Power Button)
Aug 30 19:49:09 desktop systemd-logind[761]: Watching system buttons on 
/dev/input/event1 (Power Button)
Aug 30 19:49:09 desktop systemd-logind[761]: Watching system buttons on 
/dev/input/event0 (AT Translated Set 2 keyboard)
Aug 30 19:49:09 desktop smartd[760]: Device: /dev/sda [SAT], is SMART capable. 
Adding to "monitor" list.
Aug 30 19:49:09 desktop smartd[760]: Device: /dev/sda [SAT], state read from 
/var/lib/smartmontools/smartd.WDC_WD20EZRX_00D8PB0-WD_WMC4M0HALFVF.ata.state
Aug 30 19:49:09 desktop smartd[760]: Monitoring 1 ATA/SATA, 0 SCSI/SAS and 0 
NVMe devices
Aug 30 19:49:09 desktop smartd[760]: Device: /dev/sda [SAT], 12 Currently 
unreadable (pending) sectors
Aug 30 19:49:09 desktop systemd[1]: Started System Logging Service.
Aug 30 19:49:09 desktop smartd[760]: Device: /dev/sda [SAT], 5 Offline 
uncorrectable sectors
Aug 30 19:49:09 desktop systemd[1]: Started Self Monitoring and Reporting 
Technology (SMART) Daemon.
Aug 30 19:49:09 desktop smartd[760]: Device: /dev/sda [SAT], SMART Usage 
Attribute: 194 Temperature_Celsius changed from 113 to 125
Aug 30 19:49:09 desktop rsyslogd[731]: imuxsock: Acquired UNIX socket 
'/run/systemd/journal/syslog' (fd 3) from systemd.  [v8.2102.0]
Aug 30 19:49:09 desktop rsyslogd[731]: [origin software="rsyslogd" 
swVersion="8.2102.0" x-pid="731" x-info="https://www.rsyslog.com";] start
Aug 30 19:49:09 desktop smartd[760]: Device: /dev/sda [SAT], state written to 
/var/lib/smartmontools/smartd.WDC_WD20EZRX_00D8PB0-WD_WMC4M0HALFVF.ata.state
Aug 30 19:49:10 desktop bluetoothd[723]: Bluetooth daemon 5.55
Aug 30 19:49:10 desktop systemd[1]: Started User Login Management.
Aug 30 19:49:10 desktop dbus-daemon[726]: [system] Successfully activated 
service 'org.freedesktop.systemd1'
Aug 30 19:49:10 desktop systemd[1]: Started Avahi mDNS/DNS-SD Stack.
Aug 30 19:49:10 desktop avahi-daemon[722]: Successfully called chroot().
Aug 30 19:49:10 desktop avahi-daemon[722]: Successfully dropped remaining 
capabilities.
Aug 30 19:49:10 desktop avahi-daemon[722]: No service file found in 
/etc/avahi/services.
Aug 30 19:49:10 desktop systemd[1]: Started Bluetooth service.
Aug 30 19:49:10 desktop wpa_supplicant[763]: Successfully initialized 
wpa_supplicant
Aug 30 19:49:10 desktop systemd[1]: Started WPA supplicant.
Aug 30 19:49:10 desktop systemd[1]: Reached target Bluetooth.
Aug 30 19:49:10 desktop bluetoothd[723]: Starting SDP server
Aug 30 19:49:10 desktop avahi-daemon[722]: Joining mDNS multicast group on 
interface lo.IPv6 with address ::1.
Aug 30 19:49:10 desktop avahi-daemon[722]: New relevant interface lo.IPv6 for 
mDNS.
Aug 30 19:49:10 desktop avahi-daemon[722]: Joining mDNS multicast group on 
interface lo.IPv4 with address 127.0.0.1.
Aug 30 19:49:10 desktop avahi-daemon[722]: New relevant interface lo.IPv4 for 
mDNS.
Aug 30 19:49:10 desktop avahi-daemon[722]: Network interface enumeration 
completed.
Aug 30 19:49:10 desktop avahi-daemon[722]: Registering new address record for 
::1 on lo.*.
Aug 30 19:49:10 desktop avahi-daemon[722]: Registering new address record for 
127.0.0.1 on lo.IPv4.
Aug 30 19:49:10 desktop dbus-daemon[726]: [system] Activating via systemd: 
service name='org.freedesktop.hostname1' 
unit='dbus-org.freedesktop.hostname1.service' requested by ':1.5' (uid=0 
pid=723 comm="/usr/libexec/bluetooth/bluetoothd ")
Aug 30 19:49:10 desktop bluetoothd[723]: Bluetooth management interface 1.18 
initialized
Aug 30 19:49:10 desktop kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3
Aug 30 19:49:10 desktop kernel: Bluetooth: BNEP filters: protocol multicast
Aug 30 19:49:10 desktop kernel: Bluetooth: BNEP socket layer initialized
Aug 30 19:49:10 desktop kernel: NET: Registered protocol family 38
Aug 30 19:49:10 desktop systemd[1]: Starting Hostname Service...
Aug 30 19:49:10 desktop dbus-daemon[726]: [system] Successfully activated 
service 'org.freedesktop.hostname1'
Aug 30 19:49:10 desktop systemd[1]: Started Hostname Service.
Aug 30 19:49:10 desktop polkitd[730]: started daemon version 0.105 using 
authority implementation `local' version `0.105'
Aug 30 19:49:10 desktop systemd[1]: Started Authorization Manager.
Aug 30 19:49:10 desktop systemd[1]: Starting Modem Manager...
Aug 30 19:49:10 desktop bluetoothd[723]: 
profiles/sap/server.c:sap_server_register() Sap driver initialization failed.
Aug 30 19:49:10 desktop bluetoothd[723]: sap-server: Operation not permitted (1)
Aug 30 19:49:10 desktop accounts-daemon[713]: started daemon version 0.6.55
Aug 30 19:49:10 desktop systemd[1]: Started Accounts Service.
Aug 30 19:49:10 desktop systemd[1]: systemd-rfkill.service: Succeeded.
Aug 30 19:49:11 desktop udisksd[762]: failed to load module mdraid: 
libbd_mdraid.so.2: cannot open shared object file: No such file or directory
Aug 30 19:49:11 desktop ModemManager[817]: <info>  ModemManager (version 
1.14.12) starting in system bus...
Aug 30 19:49:11 desktop avahi-daemon[722]: Server startup complete. Host name 
is stewjar.local. Local service cookie is 868304876.
Aug 30 19:49:11 desktop udisksd[762]: Failed to load the 'mdraid' libblockdev 
plugin
Aug 30 19:49:11 desktop systemd[1]: Started Modem Manager.
Aug 30 19:49:11 desktop systemd[1]: Started Disk Manager.
Aug 30 19:49:11 desktop udisksd[762]: Acquired the name org.freedesktop.UDisks2 
on the system message bus
Aug 30 19:49:13 desktop ModemManager[817]: <info>  [base-manager] couldn't 
check support for device '/sys/devices/pci0000:00/0000:00:1c.2/0000:02:00.0': 
not supported by any plugin
Aug 30 19:49:37 desktop systemd[1]: systemd-fsckd.service: Succeeded.
Aug 30 19:49:40 desktop systemd[1]: systemd-hostnamed.service: Succeeded.
Aug 30 19:50:08 desktop firehol[567]: FireHOL: Processing file 
'/etc/firehol/firehol.conf'...  OK  (209 iptables rules)
Aug 30 19:50:08 desktop FireHOL[1412]: Processing file 
'/etc/firehol/firehol.conf' succeeded with message: 209 iptables rules
Aug 30 19:50:08 desktop FireHOL[1423]: Fast activating new firewall started
Aug 30 19:50:08 desktop FireHOL[1465]: Runtime WARNING 'This might or might not 
affect the operation of your firewall.'. Source FIN
Aug 30 19:50:08 desktop firehol[567]: FireHOL: Fast activating new firewall...  
OK
Aug 30 19:50:08 desktop FireHOL[1486]: Fast activating new firewall succeeded
Aug 30 19:50:08 desktop FireHOL[1497]: Saving activated firewall to 
'/var/spool/firehol' started
Aug 30 19:50:08 desktop firehol[567]: FireHOL: Saving activated firewall to 
'/var/spool/firehol'...  OK
Aug 30 19:50:08 desktop FireHOL[1510]: Saving activated firewall to 
'/var/spool/firehol' succeeded
Aug 30 19:50:08 desktop FireHOL[1512]: Successfully activated new firewall from 
/etc/firehol/firehol.conf.
Aug 30 19:50:08 desktop systemd[1]: Finished Firehol stateful packet filtering 
firewall for humans.
Aug 30 19:50:08 desktop systemd[1]: Reached target Network (Pre).

Reply via email to