OPNsense: Hängenden Upgrade-Prozess retten

Wenn der Upgrade-Prozess von OPNsense aus unerfindlichen Gründen hängen bleibt, sollte man die Firewall auf keinen Fall einfach neu starten oder den Upgrade-Prozess anderweitig beenden. Stattdessen lässt sich mit folgendem Vorgehen einfach rausfinden, wo die Ursache liegt.

Beim Upgrade von 23.1.7_3 auf 23.1.8 blieb der Upgrade-Prozess im Browser mit folgender Ausgabe hängen (Browser-Cache leeren und Logout / Login haben nicht geholfen):

***GOT REQUEST TO UPDATE***
Currently running OPNsense 23.1.7_3 at Thu May 25 18:31:16 CEST 2023
Updating OPNsense repository catalogue...
OPNsense repository is up to date.
All repositories are up to date.
Updating OPNsense repository catalogue...
OPNsense repository is up to date.
All repositories are up to date.
Checking for upgrades (35 candidates): .......... done
Processing candidates (35 candidates): .......... done
The following 36 package(s) will be affected (of 0 checked):

New packages to be INSTALLED:
    py39-tzdata: 2023.3_1

Installed packages to be UPGRADED:
    ca_root_nss: 3.89 -> 3.89.1
    crowdsec: 1.4.6_2 -> 1.5.1
    crowdsec-firewall-bouncer: 0.0.23.r2_12 -> 0.0.27
    curl: 8.0.1 -> 8.1.0
    dhcp6c: 20200512_1 -> 20230523
    easy-rsa: 3.1.2 -> 3.1.3
    lighttpd: 1.4.69 -> 1.4.70
    mpd5: 5.9_14 -> 5.9_16
    norm: 1.5r6_2 -> 1.5r6_3
    nss: 3.89 -> 3.89.1
    openvpn: 2.6.3 -> 2.6.4
    opnsense: 23.1.7_3 -> 23.1.8
    opnsense-update: 23.1.6 -> 23.1.8
    os-crowdsec: 1.0.4 -> 1.0.5
    os-ddclient: 1.13 -> 1.13_1
    php81: 8.1.18 -> 8.1.19
    php81-ctype: 8.1.18 -> 8.1.19
    php81-curl: 8.1.18 -> 8.1.19
    php81-dom: 8.1.18 -> 8.1.19
    php81-filter: 8.1.18 -> 8.1.19
    php81-gettext: 8.1.18 -> 8.1.19
    php81-ldap: 8.1.18 -> 8.1.19
    php81-mbstring: 8.1.18 -> 8.1.19
    php81-pdo: 8.1.18 -> 8.1.19
    php81-session: 8.1.18 -> 8.1.19
    php81-simplexml: 8.1.18 -> 8.1.19
    php81-sockets: 8.1.18 -> 8.1.19
    php81-sqlite3: 8.1.18 -> 8.1.19
    php81-xml: 8.1.18 -> 8.1.19
    php81-zlib: 8.1.18 -> 8.1.19
    py39-numpy: 1.24.1_1,1 -> 1.24.1_4,1
    py39-pandas: 1.5.3_1,1 -> 2.0.1_1,1
    py39-requests: 2.29.0 -> 2.30.0
    redis: 7.0.10 -> 7.0.11
    suricata: 6.0.11_1 -> 6.0.12

Number of packages to be installed: 1
Number of packages to be upgraded: 35

The process will require 31 MiB more space.
72 MiB to be downloaded.
[1/36] Fetching php81-sqlite3-8.1.19.pkg: ... done
[2/36] Fetching php81-sockets-8.1.19.pkg: ..... done
[3/36] Fetching lighttpd-1.4.70.pkg: .......... done
[4/36] Fetching opnsense-update-23.1.8.pkg: ..... done
[5/36] Fetching os-crowdsec-1.0.5.pkg: ... done
[6/36] Fetching nss-3.89.1.pkg: .......... done
[7/36] Fetching norm-1.5r6_3.pkg: .......... done
[8/36] Fetching py39-numpy-1.24.1_4,1.pkg: .......... done
[9/36] Fetching easy-rsa-3.1.3.pkg: ....... done
[10/36] Fetching crowdsec-1.5.1.pkg: .......... done
[11/36] Fetching openvpn-2.6.4.pkg: .......... done
[12/36] Fetching php81-filter-8.1.19.pkg: ... done
[13/36] Fetching php81-8.1.19.pkg: .......... done
[14/36] Fetching py39-pandas-2.0.1_1,1.pkg: .......... done
[15/36] Fetching dhcp6c-20230523.pkg: ......... done
[16/36] Fetching py39-requests-2.30.0.pkg: .......... done
[17/36] Fetching crowdsec-firewall-bouncer-0.0.27.pkg: .......... done
[18/36] Fetching py39-tzdata-2023.3_1.pkg: .......... done
[19/36] Fetching ca_root_nss-3.89.1.pkg: .......... done
[20/36] Fetching php81-ctype-8.1.19.pkg: . done
[21/36] Fetching php81-simplexml-8.1.19.pkg: ... done
[22/36] Fetching php81-session-8.1.19.pkg: ..... done
[23/36] Fetching curl-8.1.0.pkg: .......... done
[24/36] Fetching php81-zlib-8.1.19.pkg: ... done
[25/36] Fetching os-ddclient-1.13_1.pkg: ... done
[26/36] Fetching php81-dom-8.1.19.pkg: ........ done
[27/36] Fetching suricata-6.0.12.pkg: .......... done
[28/36] Fetching mpd5-5.9_16.pkg: .......... done
[29/36] Fetching php81-ldap-8.1.19.pkg: ..... done
[30/36] Fetching php81-xml-8.1.19.pkg: ... done
[31/36] Fetching php81-pdo-8.1.19.pkg: ....... done
[32/36] Fetching php81-curl-8.1.19.pkg: ..... done
[33/36] Fetching php81-mbstring-8.1.19.pkg: .......... done
[34/36] Fetching opnsense-23.1.8.pkg: .......... done
[35/36] Fetching php81-gettext-8.1.19.pkg: . done
[36/36] Fetching redis-7.0.11.pkg: .......... done
Checking integrity... done (0 conflicting)
[1/36] Upgrading py39-numpy from 1.24.1_1,1 to 1.24.1_4,1...
[1/36] Extracting py39-numpy-1.24.1_4,1: .......... done
[2/36] Upgrading php81 from 8.1.18 to 8.1.19...
[2/36] Extracting php81-8.1.19: .......... done
[3/36] Installing py39-tzdata-2023.3_1...
[3/36] Extracting py39-tzdata-2023.3_1: .......... done
[4/36] Upgrading ca_root_nss from 3.89 to 3.89.1...
[4/36] Extracting ca_root_nss-3.89.1: ...... done
[5/36] Upgrading nss from 3.89 to 3.89.1...
[5/36] Extracting nss-3.89.1: .......... done
[6/36] Upgrading easy-rsa from 3.1.2 to 3.1.3...
[6/36] Extracting easy-rsa-3.1.3: .......... done
[7/36] Upgrading py39-pandas from 1.5.3_1,1 to 2.0.1_1,1...
[7/36] Extracting py39-pandas-2.0.1_1,1: .......... done
[8/36] Upgrading crowdsec-firewall-bouncer from 0.0.23.r2_12 to 0.0.27...
[8/36] Extracting crowdsec-firewall-bouncer-0.0.27: ...... done
crowdsec_firewall is running as pid 50436.
Stopping crowdsec_firewall.
Waiting for PIDS: 50436.
[9/36] Upgrading php81-session from 8.1.18 to 8.1.19...
[9/36] Extracting php81-session-8.1.19: .......... done
[10/36] Upgrading curl from 8.0.1 to 8.1.0...
[10/36] Extracting curl-8.1.0: .......... done
[11/36] Upgrading php81-pdo from 8.1.18 to 8.1.19...
[11/36] Extracting php81-pdo-8.1.19: .......... done
[12/36] Upgrading php81-mbstring from 8.1.18 to 8.1.19...
[12/36] Extracting php81-mbstring-8.1.19: .......... done
[13/36] Upgrading php81-sqlite3 from 8.1.18 to 8.1.19...
[13/36] Extracting php81-sqlite3-8.1.19: ......... done
[14/36] Upgrading php81-sockets from 8.1.18 to 8.1.19...
[14/36] Extracting php81-sockets-8.1.19: .......... done
[15/36] Upgrading lighttpd from 1.4.69 to 1.4.70...
===> Creating groups.
Using existing group 'www'.
===> Creating users
Using existing user 'www'.
[15/36] Extracting lighttpd-1.4.70: .......... done
[16/36] Upgrading opnsense-update from 23.1.6 to 23.1.8...
[16/36] Extracting opnsense-update-23.1.8: .......... done
[17/36] Upgrading crowdsec from 1.4.6_2 to 1.5.1...
[17/36] Extracting crowdsec-1.5.1: .......... done
crowdsec is running as pid 31994.
Stopping crowdsec.
Waiting for PIDS: 31994.
[18/36] Upgrading openvpn from 2.6.3 to 2.6.4...
===> Creating groups.
Using existing group 'openvpn'.
===> Creating users
Using existing user 'openvpn'.
[18/36] Extracting openvpn-2.6.4: .......... done
[19/36] Upgrading php81-filter from 8.1.18 to 8.1.19...
[19/36] Extracting php81-filter-8.1.19: ......... done
[20/36] Upgrading dhcp6c from 20200512_1 to 20230523...
[20/36] Extracting dhcp6c-20230523: ........ done
[21/36] Upgrading py39-requests from 2.29.0 to 2.30.0...
[21/36] Extracting py39-requests-2.30.0: .......... done
[22/36] Upgrading php81-ctype from 8.1.18 to 8.1.19...
[22/36] Extracting php81-ctype-8.1.19: ........ done
[23/36] Upgrading php81-simplexml from 8.1.18 to 8.1.19...
[23/36] Extracting php81-simplexml-8.1.19: ......... done
[24/36] Upgrading php81-zlib from 8.1.18 to 8.1.19...
[24/36] Extracting php81-zlib-8.1.19: ........ done
[25/36] Upgrading php81-dom from 8.1.18 to 8.1.19...
[25/36] Extracting php81-dom-8.1.19: .......... done
[26/36] Upgrading suricata from 6.0.11_1 to 6.0.12...
[26/36] Extracting suricata-6.0.12: .......... done
[27/36] Upgrading mpd5 from 5.9_14 to 5.9_16...
[27/36] Extracting mpd5-5.9_16: .......... done
[28/36] Upgrading php81-ldap from 8.1.18 to 8.1.19...
[28/36] Extracting php81-ldap-8.1.19: ........ done
[29/36] Upgrading php81-xml from 8.1.18 to 8.1.19...
[29/36] Extracting php81-xml-8.1.19: ......... done
[30/36] Upgrading php81-curl from 8.1.18 to 8.1.19...
[30/36] Extracting php81-curl-8.1.19: .......... done
[31/36] Upgrading php81-gettext from 8.1.18 to 8.1.19...
[31/36] Extracting php81-gettext-8.1.19: ........ done
[32/36] Upgrading os-crowdsec from 1.0.4 to 1.0.5...
[32/36] Extracting os-crowdsec-1.0.5: .......... done

Die Log-Dateien (ausgelesen um 23:30, also knapp fünf Stunden später) waren nicht sehr aufschlussreich, wieso es nicht weitergeht:

System: Firmware: Protokolldatei

2023-05-25T18:41:24 Notice  pkg-static  php81-gettext upgraded: 8.1.18 -> 8.1.19
2023-05-25T18:41:21 Notice  pkg-static  php81-curl upgraded: 8.1.18 -> 8.1.19
2023-05-25T18:41:19 Notice  pkg-static  php81-xml upgraded: 8.1.18 -> 8.1.19
2023-05-25T18:41:16 Notice  pkg-static  php81-ldap upgraded: 8.1.18 -> 8.1.19
2023-05-25T18:41:13 Notice  pkg-static  mpd5 upgraded: 5.9_14 -> 5.9_16
2023-05-25T18:41:08 Notice  pkg-static  suricata upgraded: 6.0.11_1 -> 6.0.12
2023-05-25T18:41:04 Notice  pkg-static  php81-dom upgraded: 8.1.18 -> 8.1.19
2023-05-25T18:41:04 Notice  pkg-static  php81-zlib upgraded: 8.1.18 -> 8.1.19

[...]

Also habe ich mich in der Konsole eingeloggt und dort das Upgrade angestoßen. Das klappte allerdings nicht, da das Upgrade ja bereits lief. Also musste ich die Ursache für den hängenden Upgrade-Prozess ausfindig machen.

Meine erste Vermutung war, dass sich CrowdSec vllt. nicht beendet hat (ohne zu wissen, ob es das müsste). Also habe ich über die Weboberfläche den Prozess beendet – allerdings hat das wohl nicht wirklich geklappt, es ging jedenfalls auch danach nicht weiter.

Also habe ich in der Konsole einen Blick in die Prozesstabelle geworfen. Darin hingen tatsächlich einige Prozesse im Status wait fest. Darunter auch ein Befehl zum Beenden von CrowdSec.

ps -awx -l | grep wait

  UID   PID  PPID C PRI NI    VSZ    RSS MWCHAN   STAT TT         TIME COMMAND
    0  8182 89558 3  52  0  13504   3256 wait     I     -      0:00.02 /bin/sh /usr/local/etc/rc.d/oscrowdsec stop
    0 11127     1 2  22  0  13504   2660 wait     Is    -      0:00.00 /bin/sh /usr/local/opnsense/scripts/firmware/launcher.sh update
    0 11505 11127 1  22  0  12900   2412 wait     I     -      0:00.00 /usr/local/bin/flock -n -o /tmp/pkg_upgrade.progress /usr/local/opnsense/scripts/firmware/update.sh
    0 11727 11505 3  52  0  13504   2656 wait     I     -      0:00.00 /bin/sh /usr/local/opnsense/scripts/firmware/update.sh
    0 20248 11727 0  52  0  13504   2700 wait     I     -      0:00.01 /bin/sh /usr/local/sbin/opnsense-update -pt opnsense
    0 34858 20248 3  52  0  18360   6348 wait     I     -      0:00.00 pkg-static upgrade -y
    0 37567  8182 1  52  0  13504   3364 wait     I     -      0:00.02 /bin/sh /usr/local/etc/rc.d/crowdsec_firewall stop
    0 39775 37567 0  52  0  12648   2116 kqread   I     -      0:00.00 pwait 97407
    0 40945 89558 2  23  0  13504   2664 wait     I     -      0:00.01 /bin/sh /usr/local/opnsense/scripts/firmware/changelog.sh cron
    0 74036 35507 2  45  0  13504   2648 wait     I     -      0:00.00 /bin/sh -c set -- os-crowdsec-1.0.4\n#!/bin/sh\n\n# need to temporarily stop the bouncer to remove all the rules\nservice crowdsec_firewall stop >/dev/null 2>&1 | :\n\n# the rest of the cleanup is done in the post-deinstall script, otherwise\n# t
    0 74605 74036 2  52  0  13504   3020 wait     I     -      0:00.02 /bin/sh /usr/local/etc/rc.d/crowdsec_firewall stop
    0 76898 74605 0  52  0  12648   2116 kqread   I     -      0:00.00 pwait 97407
    0 87286     1 3  52  0  36516  24352 wait     Is    -      0:03.44 /usr/local/bin/python3 /usr/local/opnsense/service/configd.py (python3.9)
    0 97407 97005 2  20  0 722192  40172 uwait    I     -      0:01.36 /usr/local/bin/crowdsec-firewall-bouncer -c /usr/local/etc/crowdsec/bouncers/crowdsec-firewall-bouncer.yaml (crowdsec-firewall-b)

Nachdem ich Prozess 97407 (pwait 97407) mit kill -9 97407 erzwungen beendet habe, konnte Prozess 37567 (/bin/sh /usr/local/etc/rc.d/crowdsec_firewall stop) abgeschlossen werden. Ein erneuter Blick in die Prozesstabelle zeigt, welche Prozesse daraufhin übrig geblieben sind:

ps -awx -l | grep wait

  UID   PID  PPID C PRI NI    VSZ    RSS MWCHAN   STAT TT         TIME COMMAND
    0 11127     1 2  22  0  13504   2660 wait     Is    -      0:00.00 /bin/sh /usr/local/opnsense/scripts/firmware/launcher.sh update
    0 11505 11127 1  22  0  12900   2412 wait     I     -      0:00.00 /usr/local/bin/flock -n -o /tmp/pkg_upgrade.progress /usr/local/opnsense/scripts/firmware/update.sh
    0 11727 11505 3  52  0  13504   2656 wait     I     -      0:00.00 /bin/sh /usr/local/opnsense/scripts/firmware/update.sh
    0 14907 35507 0  21  0  13504   2992 wait     S     -      0:00.00 /bin/sh -c set -- os-crowdsec-1.0.5\n#!/bin/sh\n\n# The configuration file used in reconfigure (i.e. settings.json) may eventually\n# have credentials, so we need to restrict its permissions. We do so by pre-creating\n# the directory, and the tem
    0 15914 14907 1  52  0  13504   3268 wait     S     -      0:00.01 /bin/sh /usr/local/etc/rc.d/configd restart
    0 20248 11727 0  52  0  13504   2700 wait     I     -      0:00.01 /bin/sh /usr/local/sbin/opnsense-update -pt opnsense
    0 24592 15914 2  52  0  13504   3272 wait     S     -      0:00.00 /bin/sh /usr/local/etc/rc.d/configd restart
    0 34858 20248 3  52  0  18360   6348 wait     I     -      0:00.00 pkg-static upgrade -y

Voila – das Upgrade lief weiter und nach kurzer Zeit (ca. 5 Minuten) startete die Firewall wie gewünscht neu:

System: Firmware: Protokolldatei

2023-05-25T23:36:00 Notice  pkg-static  redis upgraded: 7.0.10 -> 7.0.11
2023-05-25T23:35:45 Notice  pkg-static  opnsense upgraded: 23.1.7_3 -> 23.1.8
2023-05-25T23:34:44 Notice  pkg-static  os-ddclient upgraded: 1.13 -> 1.13_1
2023-05-25T23:34:35 Notice  pkg-static  norm upgraded: 1.5r6_2 -> 1.5r6_3
2023-05-25T23:34:34 Notice  pkg-static  os-crowdsec upgraded: 1.0.4 -> 1.0.5

[...]