pfSense

He's alive! :-)

This sounds like a different failure mode with potentially the same root cause as #5592, which appears to be happening much more often on recent releases than in the past.

This is the first time I've heard of it hanging, though. The usual failure mode is that something panics/crashes (or in some cases, a loss of power), then fsck checks on the next boot and marks it clean despite the filesystem still having errors. After it passes that point, it panics when encountering a bad directory on the disk, which reboots it again, fsck checks, marks it clean but still doesn't find the real problem, so it panics again, lather, rinse, repeat. Though we know it happens, we have not yet found a means to reproduce it on demand.

In those cases the only way around it is to boot single user mode and run fsck repeatedly until it no longer finds any problems. That's hard to do programmatically since fsck appears to exit without an error code when it finds and fixes problems, so it's hard to know it needs a repeat. And running fsck multiple times on each boot would unnecessarily slow down large disks / slower media installs.

Jim Pingle wrote:

He's alive! :-)

Yeah, indeed... :-)

This sounds like a different failure mode with potentially the same root cause as #5592, which appears to be happening much more often on recent releases than in the past.

This is the first time I've heard of it hanging, though. The usual failure mode is that something panics/crashes (or in some cases, a loss of power), then fsck checks on the next boot and marks it clean despite the filesystem still having errors. After it passes that point, it panics when encountering a bad directory on the disk, which reboots it again, fsck checks, marks it clean but still doesn't find the real problem, so it panics again, lather, rinse, repeat. Though we know it happens, we have not yet found a means to reproduce it on demand.

Yeah. It hangs. Now, as I have discovered after whole lot of messing, it hangs reliably on every second reboot, no matter the troubleshooting steps above. It's repeatable with journaling turned off, it's repeatable with SU+J turned off.

In those cases the only way around it is to boot single user mode and run fsck repeatedly until it no longer finds any problems. That's hard to do programmatically since fsck appears to exit without an error code when it finds and fixes problems, so it's hard to know it needs a repeat. And running fsck multiple times on each boot would unnecessarily slow down large disks / slower media installs.

When I boot to single user mode, the fsck finds nothing. No breakage. No matter how many times I try. Then, I reboot and end up with

Using /dev/label/swap0 for dump device.
/dev/ufsid/567c0b01685c651a: NO WRITE ACCESS
/dev/ufsid/567c0b01685c651a: UNEXPECTED INCONSISTENCY; RUN fsck MANUALLY.
Preen mode recommended running a check that will be performed now.
WARNING: Trying to recover filesystem from inconsistency...

once again.

For now, I'd appreciate some advise how to make the absolutely broken fsck thing totally no-op. Without it, I'm very much stuck with reinstalling the entire system, because the filesystem check is just completely FUBARed. :-( It fixes nothing, it just causes damage.

Kill Bill wrote:

it hangs reliably on every second reboot, no matter the troubleshooting steps above. It's repeatable with journaling turned off, it's repeatable with SU+J turned off.

So I thought to add

/usr/bin/touch /root/force_fsck

as shellcmd. Does not help. The only way to hack around this seems to be the CTRL+C and exit command. With that, the fsck produces

^CEnter full pathname of shell or RETURN for /bin/sh:
# exit
Configuring crash dumps...
Using /dev/label/swap0 for dump device.
/dev/ufsid/567c0b01685c651a: NO WRITE ACCESS
/dev/ufsid/567c0b01685c651a: UNEXPECTED INCONSISTENCY; RUN fsck MANUALLY.
Preen mode recommended running a check that will be performed now.
WARNING: Trying to recover filesystem from inconsistency...
** /dev/ufsid/567c0b01685c651a (NO WRITE)
** Last Mounted on /
** Root file system
** Phase 1 - Check Blocks and Sizes
** Phase 2 - Check Pathnames
** Phase 3 - Check Connectivity
** Phase 4 - Check Reference Counts
UNREF FILE I=5377154  OWNER=root MODE=100666
SIZE=0 MTIME=May 10 18:00 2016
CLEAR? no

** Phase 5 - Check Cyl groups
324509 files, 867999 used, 12237772 free (6844 frags, 1528866 blocks, 0.1% fragmentation)

and on next reboot it finds no breakage and it works. Now, when I do

# touch /root/force_fsck
# reboot

instead, on next boot I get

Forcing filesystem(s) check...
** /dev/ufsid/567c0b01685c651a
** Last Mounted on /
** Root file system
** Phase 1 - Check Blocks and Sizes
** Phase 2 - Check Pathnames
** Phase 3 - Check Connectivity
** Phase 4 - Check Reference Counts
** Phase 5 - Check Cyl groups
324522 files, 868015 used, 12237756 free (6828 frags, 1528866 blocks, 0.1% fragmentation)

***** FILE SYSTEM IS CLEAN *****
/dev/ufsid/567c0b01685c651a: FILE SYSTEM CLEAN; SKIPPING CHECKS
/dev/ufsid/567c0b01685c651a: clean, 12237756 free (6828 frags, 1528866 blocks, 0.1% fragmentation)
Filesystems are clean, continuing...
Mounting filesystems...

No problem is found, yet it hangs in exactly the same place, producing exactly the same fsck error as posted above after the CTRL+C; exit drill.

UNREF FILE I=5377154  OWNER=root MODE=100666

Just the MTIME of that file gets updated across reboots. This is just absurd...

- fsck like this is not usable at all.
- how do I find which file is using that inode?
- what's the difference between the initial fsck that fails to find anything and the latter one that produces this whole fsck-up!?

Sigh. :-(

Renato Botelho wrote:

So you have SUJ off, but you have Soft Updates enabled, right? Did you disabled SUJ for any reason or is it an old installation from the time pfSense didn't set it yet?

If Jakub turned off SUJ, this is a mistake.

Renato Botelho wrote:

So you have SUJ off, but you have Soft Updates enabled, right? Did you disabled SUJ for any reason or is it an old installation from the time pfSense didn't set it yet?

No, this was not any old upgraded install. Happened on a fresh 2.3 full install with SU+J being turned on from the very start. Was done just for testing purposes after lots of attempts to make the damned fsck thing do what's it supposed to do to no avail. Turned off just the journal, made no difference, turned both off, made no difference, turned both back on, made again no difference.

Here's the debug output with the patch applied:

^CEnter full pathname of shell or RETURN for /bin/sh:
# exit
Configuring crash dumps...
Using /dev/label/swap0 for dump device.
/dev/ufsid/567c0b01685c651a: NO WRITE ACCESS
/dev/ufsid/567c0b01685c651a: UNEXPECTED INCONSISTENCY; RUN fsck MANUALLY.
Preen mode recommended running a check that will be performed now.
WARNING: Trying to recover filesystem from inconsistency...
** /dev/ufsid/567c0b01685c651a (NO WRITE)

USE JOURNAL? no

** Skipping journal, falling through to full fsck

SETTING DIRTY FLAG IN READ_ONLY MODE

UNEXPECTED SOFT UPDATE INCONSISTENCY
** Last Mounted on /
** Root file system
** Phase 1 - Check Blocks and Sizes
** Phase 2 - Check Pathnames
** Phase 3 - Check Connectivity
UNREF DIR  I=5136450  OWNER=root MODE=40755
SIZE=512 MTIME=May 10 22:27 2016
RECONNECT? no

** Phase 4 - Check Reference Counts
LINK COUNT DIR I=5136450  OWNER=root MODE=40755
SIZE=512 MTIME=May 10 22:27 2016  COUNT 2 SHOULD BE 1
ADJUST? no

UNREF FILE I=5377164  OWNER=root MODE=100666
SIZE=0 MTIME=May 10 22:27 2016
CLEAR? no

** Phase 5 - Check Cyl groups
324510 files, 876310 used, 12229461 free (6853 frags, 1527826 blocks, 0.1% fragmentation)
DEBUG: Run #1 - rc = 0
/dev/ufsid/567c0b01685c651a: NO WRITE ACCESS
/dev/ufsid/567c0b01685c651a: UNEXPECTED INCONSISTENCY; RUN fsck MANUALLY.
DEBUG: (-p) #1 - rc = 8
** /dev/ufsid/567c0b01685c651a (NO WRITE)

USE JOURNAL? no

** Skipping journal, falling through to full fsck

SETTING DIRTY FLAG IN READ_ONLY MODE

UNEXPECTED SOFT UPDATE INCONSISTENCY
** Last Mounted on /
** Root file system
** Phase 1 - Check Blocks and Sizes
** Phase 2 - Check Pathnames
** Phase 3 - Check Connectivity
** Phase 4 - Check Reference Counts
UNREF FILE I=5377164  OWNER=root MODE=100666
SIZE=0 MTIME=May 10 22:27 2016
CLEAR? no

** Phase 5 - Check Cyl groups
324510 files, 876310 used, 12229461 free (6853 frags, 1527826 blocks, 0.1% fragmentation)
DEBUG: Run #2 - rc = 0
/dev/ufsid/567c0b01685c651a: NO WRITE ACCESS
/dev/ufsid/567c0b01685c651a: UNEXPECTED INCONSISTENCY; RUN fsck MANUALLY.
DEBUG: (-p) #2 - rc = 8
** /dev/ufsid/567c0b01685c651a (NO WRITE)

USE JOURNAL? no

** Skipping journal, falling through to full fsck

SETTING DIRTY FLAG IN READ_ONLY MODE

UNEXPECTED SOFT UPDATE INCONSISTENCY
** Last Mounted on /
** Root file system
** Phase 1 - Check Blocks and Sizes
** Phase 2 - Check Pathnames
** Phase 3 - Check Connectivity
** Phase 4 - Check Reference Counts
UNREF FILE I=5377164  OWNER=root MODE=100666
SIZE=0 MTIME=May 10 22:27 2016
CLEAR? no

** Phase 5 - Check Cyl groups
324510 files, 876310 used, 12229461 free (6853 frags, 1527826 blocks, 0.1% fragmentation)
DEBUG: Run #3 - rc = 0
/dev/ufsid/567c0b01685c651a: NO WRITE ACCESS
/dev/ufsid/567c0b01685c651a: UN.
DEBUG: (-p) #3 - rc = 8
Automatic filesystem recovery failed. Starting recovery shell!

Don't think the fsck will ever produce any useful fixes, keeping the b0rked system just for debugging now, will reinstall soon.

Kill Bill wrote:

No, this was not any old upgraded install. Happened on a fresh 2.3 full install with SU+J being turned on from the very start.

We did an enormous amount of testing and came to a stable solution.

Running outside that solution is not recommended.

Yeah, I understand it's not recommended or supported or whatever, however the stable solution (which was in place when the damage happened) does not work here apparently. The only stable thing for me was ZFS - which, sadly, ain't doable any more with 2.3

Anyway, after a couple more fsck runs in single user mode, it looks like the thing is actually producing just additional damage instead of fixing things; this fsck is just absurdly broken and completely unreliable. How's this possible with such mature systems like FreeBSD goes beyond me. :/

Kill Bill wrote:

The only stable thing for me was ZFS - which, sadly, ain't doable any more with 2.3

Why wouldn't this be possible anymore? I have pfSense running on a ZFS pool with ashift=12. The trick is to create a ZFS pool in FreeBSD, and import that while manually installing pfSense. Or, also possible, create a ZFS pool in FreeBSD, and copy all pfSense files from the pfSense iso mounted on a different virtual cd drive (ipmi can be very handy). It's probably not ideal, but at least I kinda knew what I was doing. (with emphasis on kinda)

doktornotor: welcome back. What's your wireless config like on there? What type of card and config. Not that it should matter, but piecing together some of the reports of this, it seems like the systems that can most readily replicate have wireless cards.

Jan Jurkus wrote:

Kill Bill wrote:

The only stable thing for me was ZFS - which, sadly, ain't doable any more with 2.3

Why wouldn't this be possible anymore?

He's referring to the web installer, which was removed in one of the 2.2.x versions.

Chris Buechler wrote:

He's referring to the web installer, which was removed in one of the 2.2.x versions.

Ah, that's why.

When talking about power failures it might be an issue of the used hardware. Read for instance this test about SSD and power losses:
http://lkcl.net/reports/ssd_analysis.html
It might be a contributing factor here.

Chris Buechler wrote:

doktornotor: welcome back. What's your wireless config like on there? What type of card and config. Not that it should matter, but piecing together some of the reports of this, it seems like the systems that can most readily replicate have wireless cards.

There is no wireless card in there. Onboard WAN (PPPoE plus IPv6 tunnel) and Gbit Intel LAN, that's all.

Jan Jurkus wrote:

Read for instance this test about SSD and power losses:
http://lkcl.net/reports/ssd_analysis.html
It might be a contributing factor here.

The SSD is Transcend SSD370S. Seriously, the main issues I can see here:

- the system works just fine with absolutely no errors when it actually boots. So, a minor filesystem issue is breaking the entire system due to the fsck stupidity.
- UFS's fsck is just utterly useless; its just random result generator, at best. Fails to find errors, fixes nothing, causes additional breakage. When you have a garbage fsck like this, you either need to skip it altogether, or switch to a different filesystem.

All this took to cause apparently fatal damage to the "robust" UFS was a single power failure. Since the SSD is just 64GiB and most of it is empty, I might be able to upload the image somewhere, eventually.

Kindly provide a choice of filesystem on install - every single Linux distro can do that, why's that mission impossible here? My trust in UFS has reached a freezing point. And the trust in the fsck is at absolute zero. Seriously noone upstream cares about fixing this piece of utter garbage? Bugs filed and rotting there for years and years.

And here we go again: I'm seeing this on 3 boxes already:

Crash report details:

PHP Errors:
[02-Oct-2016 20:23:40 Europe/Prague] PHP Warning:  Invalid argument supplied for foreach() in /etc/inc/auth.inc on line 341
[02-Oct-2016 20:23:40 Europe/Prague] PHP Stack trace:
[02-Oct-2016 20:23:40 Europe/Prague] PHP   1. {main}() /etc/rc.bootup:0
[02-Oct-2016 20:23:40 Europe/Prague] PHP   2. local_sync_accounts() /etc/rc.bootup:307
[02-Oct-2016 20:23:40 Europe/Prague] PHP   3. local_user_set() /etc/inc/auth.inc:468
[02-Oct-2016 20:23:40 Europe/Prague] PHP   4. userHasPrivilege() /etc/inc/auth.inc:508
[02-Oct-2016 20:23:40 Europe/Prague] PHP   5. get_user_privileges() /etc/inc/auth.inc:357

Every time I see this, there's a hidden, totally undetected filesystem corruption.

/dev/ufsid/571632113ba7d395: FILE SYSTEM CLEAN; SKIPPING CHECKS
/dev/ufsid/571632113ba7d395: clean, 5224247 free (4607 frags, 652455 blocks, 0.1% fragmentation)
Filesystems are clean, continuing...
Mounting filesystems...
Disabling APM on /dev/ad4

Sigh. Is there some usable filesystem planned for 2.4?

In case you planned on asking whether I tried to run fsck manually, then yeah, I did on one local box - and the outcome was totally identical to that in https://redmine.pfsense.org/issues/6340#note-7 - it resulted in complete filesystem destruction. So no, I do not plan to ever test this on other boxes - they are remote ones and I have better things to do than travelling there to replace the SSDs with freshly installed ones.

Kill Bill,

We have been effected by this issue as we have boxes all around America running that are bricking at random.

Can you tell me if there is a fix in any of the new versions of updates out or planned soon?

Derek, I cannot see any fix until the installer brings back the possibility to install on ZFS, and/or use a time-proven Linux filesystem (such as ext2). UFS, as far as I am concerned, is a completely broken thing I don't want to ever see anywhere in production again. I would advise to use an UPS but at least 2/3 of the affected boxes here are running on UPS already which lasts for a couple of hours. The longest blackout seen was well below one hour, so there's basically never been an unclean shutdown, ever. Yet, the filesystem is silently rotting, rotting and rotting. (Don't ever attempt to fix it with fsck, the only thing that this "utility" is capable of is a reliable filesystem destruction.)

On another note - seeing that the corruption yet again revolves around the /etc/{master.passwd,group,...} files, we basically haven't moved anywhere since Bug #4523 (IOW, blaming the /usr/sbin/pw utility was just, well... meh.)

Getting ZFS back at least should be a top priority for 2.4, IMNSHO. Afraid that's not something that's gonna happen, though. :-(((

Thank you for your quick reply. I'll just need to wait to see what comes of all of this.

@Derek: If you are willing to go back to <=2.2.2 for initial full install, you could try this: https://forum.pfsense.org/index.php?topic=94656.0 - after that, it should survive upgrade to 2.3.x normally. (Of course, none of this is supported in any way.)

Kill Bill wrote:

@Derek: If you are willing to go back to <=2.2.2 for initial full install, you could try this: https://forum.pfsense.org/index.php?topic=94656.0 - after that, it should survive upgrade to 2.3.x normally. (Of course, none of this is supported in any way.)

I attempted the instructions you sent to me, but I keep getting this error.

kern.geom.debugflags: 0 -> 16
Deleting all gparts
Running: gpart delete -i 1 ada0
ada0s1 deleted
Running: dd if=/dev/zero of=/dev/ada0 count=3000
3000+0 records in
3000+0 records out
1536000 bytes transferred in 0.246504 secs (6231134 bytes/sec)
Cleaning up ada0
Running: dd if=/dev/zero of=/dev/ada0 count=2048
2048+0 records in
2048+0 records out
1048576 bytes transferred in 0.176085 secs (5954942 bytes/sec)
Running gpart on ada0
Running: gpart create -s mbr ada0
ada0 created
Running gpart add on ada0
Running: gpart add -b 63 -s 62533233 -t freebsd -i 1 ada0
ada0s1 added
Cleaning up ada0s1
Running: dd if=/dev/zero of=/dev/ada0s1 count=1024
1024+0 records in
1024+0 records out
524288 bytes transferred in 0.104270 secs (5028178 bytes/sec)
Stamping boot1 on ada0
Running: gpart bootcode -b /boot/boot1 ada0
bootcode written to ada0
NEWFS: /dev/ada0s1a - ZFS
Running: zpool create -m none -f tank0 ada0s1a
Running: zfs set atime=off tank0
Setting up ZFS boot loader support
Running: zpool set bootfs=tank0 tank0
Running: zpool export tank0
Running: dd if=/boot/zfsboot of=/dev/ada0s1 count=1
1+0 records in
1+0 records out
512 bytes transferred in 0.016450 secs (31125 bytes/sec)
Running: dd if=/boot/zfsboot of=/dev/ada0s1a skip=1 seek=1024
dd: /dev/ada0s1a: Operation not supported
Error 1: dd if=/boot/zfsboot of=/dev/ada0s1a skip=1 seek=1024

Managed to completely destruct entire system by a single power cycle. Unbootable, kernel panic, endless reboot cycle. Impressive - NOT! Production ready? Absolutely NOT. Guys, is anyone actually working on ZFS? We cannot continue deploying this UFS crap on remote locations, noone is going to pay the travel expenses for these self-destructing things.

So far I am happy with 2.4 running on ZFS, even it highly experimental, I use on one non so critical production firewall about month. I have had issues with UFS after unclean shutdown at least three times during last 3 years on two production firewalls.

Turn off sync mode.

On a clean system, before an issue crops up. It will let UFS do what it does, and not generate errors fsck doesn't see.

Sync mode only "works" on systems where the entire storage stack supports that part of the ATA standard through every single layer. This is why you don't see most VM's effected. Most VM's don't support the ATA stack, guest OS kernel all the way down to physical host storage. Neither do most USB bus connected SD cards. Neither do most USB flash drives.

I have one old system with a nice CF card in it, that is actually ATA compliant, plugged directly into an onboard Intel IDE controller. All forced sync mode does, is make the CF card seem horribly slow. Which in turn results in dramatically increasing the possibility of filesystem errors, because file writes take ~5x longer to complete, so ~5x more of the time failures will cause errors. Disable all mounting in sync mode on this system, and not a single filesystem error fsck doesn't correct.

Metadata on UFS is always written in sync mode, unless explicitly disabled by mounting in async mode. The file contents are either written to disk, or not, regardless of mode, so why make it less likely to happen on better hardware stacks? At the least...

At the most, weird issues with compliant storage devices / stacks, that, shocker, can't be replicated in a VM, or other hardware, that doesn't support what sync mode does, through the entire storage stack.

I saw an issue like this on the first power cycle of a new SG-2440.
manually running fsck didn't find an issue but every boot caused a panic and reboot.
I followed this:
http://phaq.phunsites.net/2007/07/01/ufs_dirbad-panic-with-mangled-entries-in-ufs/comment-page-1/
and found it was the temp directory that had got corrupted. Removed that directory through the file system debugger, then recreated it and everything seems fine now.
Only had the one power cycle since this incident though.

Graham Collinson wrote:

I saw an issue like this on the first power cycle of a new SG-2440.
manually running fsck didn't find an issue but every boot caused a panic and reboot.
I followed this:
http://phaq.phunsites.net/2007/07/01/ufs_dirbad-panic-with-mangled-entries-in-ufs/comment-page-1/
and found it was the temp directory that had got corrupted. Removed that directory through the file system debugger, then recreated it and everything seems fine now.
Only had the one power cycle since this incident though.

I suppose this box was running 2.3.2, right?

yes it was on 2.3.2

Graham Collinson wrote:

yes it was on 2.3.2

It was changed since 2.3.2. New code is on 2.3.3 and 2.4.0 snapshots.

After power cycling an appliance running 2.4.0.b.20170401.1306 with UFS FS for over an hour, dozens of fsck's were triggered but in every case the system booted successfully.