mksnap_ffs, snapshot issues, again
Kirk McKusick
mckusick at beastie.mckusick.com
Sat Aug 23 01:52:40 PDT 2003
Robert Watson forwarded your posting to me as I am not as current
on current as I should be.
---------- Forwarded message ----------
> Date: Mon, 18 Aug 2003 22:38:47 +0200
> From: "[iso-8859-2] Branko F. Graènar" <bfg at noviforum.si>
> To: freebsd-current at freebsd.org
> Subject: mksnap_ffs, snapshot issues, again
>
> I have 900G array on a promise sx6000 controller
>
> This is freshly formatted filesystem (newfs -L export -O 2 -U -g 48000 -i 2048 -m 0 -o space /dev/pst0s2d)
>
> # df -i /export
> /dev/pst0s2d 778742004 216194 778525810 0% 2 445159292 0% /export
>
> # mount | grep export
> /dev/pst0s2d on /export (ufs, local, soft-updates)
>
> let's try to create a snapshot of empty filesystem
>
> # cd /export
> # mksnap_ffs /export aaa.snap
>
> ... after 30 minutes ... snapshot was not created (!!! On a empty
> filesystem !!!)... Ok, long snapshot creation would be fine if it
> would not hang all processes, which would like to do something on
> /export (ls /export for example.). Filesystem cannot be unmounted.
> mksnap_ffs process cannot be killed. Reboot and foreground fsck
> helps.
>
> This is 5.1-RELEASE (without patches, with custom kernel -> just picked up generic kernel and removed uneeded stuff.)....
>
> Any ideas, why is this happening? As i mentioned before, this prevents background fsck to make his job done (machine hangs.)
>
>
> I would really like to solve this issue....
>
> Brane
------------ Discussion -----------------
Paul Saab kindly arranged a machine (tank.freebsd.org) with a 2Tb
disk array on it for me to test. I enclose a copy of the `sysctl kern'
output at the end of this message. I first ran my own test which
involved creating a default configuration filesystem, taking a
snapshot, and removing the snapshot. The scripted result is below.
It shows that it takes 48 minutes to create the snapshot and 15
minutes to remove it. But importantly, it shows that the filesystem
is only locked down and inaccessible for 0.042 seconds of that 48
minutes. The problem is that the 77,000 indirect blocks needed by
the snapshot do not fit in the 300 kernel buffers allotted to it.
So, every indirect block needs to be read and written approximately
three times. Just to be sure that there was not something weird about
your configuration, I also ran the same set of tests using your
newfs parameters. Other than creating more cylinder groups the
result (e.g., running time) was about the same.
But, to get to the problem that you are having with accessing your
filesystem. The problem is that although the filesystem is only
locked briefly, the snapshot file is locked for the entire 48 minutes.
Thus, if you touch the snapshot file (by for example doing a "stat"
on it), then the process doing the stat will hang for 48 minutes.
The next process to try and touch the snapshot will lock /export
while it waits for the lock on the snapshot to clear. And at that
point you are hosed for 48 minutes on all access to /export :-(
So, I think that the best solution for you would be to try creating
a hidden directory for the snapshot file, e.g., create a /export/.snap
directory mode 700 owned by root, then create the snapshot as say
/export/.snap/snap1. This way, it will be out of the way of all
snoopy programs except those walking the filetree as root.
Kirk McKusick
------------ Results of my test -----------------
Script started on Fri Aug 22 17:18:34 2003
tank# newfs /dev/twed0
/dev/twed0: 2097152.0MB (4294967292 sectors) block size 16384, fragment size 2048
using 11413 cylinder groups of 183.77MB, 11761 blks, 23552 inodes.
super-block backups (for fsck -b #) at:
160, 376512, 752864, 1129216, 1505568, 1881920, 2258272, 2634624, 3010976,
3387328, 3763680, 4140032, 4516384, 4892736, 5269088, 5645440, 6021792,
6398144, 6774496, 7150848, 7527200, 7903552, 8279904, 8656256, 9032608,
9408960, 9785312, 10161664, 10538016, 10914368, 11290720, 11667072, 12043424,
12419776, 12796128, 13172480, 13548832, 13925184, 14301536, 14677888,
15054240, 15430592, 15806944, 16183296, 16559648, 16936000, 17312352,
17688704, 18065056, 18441408, 18817760, 19194112, 19570464, 19946816,
20323168, 20699520, 21075872, 21452224, 21828576, 22204928, 22581280,
< etc, etc, etc >
4283638624, 4284014976, 4284391328, 4284767680, 4285144032, 4285520384,
4285896736, 4286273088, 4286649440, 4287025792, 4287402144, 4287778496,
4288154848, 4288531200, 4288907552, 4289283904, 4289660256, 4290036608,
4290412960, 4290789312, 4291165664, 4291542016, 4291918368, 4292294720,
4292671072, 4293047424, 4293423776, 4293800128, 4294176480, 4294552832,
4294929184
tank# dumpfs /dev/twed0 | head -22
magic 19540119 (UFS2) time Sat Aug 23 01:18:55 2003
superblock location 65536 id [ 3f47236f d612c37d ]
ncg 11413 size 1073741823 blocks 1039959213
bsize 16384 shift 14 mask 0xffffc000
fsize 2048 shift 11 mask 0xfffff800
frag 8 shift 3 fsbtodb 2
minfree 8% optim time symlinklen 120
maxbsize 16384 maxbpg 2048 maxcontig 8 contigsumsize 8
nbfree 129994899 ndir 1 nifree 268798973 nffree 20
bpg 11761 fpg 94088 ipg 23552
nindir 2048 inopb 64 maxfilesize 140806241583103
sbsize 2048 cgsize 16384 csaddr 3000 cssize 184320
sblkno 40 cblkno 48 iblkno 56 dblkno 3000
cgrotor 0 fmod 0 ronly 0 clean 1
flags none
fsmnt
volname swuid 0
cs[].cs_(nbfree,ndir,nifree,nffree):
(11373,1,23549,13) (11391,0,23552,0) (11391,0,23552,0) (11391,0,23552,0)
(11391,0,23552,0) (11391,0,23552,0) (11391,0,23552,0) (11391,0,23552,0)
(11391,0,23552,0) (11391,0,23552,0) (11391,0,23552,0) (11391,0,23552,0)
tank# ^ew^we
tunefs -n enable /dev/twed0
tunefs: soft updates set
tank# mount /dev/twed0 /mnt
tank# cd /mnt
tank# df -i /mnt
Filesystem 1K-blocks Used Avail Capacity iused ifree %iused Mounted on
/dev/twed0 2079918426 2 1913524950 0% 1 268798973 0% /mnt
tank# df -i -g /mnt
Filesystem 1G-blocks Used Avail Capacity iused ifree %iused Mounted on
/dev/twed0 1983 0 1824 0% 1 268798973 0% /mnt
tank# sysctl -w debug.collectsnapstats=1
debug.collectsnapstats: 0 -> 1
tank# mount -u -o snapshot snap1 /mnt
0.000u 51.055s 47:57.80 1.7% 522+253k 191899+286461io 0pf+0w
tank# ls -lis /mnt/snap1
3 1232048 -r-------- 1 root wheel 2199023346984 Aug 22 17:06 snap1
tank % df /mnt
Filesystem 1K-blocks Used Avail Capacity Mounted on
/dev/twed0 2079918426 1232050 1912292902 0% /mnt
tank# rm -f snap1
0.000u 8.084s 14:39.67 0.9% 506+275k 65567+65536io 0pf+0w
tank# egrep suspended /var/log/messages | tail -1
Aug 22 18:04:02 tank kernel: /mnt: suspended 0.042 sec, redo 0 of 11413
tank# exit
Script done on Fri Aug 22 19:21:00 2003
------------ Results of your test -----------------
Script started on Fri Aug 22 23:52:19 2003
tank# newfs -L export -O 2 -U -g 48000 -i 2048 -m 0 -o space /dev/twed0
/dev/twed0: 2097152.0MB (4294967292 sectors) block size 16384, fragment size 2048
using 17642 cylinder groups of 118.88MB, 7608 blks, 60864 inodes.
with soft updates
super-block backups (for fsck -b #) at:
160, 243616, 487072, 730528, 973984, 1217440, 1460896, 1704352, 1947808,
2191264, 2434720, 2678176, 2921632, 3165088, 3408544, 3652000, 3895456,
4138912, 4382368, 4625824, 4869280, 5112736, 5356192, 5599648, 5843104,
6086560, 6330016, 6573472, 6816928, 7060384, 7303840, 7547296, 7790752,
8034208, 8277664, 8521120, 8764576, 9008032, 9251488, 9494944, 9738400,
9981856, 10225312, 10468768, 10712224, 10955680, 11199136, 11442592, 11686048,
11929504, 12172960, 12416416, 12659872, 12903328, 13146784, 13390240,
13633696, 13877152, 14120608, 14364064, 14607520, 14850976, 15094432,
< etc, etc, etc >
4287016864, 4287260320, 4287503776, 4287747232, 4287990688, 4288234144,
4288477600, 4288721056, 4288964512, 4289207968, 4289451424, 4289694880,
4289938336, 4290181792, 4290425248, 4290668704, 4290912160, 4291155616,
4291399072, 4291642528, 4291885984, 4292129440, 4292372896, 4292616352,
4292859808, 4293103264, 4293346720, 4293590176, 4293833632, 4294077088,
4294320544, 4294564000, 4294807456
tank# dumpfs /dev/twed0 | head -22
magic 19540119 (UFS2) time Fri Aug 22 23:52:39 2003
superblock location 65536 id [ 3f470f37 1d9cb87a ]
ncg 17642 size 1073741823 blocks 939239037
bsize 16384 shift 14 mask 0xffffc000
fsize 2048 shift 11 mask 0xfffff800
frag 8 shift 3 fsbtodb 2
minfree 0% optim space symlinklen 120
maxbsize 16384 maxbpg 2048 maxcontig 8 contigsumsize 8
nbfree 117404877 ndir 1 nifree 1073762685 nffree 20
bpg 7608 fpg 60864 ipg 60864
nindir 2048 inopb 64 maxfilesize 140806241583103
sbsize 2048 cgsize 16384 csaddr 7664 cssize 282624
sblkno 40 cblkno 48 iblkno 56 dblkno 7664
cgrotor 0 fmod 0 ronly 0 clean 1
flags soft-updates
fsmnt
volname export swuid 0
cs[].cs_(nbfree,ndir,nifree,nffree):
(6631,1,60861,13) (6655,0,60864,0) (6655,0,60864,0) (6655,0,60864,0)
(6655,0,60864,0) (6655,0,60864,0) (6655,0,60864,0) (6655,0,60864,0)
(6655,0,60864,0) (6655,0,60864,0) (6655,0,60864,0) (6655,0,60864,0)
tank# mount /dev/twed0 /mnt
tank# cd /mnt
tank# df -i /mnt
Filesystem 1K-blocks Used Avail Capacity iused ifree %iused Mounted on
/dev/twed0 1878478074 2 1878478072 0% 1 1073762685 0% /mnt
tank# df -i -g /mnt
Filesystem 1G-blocks Used Avail Capacity iused ifree %iused Mounted on
/dev/twed0 1791 0 1791 0% 1 1073762685 0% /mnt
tank# sysctl debug.collectsnapstats
debug.collectsnapstats: 1
tank# set time
tank# mount -u -o snapshot /mnt/snap1 /mnt
load: 0.00 cmd: mount 3908 [biord] 0.00u 49.03s 0% 360k
load: 0.07 cmd: mount 3908 [physrd] 0.00u 49.30s 0% 360k
0.000u 57.064s 47:55.13 1.9% 526+255k 222815+300336io 0pf+0w
tank# ls -lis /mnt/snap1
3 1331856 -r-------- 1 root wheel 2199023396864 Aug 23 00:43 /mnt/snap1
tank# df /mnt
Filesystem 1K-blocks Used Avail Capacity Mounted on
/dev/twed0 1878478074 1331858 1877146216 0% /mnt
tank# rm -f snap1
0.000u 8.180s 10:25.82 1.3% 505+240k 65567+65536io 0pf+0w
tank# egrep suspended /var/log/messages | tail -1
Aug 23 00:15:30 tank kernel: /mnt: suspended 0.027 sec, redo 0 of 17642
tank# exit
Script done on Sat Aug 23 00:54:41 2003
------------ sysctl kern output -----------------
kern.ostype: FreeBSD
kern.osrelease: 5.1-CURRENT
kern.osrevision: 199506
kern.version: FreeBSD 5.1-CURRENT #0: Thu Aug 21 02:11:29 PDT 2003
ps at tank.freebsd.org:/usr/src/sys/i386/compile/TANK
kern.maxvnodes: 70264
kern.maxproc: 6164
kern.maxfiles: 12328
kern.argmax: 65536
kern.securelevel: -1
kern.hostname: tank.freebsd.org
kern.hostid: 0
kern.clockrate: { hz = 100, tick = 10000, profhz = 1024, stathz = 128 }
kern.posix1version: 200112
kern.ngroups: 16
kern.job_control: 1
kern.saved_ids: 0
kern.boottime: { sec = 1061550694, usec = 491116 } Fri Aug 22 04:11:34 2003
kern.domainname: freebsd
kern.osreldate: 501105
kern.bootfile: /boot/kernel/kernel
kern.maxfilesperproc: 11095
kern.maxprocperuid: 5547
kern.ipc.maxsockbuf: 262144
kern.ipc.sockbuf_waste_factor: 8
kern.ipc.somaxconn: 128
kern.ipc.max_linkhdr: 16
kern.ipc.max_protohdr: 40
kern.ipc.max_hdr: 56
kern.ipc.max_datalen: 152
kern.ipc.nmbclusters: 25600
kern.ipc.nmbufs: 51200
kern.ipc.nmbcnt: 32256
kern.ipc.nsfbufs: 6656
kern.ipc.mbuf_wait: 64
kern.ipc.mbuf_hiwm: 512
kern.ipc.mbuf_lowm: 128
kern.ipc.clust_hiwm: 128
kern.ipc.clust_lowm: 16
kern.ipc.maxpipekva: 10485760
kern.ipc.maxpipekvawired: 5242880
kern.ipc.pipes: 2
kern.ipc.bigpipes: 0
kern.ipc.pipekva: 32768
kern.ipc.pipekvawired: 0
kern.ipc.msgmax: 16384
kern.ipc.msgmni: 40
kern.ipc.msgmnb: 2048
kern.ipc.msgtql: 40
kern.ipc.msgssz: 8
kern.ipc.msgseg: 2048
kern.ipc.semmap: 30
kern.ipc.semmni: 10
kern.ipc.semmns: 60
kern.ipc.semmnu: 30
kern.ipc.semmsl: 60
kern.ipc.semopm: 100
kern.ipc.semume: 10
kern.ipc.semusz: 92
kern.ipc.semvmx: 32767
kern.ipc.semaem: 16384
kern.ipc.shmmax: 33554432
kern.ipc.shmmin: 1
kern.ipc.shmmni: 192
kern.ipc.shmseg: 128
kern.ipc.shmall: 8192
kern.ipc.shm_use_phys: 0
kern.ipc.numopensockets: 23
kern.ipc.maxsockets: 25600
kern.dummy: 0
kern.ps_strings: 3217031152
kern.usrstack: 3217031168
kern.logsigexit: 1
kern.iov_max: 1024
kern.cam.scsi_delay: 15000
kern.cam.cd.changer.min_busy_seconds: 5
kern.cam.cd.changer.max_busy_seconds: 15
kern.cam.da.retry_count: 4
kern.cam.da.default_timeout: 60
kern.random.sys.seeded: 1
kern.random.sys.burst: 20
kern.random.sys.harvest.ethernet: 1
kern.random.sys.harvest.point_to_point: 1
kern.random.sys.harvest.interrupt: 1
kern.random.sys.harvest.swi: 0
kern.random.yarrow.gengateinterval: 10
kern.random.yarrow.bins: 10
kern.random.yarrow.fastthresh: 192
kern.random.yarrow.slowthresh: 256
kern.random.yarrow.slowoverthresh: 2
kern.disks: twed0 ad2 ad0
kern.geom.debugflags: 0
kern.geom.collectstats: 1
kern.elf32.fallback_brand: -1
kern.init_path: /sbin/init:/sbin/oinit:/sbin/init.bak:/stand/sysinstall
kern.acct_suspend: 2
kern.acct_resume: 4
kern.acct_chkfreq: 15
kern.cp_time: 6158 0 148996 17012 17783789
kern.openfiles: 69
kern.kq_calloutmax: 4096
kern.stackprot: 7
kern.ps_arg_cache_limit: 256
kern.ps_argsopen: 1
kern.lastpid: 3850
kern.randompid: 0
kern.ktrace.genio_size: 4096
kern.ktrace.request_pool: 100
kern.module_path: /boot/kernel;/boot/modules
kern.malloc:
Type InUse MemUse HighUse Requests Size(s)
twe commands 255 16K 32K 266 64,512,8192,16384
ISOFS mount 1 256K 256K 1
atkbddev 2 1K 1K 2 32
isadev 21 2K 2K 21 64
GEOM 116 12K 83K 6174 16,32,64,128,256,512,1024,65536
nexusdev 3 1K 1K 3 16
memdesc 1 4K 4K 1 4096
VM pgdata 2 65K 65K 2 64,65536
pfs_fileno 1 32K 32K 1 32768
pfs_nodes 20 3K 3K 20 128
UFS mount 26 379K 711K 41 64,256,2048,4096,8192
UFS ihash 1 256K 256K 1
UFS dirhash 69 13K 13K 69 16,32,64,128,256,512
dirrem 0 0K 1K 1011 32
mkdir 0 0K 1K 2 32
diradd 0 0K 1K 1045 32
freefile 0 0K 1K 175 32
freeblks 0 0K 5K 161 256
freefrag 0 0K 1K 40 32
allocindir 0 0K 329K 154001 64
indirdep 0 0K 52K 22901 32,16384
allocdirect 0 0K 3K 313 128
bmsafemap 0 0K 53K 149301 32
newblk 1 1K 1K 154315 64,256
inodedep 1 256K 265K 1369 128,256
pagedep 1 32K 33K 227 64,32768
p1003.1b 1 1K 1K 1 16
NFS daemon 1 1K 1K 1 256
NFS hash 1 256K 256K 1
NFS req 0 0K 1K 2240 64
syncache 1 8K 8K 1 8192
tseg_qent 0 0K 1K 2 32
in_multi 2 1K 1K 2 32
routetbl 38 6K 6K 96 16,32,64,128,256
lo 1 1K 1K 1 512
clone 1 4K 4K 1 4096
ether_multi 7 1K 1K 7 16,32,64
ifaddr 21 6K 6K 21 32,256,512,2048
BPF 3 1K 1K 3 128
mount 19 7K 7K 26 16,32,128,512
MSDOSFS mount 1 128K 128K 1
vnodes 25 6K 6K 153 16,32,64,128,256
cluster_save buffer 0 0K 1K 1 64
vfscache 1 512K 512K 1
BIO buffer 2 4K 185K 100 1024,2048
pcb 21 5K 5K 1730 16,32,64,2048
soname 5 1K 1K 594269 16,32,128
ptys 2 1K 1K 2 512
ttys 1110 143K 156K 2790 128,512
shm 1 16K 16K 1 16384
sem 4 7K 7K 4 1024,4096
msg 4 25K 25K 4 512,4096,16384
ioctlops 0 0K 1K 331 512,1024
DEVFS 107 17K 18K 217 16,32,128,4096
ATA generic 4 2K 2K 4 16,512
MD sectors 4 16K 16K 80 4096
taskqueue 3 1K 1K 3 128
MD disk 8 2K 2K 160 16,256
acpidev 55 1K 1K 55 16
sbuf 0 0K 33K 2205 16,32,64,128,256,512,1024,2048,4096,8192,16384
rman 115 8K 8K 481 64
acpisem 17 3K 3K 17 64,128
acpitask 0 0K 1K 2 16,32
mbufmgr 102 135K 135K 102 32,64,256,8192,16384
acpica 965 53K 54K 10560 16,32,64,128,256,512,1024,2048
kobj 97 388K 388K 97 4096
eventhandler 31 2K 2K 31 32,128
devstat 12 25K 25K 12 16,4096
bus 609 42K 133K 4434 16,32,64,128,256,512,1024,2048,4096,16384,32768
SWAP 2 549K 549K 2 64
sysctltmp 0 0K 2K 21688 16,32,64,128,256,512,2048
sysctloid 125 4K 4K 125 16,32,64
sysctl 0 0K 1K 973 16,32,64
uidinfo 6 2K 2K 143 32,1024
cred 26 4K 5K 9207 128
subproc 85 292K 328K 4251 256,4096
proc 2 8K 8K 2 4096
session 20 3K 3K 409 128
pgrp 24 3K 4K 698 128
mtx_pool 1 8K 8K 1 8192
module 147 10K 10K 149 64,128
temp 7 117K 117K 7384 16,32,64,128,256,512,1024,2048,4096,8192,32768
devbuf 142 855K 905K 131522 16,32,64,128,256,512,1024,2048,4096,16384
lockf 9 1K 1K 877 32,64
linker 33 93K 98K 103 16,32,256,1024,2048,4096,16384,65536
AR driver 1 1K 3K 5 64,256,2048
KTRACE 100 13K 13K 100 128
ithread 41 4K 4K 41 64,128
zombie 0 0K 1K 3779 128
proc-args 25 2K 2K 17589 16,32,64,128,256
kqueue 6 6K 10K 193053 256,1024
kenv 109 6K 6K 110 16,32,64,2048
sigio 1 1K 1K 1 32
file desc 71 18K 26K 3960 256,2048
dev_t 147 37K 37K 147 256
AD driver 2 1K 2K 21823 64,512
ATA DMA 2 1K 1K 2 64
kern.ident: TANK
kern.maxusers: 384
kern.fallback_elf_brand: -1
kern.kstack_pages: 2
kern.uarea_pages: 1
kern.sync_on_panic: 1
kern.shutdown.poweroff_delay: 5000
kern.shutdown.kproc_shutdown_wait: 60
kern.sugid_coredump: 0
kern.coredump: 1
kern.corefile: %N.core
kern.fscale: 2048
kern.timecounter.nbinuptime: 35881781
kern.timecounter.nnanouptime: 3
kern.timecounter.nmicrouptime: 3883
kern.timecounter.nbintime: 245389
kern.timecounter.nnanotime: 34
kern.timecounter.nmicrotime: 245355
kern.timecounter.ngetbinuptime: 0
kern.timecounter.ngetnanouptime: 3087
kern.timecounter.ngetmicrouptime: 2181958
kern.timecounter.ngetbintime: 0
kern.timecounter.ngetnanotime: 0
kern.timecounter.ngetmicrotime: 7012364
kern.timecounter.nsetclock: 3
kern.timecounter.hardware: ACPI-fast
kern.timecounter.choice: TSC(-100) ACPI-fast(1000) i8254(0) dummy(-1000000)
kern.timecounter.tick: 1
kern.timecounter.smp_tsc: 0
kern.threads.debug: 0
kern.threads.max_threads_per_proc: 150
kern.threads.max_groups_per_proc: 50
kern.threads.max_threads_hits: 0
kern.threads.virtual_cpu: 4
kern.quantum: 100000
kern.ccpu: 1948
kern.devstat.numdevs: 3
kern.devstat.generation: 1738
kern.devstat.version: 6
kern.kobj_methodcount: 58
kern.log_wakeups_per_second: 5
kern.log_console_output: 1
kern.msgbuf:
kern.msgbuf_clear: 0
kern.smp.active: 1
kern.smp.disabled: 0
kern.smp.cpus: 4
kern.smp.forward_signal_enabled: 1
kern.smp.forward_roundrobin_enabled: 1
kern.nselcoll: 0
kern.drainwait: 300
kern.tty_nin: 3131
kern.tty_nout: 368061
kern.console: ttyd0,/ttyd0,consolectl,
kern.consmute: 0
kern.consmsgbuf_size: 8192
kern.constty_wakeups_per_second: 5
kern.rootdev: ad0s1a
kern.filedelay: 30
kern.dirdelay: 29
kern.metadelay: 28
kern.minvnodes: 17566
kern.chroot_allow_open_directories: 1
More information about the freebsd-current
mailing list