Date: Fri, 15 Mar 2013 22:27:31 +0100 From: Palle Girgensohn <girgen@FreeBSD.org> To: Kirk McKusick <mckusick@mckusick.com> Cc: freebsd-fs@freebsd.org, Jeff Roberson <jroberson@jroberson.net> Subject: Re: leaking lots of unreferenced inodes (pg_xlog files?), maybe after moving tables and indexes to tablespace on different volume Message-ID: <51439243.5020604@FreeBSD.org> In-Reply-To: <201303131652.r2DGqSr4051899@chez.mckusick.com> References: <201303131652.r2DGqSr4051899@chez.mckusick.com>
next in thread | previous in thread | raw e-mail | index | archive | help
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
Kirk McKusick skrev:
> Thanks for your report. It is certainly unlike anything that we have
> seen reported before.
>
> Are you running your /usr filesystem with (the default) journalled
> soft updates? You can check this by running the `mount' command with
> no arguments.
>
> Rather than rebooting your system, it would be most helpful if you
> could instead shut it down to single user. Then do the following:
>
> Create a transcript of your session by running `script'. Once running
> in the session run these commands:
>
> Run `mount' to show your filesystem configuration. Run `df -hi /usr'
> to see whether the inodes are still missing. Verify that you can
> cleanly unmount /usr (e.g., that the unmount does not hang and does
> not complain). Remount /usr and run `df -hi' to see whether the
> inodes are still missing. Unmount /usr again and run `fsck_ffs -p -f
> -d /usr'. If the fsck_ffs fails with an unexpected inconsistency, you
> can run `fsck_ffs -y -d /usr' to force it to clean up. When you have
> the filesystem successfully cleaned up, type `exit' to get out of the
> script session and mail me the transcript of the session
> (typescript).
>
> Thanks for your help in tracking this down.
>
> Kirk McKusick
Hi again,
A umount + mount was enough to reclaim the space.
Script started on Fri Mar 15 19:02:22 2013
# mount
/dev/da0s1a on / (ufs, local)
devfs on /dev (devfs, local, multilabel)
/dev/da0s1d on /tmp (ufs, local, soft-updates)
/dev/da0s1f on /usr (ufs, local, soft-updates)
/dev/da0s1e on /var (ufs, local, soft-updates)
/dev/da1s1d on /opt (ufs, local, soft-updates)
procfs on /proc (procfs, local)
fdescfs on /dev/fd (fdescfs)
# df -hi /usr
Filesystem Size Used Avail Capacity iused ifree %iused Mounted on
/dev/da0s1f 104G 88G 7.5G 92% 283k 13M 2% /usr
# umount /usr
# mount /usr
# du-hi /usr
Filesystem Size Used Avail Capacity iused ifree %iused Mounted on
/dev/da0s1f 104G 4.7G 91G 5% 278k 13M 2% /usr
# ^D
Script done on Fri Mar 15 19:09:26 2013
But, after a couple of hours in production again, after power-off +
reboot (for other reasons, had to replace the remote console card, the
iLO), an fsck indicates that it might still be losing file references
occasionally? Look at the unreferenced files with size ~ 11111686. This
is exactly how it looked before the unmount/remount, only there where
many many more.
# fsck /usr
** /dev/da0s1f (NO WRITE)
** Last Mounted on /usr
** Phase 1 - Check Blocks and Sizes
** Phase 2 - Check Pathnames
UNALLOCATED I=3157519 OWNER=pgsql MODE=100600
SIZE=0 MTIME=Mar 15 22:15 2013
FILE=/local/pgsql/data/base/16431/t79_3703656628
UNEXPECTED SOFT UPDATE INCONSISTENCY
REMOVE? no
UNALLOCATED I=7301569 OWNER=pgsql MODE=100600
SIZE=0 MTIME=Mar 15 22:15 2013
FILE=/local/pgsql/data/base/2969955511/t109_3703656671
UNEXPECTED SOFT UPDATE INCONSISTENCY
REMOVE? no
** Phase 3 - Check Connectivity
** Phase 4 - Check Reference Counts
UNREF FILE I=3156555 OWNER=pgsql MODE=100600
SIZE=11100363 MTIME=Mar 15 20:42 2013
CLEAR? no
UNREF FILE I=3156714 OWNER=pgsql MODE=100600
SIZE=11126220 MTIME=Mar 15 20:08 2013
CLEAR? no
UNREF FILE I=3157415 OWNER=pgsql MODE=100600
SIZE=11101546 MTIME=Mar 15 20:34 2013
CLEAR? no
UNREF FILE I=3157512 OWNER=pgsql MODE=100600
SIZE=11100870 MTIME=Mar 15 20:39 2013
CLEAR? no
UNREF FILE I=3157518 OWNER=pgsql MODE=100600
SIZE=11100194 MTIME=Mar 15 20:59 2013
CLEAR? no
UNREF FILE I=3157520 OWNER=pgsql MODE=100600
SIZE=11098673 MTIME=Mar 15 21:58 2013
CLEAR? no
UNREF FILE I=3157544 OWNER=pgsql MODE=100600
SIZE=11107123 MTIME=Mar 15 21:13 2013
CLEAR? no
UNREF FILE I=3157547 OWNER=pgsql MODE=100600
SIZE=11110672 MTIME=Mar 15 21:54 2013
CLEAR? no
UNREF FILE I=3157554 OWNER=pgsql MODE=100600
SIZE=11111686 MTIME=Mar 15 22:12 2013
CLEAR? no
LINK COUNT FILE I=3157590 OWNER=pgsql MODE=0
SIZE=0 MTIME=Mar 15 22:15 2013 COUNT 0 SHOULD BE -1
ADJUST? no
UNREF FILE I=3157596 OWNER=pgsql MODE=100600
SIZE=11107968 MTIME=Mar 15 20:48 2013
CLEAR? no
UNREF FILE I=3157607 OWNER=pgsql MODE=100600
SIZE=11093096 MTIME=Mar 15 21:23 2013
CLEAR? no
LINK COUNT FILE I=7301564 OWNER=pgsql MODE=0
SIZE=0 MTIME=Mar 15 22:15 2013 COUNT 0 SHOULD BE -2
ADJUST? no
UNREF FILE I=8485378 OWNER=pgsql MODE=100600
SIZE=0 MTIME=Mar 15 22:15 2013
RECONNECT? no
CLEAR? no
** Phase 5 - Check Cyl groups
SUMMARY INFORMATION BAD
SALVAGE? no
ALLOCATED FRAGS 3416608-3416735 MARKED FREE
BLK(S) MISSING IN BIT MAPS
SALVAGE? no
FREE BLK COUNT(S) WRONG IN SUPERBLK
SALVAGE? no
278680 files, 2516552 used, 52158314 free (72842 frags, 6510684 blocks,
0.1% fragmentation)
FreeBSD 9.1-RELEASE, amd64, GENERIC kernel.
Any ideas?
Best regards,
Palle
>
> ----- Original Message:
>
> Date: Wed, 13 Mar 2013 11:23:13 +0100 From: Palle Girgensohn
> <girgen@freebsd.org> To: freebsd-fs@freebsd.org Subject: leaking lots
> of unreferenced inodes (pg_xlog files?), maybe after moving tables
> and indexes to tablespace on different volume
>
> Hi!
>
> Running postgresql-9.2.2 on FreeBSD 9.1 amd64 using vanilla ufs file
> system.
>
> I have the postgresql base/ on the /usr disk, and a separate volume
> /opt where the default tablespace resides. This means that the amount
> of data on the /usr disk sould be stable. This is not the case, the
> disk usage grows linearly (it seems to leave many inodes
> unreferenced).
>
> The the discrepancy between df and du is now huge:
>
> # du -sxh /usr; df -h /usr 4,6G /usr Filesystem Size Used
> Avail Capacity Mounted on /dev/da0s1f 104G 88G 8.0G 92%
> /usr
>
> 4,6G vs 88GB, that must be more than a rounding error?
>
> Strange thing is I cannot find any open files among the missing.
>
> # lsof /usr| awk '{print $9}'|xargs ls -l > /dev/null
>
> returns no errors (a missing file would render an error with ls). If
> there where open files not referenced in any directory, they should
> be found.
>
> Next thing is fsck, and yes, there are plenty of unreferenced files.
>
> I ran fsck while system is running (i.e. read only) to get a grip
> oif the amount of lost inodes:
>
> fsck /usr | awk '{print $1}'|cut -f 2 -d=| perl -e '$i = 0; while
> (<>) { $i += $_;}; print $i / 1024 / 1024; print "\n";'
> 85223.3530330658
>
> ~85 GB gone, that's 80% of the disk, and it accounts fo all the
> missing space.
>
> MTIME for the inodes are pretty evenly spread over time since the
> machine was updated to FreeBSD 9.1, rebooted, and PostgreSQL was
> updated to 9.2. All was done at the same time, so I can't really tell
> who's to blaim, but this is the only server, out of a dozen that
> where updated to exactly the same versions, that has this problem.
> All other servers have their /usr disk usage stable (since all data
> resides on a separate tablespace).
>
> The unreferenced inodes are almost exclusively around 16 MB in size,
> so they most certainly all are postgresql pg_xlog files. This means
> all files are lost from the same portion of code in the database
> engine.
>
> How could it possibly be able to leave unreferenced inodes around
> like this at such a scale? Is the culprit a combination of postgresql
> and file system code? Both where updated.
>
> pg_xlog checkpoints seems to happen approximately every three
> minutes:
>
> Mar 13 00:39:08 dbserver postgres[5298]: [48-1] db=,user= LOG:
> checkpoint starting: time Mar 13 00:41:38 dbserver postgres[5298]:
> [49-1] db=,user= LOG: checkpoint complete: wrote 2542 buffers (0.3%);
> 0 transaction log file(s) added, 0 removed, 1 recycled; write=149.667
> s, sync=0.101 s, total=149.770 s; sync files=628, longest=0.021 s,
> average=0.000 s Mar 13 00:44:08 dbserver postgres[5298]: [50-1]
> db=,user= LOG: checkpoint starting: time Mar 13 00:46:38 dbserver
> postgres[5298]: [51-1] db=,user= LOG: checkpoint complete: wrote 3996
> buffers (0.4%); 0 transaction log file(s) added, 0 removed, 1
> recycled; write=149.438 s, sync=0.111 s, total=149.551 s; sync
> files=823, longest=0.006 s, average=0.000 s Mar 13 00:49:08 dbserver
> postgres[5298]: [52-1] db=,user= LOG: checkpoint starting: time Mar
> 13 00:51:38 dbserver postgres[5298]: [53-1] db=,user= LOG: checkpoint
> complete: wrote 13736 buffers (1.4%); 0 transaction log file(s)
> added, 0 removed, 2 recycled; write=149.958 s, sync=0.311 s,
> total=150.271 s; sync files=1335, longest=0.079 s, average=0.000 s
> Mar 13 00:54:08 dbserver postgres[5298]: [54-1] db=,user= LOG:
> checkpoint starting: time Mar 13 00:56:38 dbserver postgres[5298]:
> [55-1] db=,user= LOG: checkpoint complete: wrote 14638 buffers
> (1.5%); 0 transaction log file(s) added, 0 removed, 17 recycled;
> write=149.330 s, sync=0.271 s, total=149.603 s; sync files=1363,
> longest=0.017 s, average=0.000 s Mar 13 00:59:08 dbserver
> postgres[5298]: [56-1] db=,user= LOG: checkpoint starting: time Mar
> 13 01:01:38 dbserver postgres[5298]: [57-1] db=,user= LOG: checkpoint
> complete: wrote 8035 buffers (0.8%); 0 transaction log file(s) added,
> 0 removed, 21 recycled; write=149.285 s, sync=0.146 s, total=149.433
> s; sync files=1160, longest=0.003 s, average=0.000 s Mar 13 01:04:08
> dbserver postgres[5298]: [58-1] db=,user= LOG: checkpoint starting:
> time Mar 13 01:06:37 dbserver postgres[5298]: [59-1] db=,user= LOG:
> checkpoint complete: wrote 2156 buffers (0.2%); 0 transaction log
> file(s) added, 0 removed, 9 recycled; write=149.402 s, sync=0.057 s,
> total=149.461 s; sync files=610, longest=0.000 s, average=0.000 s Mar
> 13 01:09:08 dbserver postgres[5298]: [60-1] db=,user= LOG: checkpoint
> starting: time
>
>
> I'm pretty certain that unmounting the file system and running fsck
> will regain the lost space, but will it stop there?
>
> Stopping postgresql briefly did not help, I tried that. That would
> have helped if the files where open, but they're not. It seems to
> postgresql did the right thing, and FreeBSD failed to unreference the
> files.
>
> The server has about 30 databases and ~127 concurrent connections
> (not all beeing active simultaneously, though), so it is fair to say
> it is pretty active, but nothing extreme.
>
> Hardware is HP DL360, using their HT Smart Array P410i.
>
> Any ideas how to debug this? Or shall I just reboot, fsck, hope the
> problem will go away, and when it does, forget about it?
>
> Thanks, Palle -----BEGIN PGP SIGNATURE----- Version: GnuPG/MacGPG2
> v2.0.17 (Darwin) Comment: GPGTools - http://gpgtools.org Comment:
> Using GnuPG with Mozilla - http://enigmail.mozdev.org/
>
> iQEcBAEBAgAGBQJRQFORAAoJEIhV+7FrxBJDzVUIAJHU011JDxLxj8/xg05Gwhgq
> XK3xB+0N0NSUQ50yhcRKLINz/j/XfeS0ZxlH+MstaPA9y0r1JUXMxkb/uTUvGBiy
> jutk3eVe0cati9cVZbJkRU5FxEgmQ0fg0GOMl3RQAErkh5achj+klWvN7PnwGjTs
> O3L9RgckKuxTJffk52GAS05qY/TKR6f08kdX3I2cFtqw3tyTyrXU0JPdk2snuPhv
> H40xV46zgtWMFDvZLt61MryQ7/JotVQwU78scUB+zxrf8KKM9V0mM7pk0pIbG4Qw
> NJBpZJ5gjbl4x+dkQrtZdL65yq88hACYwo9D+83Ct4ig8tgcQ7ViNHWxJqknK7Q=
> =3ZZs -----END PGP SIGNATURE-----
> _______________________________________________
> freebsd-fs@freebsd.org mailing list
> http://lists.freebsd.org/mailman/listinfo/freebsd-fs To unsubscribe,
> send any mail to "freebsd-fs-unsubscribe@freebsd.org"
-----BEGIN PGP SIGNATURE-----
Version: GnuPG/MacGPG2 v2.0.17 (Darwin)
Comment: GPGTools - http://gpgtools.org
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/
iQEcBAEBAgAGBQJRQ5JDAAoJEIhV+7FrxBJDuK8H/3gvtaZyKqNxbrQ+JkgGooit
AVs5i38j6ZjKoYOPTNrqD5zsqk76NE5hUmJ2HAj/EkEt5CnPkR0trVN/s95NQu1S
IY+iOlng9ImKHVvIEWKRap0WTeUu7BT2M+e6szOkOOo93xqS7E0U7tfwgkFXgjI2
MUcy7QxFz/Yfjyu7HrYDvJMCmCEL2e5SDRQoPXO/Qs4CRnE16d85nJtFJXuM8EgQ
j8ZZmmphRt9yxxLg6tAlm3Tscf2QqXL8G4ABHSf32dJYuO11/7Glz+svh4m/gj7B
YnlXuqOq7ESBMhwLpQqA78JOWfZiiF8B8aTQVlxm3GtjPWknm4rkK1XljWl8Zi8=
=kIKS
-----END PGP SIGNATURE-----
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?51439243.5020604>