Crash report on upgrade
-
@jimp
Very interesting. Didn't know that. This is the output:load: 0.19 cmd: php 82957 [piperd] 4944.73r 1.85u 1.99s 0% 45108k
-
So it's reading from a pipe of some kind. Though the exact specifics of what are tougher to find out. It may be waiting on some other task or job to complete before one of the pkg de/install scripts can complete.
I'd look at each site that is affected and see what packages they have in common. Odds are, it's one of those. And you might consider uninstalling the packages before running the upgrade on the next device to see how it goes.
-
Hmmm. Even after reboot if I try to update/install/uninstall packages I just get:
Please wait while the update system initializes
EDIT:
And when I try from the command line:
[2.4.4-RELEASE][root@router.localdomain]/root: pkg upgrade
Updating pfSense-core repository catalogue...
pfSense-core repository is up to date.
Updating pfSense repository catalogue...
pfSense repository is up to date.
All repositories are up to date.
process with pid 60991 still holds the lock
process with pid 60991 still holds the lock
process with pid 60991 still holds the lock
process with pid 60991 still holds the lock
process with pid 60991 still holds the lock
process with pid 60991 still holds the lock
pkg: Cannot get an advisory lock on a database, it is locked by another process
[2.4.4-RELEASE][root@router.localdomain]/root: ps -aux | grep 60991
root 60991 0.0 0.3 24676 13700 u0 I+ 10:49 0:01.80 pkg-static upgrade -U
root 25342 0.0 0.1 6564 2456 0 S+ 12:01 0:00.01 grep 60991 -
Gave it another hour and it still hadn't finished. Tried to run a reboot but it hung after stopping icap. Forced a reboot and everything looks updated now.
-
Just hopped on the second box I'm upgrading, hung at the same spot. Ctrl+t gives:
load: 0.73 cmd: sh 66890 [fifoow] 11850.05r 0.00u 0.00s 0% 2816k
Maybe that means something to you?
-
@stewart said in Crash report on upgrade:
fifoow
https://wiki.freebsd.org/WaitChannels
Waiting in a blocking write-only open of a FIFO (O_WRONLY) for another process to open a readable descriptor on this FIFO (O_RDWR or O_RDONLY)
So again it's stuck waiting on some process to finish up before it can proceed. If you can still ssh to the box you could check the
ps uxawwdoutput and see what is running. -
@jimp said in Crash report on upgrade:
ps uxawwd
There's a lot in there and I'll post it below, but I'm guessing this is what would be relevant?
root 28 0.0 0.1 13096 2324 u0 Is+ 10:46 0:00.03 `-- sh /etc/rc autoboot root 45541 0.0 0.1 6968 2824 u0 I+ 10:49 0:00.01 `-- /bin/sh /usr/local/sbin/pfSense-upgrade -y -U -b 3 root 46142 0.0 0.0 4140 1956 u0 I+ 10:49 0:00.00 `-- /usr/bin/lockf -s -t 5 /tmp/pfSense-upgrade.lock /usr/local/libexec/pfSense-upgrade -y -U -b 3 root 46195 0.0 0.1 6968 3028 u0 I+ 10:49 0:00.04 `-- /bin/sh /usr/local/libexec/pfSense-upgrade -y -U -b 3 root 60325 0.0 0.1 6968 3028 u0 I+ 10:49 0:00.00 `-- /bin/sh /usr/local/libexec/pfSense-upgrade -y -U -b 3 root 60470 0.0 0.1 6968 3028 u0 I+ 10:49 0:00.00 |-- /bin/sh /usr/local/libexec/pfSense-upgrade -y -U -b 3 root 60620 0.0 0.2 10340 6208 u0 I+ 10:49 0:00.00 | `-- pkg-static upgrade -U root 60991 0.0 0.3 24676 13700 u0 I+ 10:49 0:01.80 | `-- pkg-static upgrade -U clamav 6903 0.0 0.0 0 0 - Z 10:49 0:00.01 | |-- <defunct> root 12405 0.0 0.0 0 0 - Z 10:49 0:00.01 | |-- <defunct> clamav 24641 0.0 14.8 662788 612928 - Is 10:51 5:46.23 | |-- /usr/local/sbin/clamd --config-file=/usr/local/etc/clamd.conf root 5293 0.0 0.0 0 0 u0 Z+ 10:49 0:00.01 | |-- <defunct> root 5895 0.0 0.0 0 0 u0 Z+ 10:49 0:00.03 | |-- <defunct> root 15841 0.0 0.0 0 0 u0 Z+ 10:49 0:00.01 | |-- <defunct> root 16086 0.0 0.0 0 0 u0 Z+ 10:49 0:00.10 | |-- <defunct> root 17739 0.0 1.1 52988 45760 u0 I+ 10:49 0:04.34 | |-- /usr/local/bin/php -f /etc/rc.packages pfSense-pkg-squidGuard POST-INSTALL root 66829 0.0 0.0 0 0 u0 Z+ 10:49 0:00.01 | | `-- <defunct> root 29814 0.0 0.0 0 0 u0 ZN+ 10:49 0:00.02 | |-- <defunct> root 66568 0.0 0.0 0 0 u0 Z+ 10:49 2:04.37 | |-- <defunct> root 66890 0.0 0.1 6968 2832 u0 I+ 10:49 0:00.00 | `-- sh -c /usr/bin/nohup /bin/echo -n "reconfigure" > /var/run/c-icap/c-icap.ctl > /dev/null 2>&1 & echo $! root 60542 0.0 0.0 6192 1996 u0 IC+ 10:49 0:00.01 |-- tee -a /cf/conf/upgrade_log.txt root 60751 0.0 0.1 6564 2496 u0 I+ 10:49 0:00.01 |-- grep -v pkg-static: Warning: Major OS version upgrade detected. root 60905 0.0 0.1 6564 2476 u0 I+ 10:49 0:00.00 `-- grep -v is locked and may not be modified66890 appears to be part of c-icap
-
Here is the full output:
USER PID %CPU %MEM VSZ RSS TT STAT STARTED TIME COMMAND root 0 0.0 0.0 0 560 - DLs 10:46 0:00.14 [kernel] root 11 400.0 0.0 0 64 - RNL 10:46 903:10.40 - [idle] root 1 0.0 0.0 5028 812 - ILs 10:46 0:00.08 - /sbin/init -- root 55591 2.4 11.2 514856 464180 - Ss 11:44 7:16.38 |-- /usr/local/bin/suricata -i igb1 -D -c /usr/local/etc/suricata/suricata_28922_igb1/suricata.yaml --pidfile /var/run/suricata_igb128922.pid root 64348 2.4 8.2 379160 338184 - Ss 11:44 7:27.99 |-- /usr/local/bin/suricata -i igb2 -D -c /usr/local/etc/suricata/suricata_58265_igb2/suricata.yaml --pidfile /var/run/suricata_igb258265.pid root 2033 0.0 0.7 88268 30348 - Ss 10:48 0:01.10 |-- php-fpm: master process (/usr/local/lib/php-fpm.conf) (php-fpm) root 2034 0.0 1.0 92756 40556 - I 10:48 0:18.75 | |-- php-fpm: pool nginx (php-fpm) root 57906 0.0 0.1 6968 2816 - I 11:43 0:00.01 | | `-- /bin/sh root 58454 0.0 0.1 6968 2824 - I 11:43 0:00.01 | | `-- /bin/sh /usr/local/etc/rc.d/c-icap.sh stop root 58618 0.0 0.1 6968 2824 - I 11:43 0:00.00 | | `-- /bin/sh /usr/local/etc/rc.d/c-icap.sh stop root 2035 0.0 1.0 92948 41604 - S 10:48 0:29.74 | |-- php-fpm: pool nginx (php-fpm) root 7352 0.0 1.0 92628 39760 - I 11:45 0:08.86 | |-- php-fpm: pool nginx (php-fpm) root 15096 0.0 1.0 92628 39808 - I 11:45 0:09.65 | |-- php-fpm: pool nginx (php-fpm) root 82385 0.0 1.0 90444 40636 - I 10:53 0:04.82 | |-- php-fpm: pool nginx (php-fpm) root 61973 0.0 0.0 0 0 - Z 10:53 0:00.01 | | `-- <defunct> root 90618 0.0 1.0 94676 42100 - I 10:49 0:29.38 | |-- php-fpm: pool nginx (php-fpm) root 97028 0.0 1.0 88464 39516 - I 10:53 0:27.07 | |-- php-fpm: pool nginx (php-fpm) root 99387 0.0 1.0 90512 41068 - I 10:53 0:21.98 | `-- php-fpm: pool nginx (php-fpm) root 40579 0.0 0.0 0 0 - Z 11:46 0:00.01 | `-- <defunct> root 2072 0.0 0.1 9240 5224 - INs 10:48 0:00.06 |-- /usr/local/sbin/check_reload_status root 2074 0.0 0.1 9240 5036 - IN 10:48 0:00.00 | `-- check_reload_status: Monitoring daemon of check_reload_status root 2113 0.0 0.1 9184 5048 - Is 10:48 0:00.05 |-- /sbin/devd -q -f /etc/pfSense-devd.conf unbound 6939 0.0 1.1 57092 47320 - Ss 11:46 0:02.82 |-- /usr/local/sbin/unbound -c /var/unbound/unbound.conf root 9913 0.0 0.2 12612 8800 - Is 10:48 0:00.01 |-- /usr/sbin/sshd root 73363 0.0 0.2 12904 9276 - Ss 14:44 0:00.17 | `-- sshd: root@pts/0 (sshd) root 73880 0.0 0.1 6968 2964 0 Is 14:44 0:00.01 | `-- -sh (sh) root 74131 0.0 0.1 6968 2840 0 I 14:44 0:00.01 | `-- /bin/sh /etc/rc.initial root 91661 0.0 0.1 7276 3688 0 S 14:44 0:00.05 | `-- /bin/tcsh root 96402 0.0 0.1 6808 2824 0 R+ 14:49 0:00.01 | `-- ps uxawwd dhcpd 16434 0.0 0.2 12576 8024 - Ss 11:46 0:01.86 |-- /usr/local/sbin/dhcpd -user dhcpd -group _dhcp -chroot /var/dhcpd -cf /etc/dhcpd.conf -pf /var/run/dhcpd.pid igb0 root 16728 0.0 0.1 6600 2616 - Ss 10:48 0:20.55 |-- /usr/local/sbin/filterlog -i pflog0 -p /var/run/filterlog.pid root 25507 0.0 0.1 6968 2872 - IN 11:46 0:04.08 |-- /bin/sh /var/db/rrd/updaterrd.sh root 95301 0.0 0.0 4144 1952 - INC 14:49 0:00.00 | `-- sleep 60 root 40909 0.0 0.1 6968 2816 - I 11:46 0:00.00 |-- sh -c /usr/bin/nohup /bin/echo -n "reconfigure" > /var/run/c-icap/c-icap.ctl > /dev/null 2>&1 & echo $! root 42883 0.0 0.1 6392 2556 - Ss 10:49 0:11.49 |-- /usr/sbin/syslogd -s -c -c -l /var/dhcpd/var/run/log -P /var/run/syslog.pid -f /etc/syslog.conf root 76000 0.0 0.1 6968 2848 - Is 10:49 0:00.01 | `-- /bin/sh /usr/local/sbin/sshguard root 76294 0.0 0.0 6196 2004 - I 10:49 0:00.00 | |-- cat root 76301 0.0 0.2 11612 7452 - IC 10:49 0:00.01 | |-- /usr/local/libexec/sshg-parser root 76327 0.0 0.1 6524 2484 - IC 10:49 0:00.03 | |-- /usr/local/libexec/sshg-blocker -s 3600 root 76581 0.0 0.1 6968 2848 - I 10:49 0:00.00 | `-- /bin/sh /usr/local/sbin/sshguard root 76637 0.0 0.1 6968 2836 - I 10:49 0:00.01 | `-- /bin/sh /usr/local/libexec/sshg-fw-pf root 43441 0.0 0.0 6192 2024 - Is 10:49 0:00.00 |-- /usr/local/bin/minicron 240 /var/run/ping_hosts.pid /usr/local/bin/ping_hosts.sh root 43998 0.0 0.0 6192 2040 - S 10:49 0:00.01 | `-- minicron: helper /usr/local/bin/ping_hosts.sh (minicron) root 44108 0.0 0.0 6192 2024 - Is 10:49 0:00.00 |-- /usr/local/bin/minicron 3600 /var/run/expire_accounts.pid /usr/local/sbin/fcgicli -f /etc/rc.expireaccounts root 44579 0.0 0.0 6192 2040 - S 10:49 0:00.00 | `-- minicron: helper /usr/local/sbin/fcgicli -f /etc/rc.expireaccounts (minicron) root 44886 0.0 0.0 6192 2024 - Is 10:49 0:00.00 |-- /usr/local/bin/minicron 86400 /var/run/update_alias_url_data.pid /usr/local/sbin/fcgicli -f /etc/rc.update_alias_url_data root 45145 0.0 0.0 6192 2040 - I 10:49 0:00.00 | `-- minicron: helper /usr/local/sbin/fcgicli -f /etc/rc.update_alias_url_data (minicron) nobody 51475 0.0 0.1 6772 2876 - Is 11:44 0:00.06 |-- /usr/local/sbin/darkstat -i igb2 -p 666 nobody 51713 0.0 0.1 6772 2708 - Is 11:44 0:00.00 | `-- darkstat: DNS child (darkstat) root 54885 0.0 0.2 10360 6696 - S 10:53 0:01.03 |-- /usr/local/sbin/lighttpd_pfb -f /var/unbound/pfb_dnsbl_lighty.conf root 57465 0.0 0.1 6900 2456 - Is 11:46 0:05.08 |-- /usr/local/bin/dpinger -S -r 0 -i WAN_DHCP -B 192.168.0.124 -p /var/run/dpinger_WAN_DHCP~192.168.0.124~192.168.0.1.pid -u /var/run/dpinger_WAN_DHCP~192.168.0.124~192.168.0.1.sock -C /etc/rc.gateway_alarm -d 0 -s 500 -l 2000 -t 60000 -A 1000 -D 500 -L 20 192.168.0.1 root 60576 0.0 1.6 69636 64416 - Ss 11:46 0:03.18 |-- /usr/sbin/bsnmpd -c /var/etc/snmpd.conf -p /var/run/snmpd.pid root 60937 0.0 1.1 50876 43688 - S 10:53 0:13.29 |-- /usr/local/bin/php -f /usr/local/pkg/pfblockerng/pfblockerng.inc dnsbl root 61027 0.0 0.2 21544 7784 - Is 10:48 0:00.00 |-- nginx: master process /usr/local/sbin/nginx -c /var/etc/nginx-webConfigurator.conf (nginx) root 61050 0.0 0.2 23592 9528 - I 10:48 0:00.26 | |-- nginx: worker process (nginx) root 61380 0.0 0.2 23592 9828 - I 10:48 0:18.94 | `-- nginx: worker process (nginx) root 62182 0.0 0.1 6368 2496 - Is 10:48 0:00.46 |-- /usr/sbin/cron -s root 62198 0.0 0.1 6968 2816 - I 10:53 0:00.00 |-- sh -c /usr/bin/nohup /bin/echo -n "reconfigure" > /var/run/c-icap/c-icap.ctl > /dev/null 2>&1 & echo $! root 62947 0.0 0.3 12396 12500 - Ss 10:48 0:03.77 |-- /usr/local/sbin/ntpd -g -c /var/etc/ntpd.conf -p /var/run/ntpd.pid root 67275 0.0 0.1 6448 2428 - Is 11:46 0:00.00 |-- dhclient: igb1 [priv] (dhclient) _dhcp 72261 0.0 0.1 6448 2532 - ICs 11:46 0:00.02 |-- dhclient: igb1 (dhclient) root 76101 0.0 0.1 6196 2228 - Is 14:06 0:00.00 |-- /usr/local/sbin/dhcpleases -l /var/dhcpd/var/db/dhcpd.leases -d localdomain -p /var/run/unbound.pid -u /var/unbound/dhcpleases_entries.conf -h /etc/hosts root 98040 0.0 0.1 6288 2112 - Ss 10:49 0:06.18 |-- /usr/sbin/powerd -b min -a adp -n adp root 28 0.0 0.1 13096 2324 u0 Is+ 10:46 0:00.03 `-- sh /etc/rc autoboot root 45541 0.0 0.1 6968 2824 u0 I+ 10:49 0:00.01 `-- /bin/sh /usr/local/sbin/pfSense-upgrade -y -U -b 3 root 46142 0.0 0.0 4140 1956 u0 I+ 10:49 0:00.00 `-- /usr/bin/lockf -s -t 5 /tmp/pfSense-upgrade.lock /usr/local/libexec/pfSense-upgrade -y -U -b 3 root 46195 0.0 0.1 6968 3028 u0 I+ 10:49 0:00.04 `-- /bin/sh /usr/local/libexec/pfSense-upgrade -y -U -b 3 root 60325 0.0 0.1 6968 3028 u0 I+ 10:49 0:00.00 `-- /bin/sh /usr/local/libexec/pfSense-upgrade -y -U -b 3 root 60470 0.0 0.1 6968 3028 u0 I+ 10:49 0:00.00 |-- /bin/sh /usr/local/libexec/pfSense-upgrade -y -U -b 3 root 60620 0.0 0.2 10340 6208 u0 I+ 10:49 0:00.00 | `-- pkg-static upgrade -U root 60991 0.0 0.3 24676 13700 u0 I+ 10:49 0:01.80 | `-- pkg-static upgrade -U clamav 6903 0.0 0.0 0 0 - Z 10:49 0:00.01 | |-- <defunct> root 12405 0.0 0.0 0 0 - Z 10:49 0:00.01 | |-- <defunct> clamav 24641 0.0 14.8 662788 612928 - Is 10:51 5:46.23 | |-- /usr/local/sbin/clamd --config-file=/usr/local/etc/clamd.conf root 5293 0.0 0.0 0 0 u0 Z+ 10:49 0:00.01 | |-- <defunct> root 5895 0.0 0.0 0 0 u0 Z+ 10:49 0:00.03 | |-- <defunct> root 15841 0.0 0.0 0 0 u0 Z+ 10:49 0:00.01 | |-- <defunct> root 16086 0.0 0.0 0 0 u0 Z+ 10:49 0:00.10 | |-- <defunct> root 17739 0.0 1.1 52988 45760 u0 I+ 10:49 0:04.34 | |-- /usr/local/bin/php -f /etc/rc.packages pfSense-pkg-squidGuard POST-INSTALL root 66829 0.0 0.0 0 0 u0 Z+ 10:49 0:00.01 | | `-- <defunct> root 29814 0.0 0.0 0 0 u0 ZN+ 10:49 0:00.02 | |-- <defunct> root 66568 0.0 0.0 0 0 u0 Z+ 10:49 2:04.37 | |-- <defunct> root 66890 0.0 0.1 6968 2832 u0 I+ 10:49 0:00.00 | `-- sh -c /usr/bin/nohup /bin/echo -n "reconfigure" > /var/run/c-icap/c-icap.ctl > /dev/null 2>&1 & echo $! root 60542 0.0 0.0 6192 1996 u0 IC+ 10:49 0:00.01 |-- tee -a /cf/conf/upgrade_log.txt root 60751 0.0 0.1 6564 2496 u0 I+ 10:49 0:00.01 |-- grep -v pkg-static: Warning: Major OS version upgrade detected. root 60905 0.0 0.1 6564 2476 u0 I+ 10:49 0:00.00 `-- grep -v is locked and may not be modified root 2 0.0 0.0 0 16 - DL 10:46 0:00.00 - [crypto] root 3 0.0 0.0 0 16 - DL 10:46 0:00.00 - [crypto returns 0] root 4 0.0 0.0 0 16 - DL 10:46 0:00.00 - [crypto returns 1] root 5 0.0 0.0 0 16 - DL 10:46 0:00.00 - [crypto returns 2] root 6 0.0 0.0 0 16 - DL 10:46 0:00.00 - [crypto returns 3] root 7 0.0 0.0 0 32 - DL 10:46 0:04.41 - [cam] root 8 0.0 0.0 0 16 - DL 10:46 0:00.01 - [soaiod1] root 9 0.0 0.0 0 16 - DL 10:46 0:00.01 - [soaiod2] root 10 0.0 0.0 0 16 - DL 10:46 0:00.00 - [audit] root 12 0.0 0.0 0 544 - WL 10:46 1:02.28 - [intr] root 13 0.0 0.0 0 64 - DL 10:46 0:00.00 - [ng_queue] root 14 0.0 0.0 0 48 - DL 10:46 0:00.07 - [geom] root 15 0.0 0.0 0 160 - DL 10:46 0:01.62 - [usb] root 16 0.0 0.0 0 16 - DL 10:46 0:00.01 - [soaiod3] root 17 0.0 0.0 0 16 - DL 10:46 0:00.01 - [soaiod4] root 18 0.0 0.0 0 16 - DL 10:46 0:00.00 - [sctp_iterator] root 19 0.0 0.0 0 16 - DL 10:46 0:05.86 - [pf purge] root 20 0.0 0.0 0 16 - DL 10:46 0:01.79 - [rand_harvestq] root 21 0.0 0.0 0 48 - DL 10:46 0:03.86 - [pagedaemon] root 22 0.0 0.0 0 16 - DL 10:46 0:00.00 - [vmdaemon] root 23 0.0 0.0 0 16 - DNL 10:46 0:00.00 - [pagezero] root 24 0.0 0.0 0 16 - DL 10:46 0:00.77 - [bufspacedaemon] root 25 0.0 0.0 0 32 - DL 10:46 0:02.63 - [bufdaemon] root 26 0.0 0.0 0 16 - DL 10:46 0:00.34 - [vnlru] root 27 0.0 0.0 0 16 - DL 10:46 0:16.95 - [syncer] root 60 0.0 0.0 0 16 - DL 10:46 0:00.11 - [md0] -
So it's stuck waiting on squidGuard's post-install script to finish, whatever it's doing.
This is definitely a situation where you should uninstall all the packages before attempting the upgrade. Something in there is stopping it, but it's difficult to say what exactly at that point.
-
Well, reboots seem to get it past the problem so it isn't that huge of a deal. Do the packages need to be uninstalled/reinstalled or just disabled?
-
Rebooting it is probably breaking something, though. The package reinstall didn't complete, so who knows which packages are OK and which need reinstalled yet. I'd remove and then install all of the packages again for good measure.
-
Sounds good. Thanks for the help!
