Differences

This shows you the differences between two versions of the page.

--- unix:lvm_recovery [2012/02/11 23:33]
robm [Finding the ext4 file-system]
+++ unix:lvm_recovery [2013/08/20 22:54] (current)
@@ Line 505: / Line 505: @@
 Success!
-**Update**: I ended up writing a Python script, [[https://github.com/meermanr/ext3_recovery|find_ext3.py]], to help me locate ''ext3'' superblocks, and automatically check their validity using ''dumpe2fs''.
+**Update**: I ended up writing a Python script, [[https://github.com/meermanr/ext3_recovery|find_ext3.py]], to help me locate ''ext3'' superblocks, and automatically check their validity using ''dumpe2fs''. This showed that the most common file-system origin is actually _before_ the start of the LVM logical volume:
+<code>
+root@skuld:/home/meermanr/projects/find_ext3# cut -d' ' -f9- store_vg-store_lv.find_ext3.log | sort | uniq
+ -c | sort -rn | head
+origin -134282240
+origin -134514176
+origin 8382976
+origin 8268288
+origin 8256000
+origin 8215040
+origin 8145408
+origin 8133120
+origin 8043008
+origin 8030720
+</code>
+From this I conclude that my original (working) installation was not actually using the Logical Volume! This may explain why updating Ubuntu to a version which has LVM support by default made my system unable to find the file-system.
+So from this point on I'll ignore the Logical Volumes in my disk image (''store_vg/store_lv''), and instead look for a file-system in the raw image.
 ====== Getting my data back ======
@@ Line 545: / Line 564: @@
 Error writing block 3226742528 (Invalid argument).  Ignore error? yes
+</code>
+Using my [[https://github.com/meermanr/ext3_recovery|find_ext3.py]] script I mapped out the location of all superblocks on my disk in the form of a log file as follows:
+<code>
+# meermanr@Ikari:/home/meermanr/projects/find_ext3 (master)
+# head vg_scratch-snap.log
+OK  /dev/vg_scratch/snap 1024 store #0 4096 kB 32768 bpg, origin 0
+BAD /dev/vg_scratch/snap 6358016 store #0 4096 kB 32768 bpg, origin 6356992
+BAD /dev/vg_scratch/snap 6403072 store #0 4096 kB 32768 bpg, origin 6402048
+BAD /dev/vg_scratch/snap 6444032 store #0 4096 kB 32768 bpg, origin 6443008
+BAD /dev/vg_scratch/snap 6456320 store #0 4096 kB 32768 bpg, origin 6455296
+BAD /dev/vg_scratch/snap 6525952 store #0 4096 kB 32768 bpg, origin 6524928
+BAD /dev/vg_scratch/snap 6562816 store #0 4096 kB 32768 bpg, origin 6561792
+BAD /dev/vg_scratch/snap 6640640 store #0 4096 kB 32768 bpg, origin 6639616
+BAD /dev/vg_scratch/snap 6652928 store #0 4096 kB 32768 bpg, origin 6651904
+BAD /dev/vg_scratch/snap 6722560 store #0 4096 kB 32768 bpg, origin 6721536
+</code>
+Obviously the "OK" superblock at origin 0 isn't actually valid, according to ''fsck''. I suspect I've reformatted this drive a number of times, and unfortunately used the same label (''store'') each time, which doesn't help. So let's take a statistical approach: tally how often each origin offset is mentioned, and investigate the most frequent:
+<code>
+# meermanr@Ikari:/home/meermanr/projects/find_ext3 (master)
+# cut -d' ' -f9- ./vg_scratch-snap.log | sort | uniq -c | sort -rn | head
+origin 231936
+origin 0
+origin 880602744320
+origin 8802304
+origin 8790016
+origin 8679424
+origin 8667136
+origin 8556544
+origin 8544256
+origin 8433664
+</code>
+As above, I mounted this on a loop back device and ran ''fsck'' on it. This got a lot further than previous attempts: more text scrolled past me, and it sat there for a while writing out a new journal. Ultimately it gave up with the same error as last time.
+On the advice of [[http://forums.gentoo.org/viewtopic-p-3778374.html#3778374|Gentoo forum post]] I ran
+<code>
+mke2fs -S /dev/loop0
+</code>
+followed by ''fsck''. That was last night. This morning it's still running, pinning one of my CPUs at 100%, consuming so much memory it has caused my system to nearly exhaust its swap file and nearly consume all of the snapshot volumes Copy-On-Write table!
+===== Lowering IO and CPU scheduling priority of fsck =====
+<code>
+# meermanr@Ikari:/home/meermanr/projects/find_ext3 (master)
+# ps fo pid,pmem,pcpu,cmd -t 13
+  PID %MEM %CPU CMD
+  0.0  0.0 -bash
+  0.0  0.0  \_ sudo su
+  0.0  0.0      \_ su
+  0.0  0.0          \_ bash
+  0.0  0.0              \_ fsck /dev/loop0 -y
+49.4 86.8                  \_ fsck.ext2 -y /dev/loop0
+</code>
+To keep my system usable I lowered the IO and CPU priority of ''fsck''. First change the IO scheduling class to "idle" (3) for the hungry process:
+<code>
+root@Ikari:~# ionice -c3 -p 20182
+</code>
+Then raise the "niceness" of the process. Higher values make processes nicer, which means they are more likely to "give way" to other processes. Really it just means the kernel will pre-empty nice processes more often:
+<code>
+root@Ikari:~# renice 10 20182
+(process ID) old priority 0, new priority 10
+</code>
+===== Adding more swap to my system =====
+<code>
+# meermanr@Ikari:/home/meermanr/projects/find_ext3 (master)
+# free -m
+             total       used       free     shared    buffers     cached
+Mem:          5969       5523        445          0        325        117
+-/+ buffers/cache:       5080        888
+Swap:         6234       3477       2757
+</code>
+I was concerned to see that 50% of my swap was in use. I don't know how long ''fsck'' will take, so adding more swap seems prudent. As luck would have it, I recently added an solid state drive (SSD) to my system, so I have an unused spinning disk which I'm pretty sure has a swap partition on it that isn't doing anything.
+<code>
+# meermanr@Ikari:/home/meermanr/projects/find_ext3 (master)
+# lsblk
+NAME                                  MAJ:MIN RM   SIZE RO TYPE MOUNTPOINT
+loop0                                   7:0    0 894.3G  0 loop
+sda                                     8:0    0  93.2G  0 disk
+├─sda1                                  8:1    0  87.2G  0 part /
+├─sda2                                  8:2    0     1K  0 part
+└─sda5                                  8:5    0     6G  0 part [SWAP]
+sdb                                     8:16   0 298.1G  0 disk
+├─sdb1                                  8:17   0 294.1G  0 part
+├─sdb2                                  8:18   0     1K  0 part
+└─sdb5                                  8:21   0     4G  0 part
+sr0                                    11:0    1  1024M  0 rom
+sr1                                    11:1    1  1024M  0 rom
+sde                                     8:64   0   1.8T  0 disk
+└─sde1                                  8:65   0   1.8T  0 part
+  ├─vg_scratch-home_zfs (dm-0)        252:0    0 186.3G  0 lvm
+  ├─vg_scratch-lv_scratch-real (dm-3) 252:3    0 894.3G  0 lvm
+  │ ├─vg_scratch-lv_scratch (dm-2)    252:2    0 894.3G  0 lvm
+  │ └─vg_scratch-snap (dm-1)          252:1    0 894.3G  0 lvm
+  ├─vg_scratch-snap-cow (dm-4)        252:4    0  18.6G  0 lvm
+  │ └─vg_scratch-snap (dm-1)          252:1    0 894.3G  0 lvm
+  └─vg_scratch-photorec (dm-5)        252:5    0 763.9G  0 lvm
+</code>
+It's probably ''/dev/sdb5'', let's check with ''file'':
+<code>
+# meermanr@Ikari:/home/meermanr/projects/find_ext3 (master)
+# file -Ls /dev/sdb5
+/dev/sdb5: no read permission
+# meermanr@Ikari:/home/meermanr/projects/find_ext3 (master)
+# sudo !!
+sudo file -Ls /dev/sdb5
+[sudo] password for meermanr:
+/dev/sdb5: Linux/i386 swap file (new style), version 1 (4K pages), size 1048063 pages, no label, UUID=d0bbff73-a09a-47f6-8387-e27268cdc9fc
+</code>
+Great! Let's enable it!
+<code>
+# meermanr@Ikari:/home/meermanr/projects/find_ext3 (master)
+# sudo swapon /dev/sdb5
+</code>
+And verify:
+<code>
+# meermanr@Ikari:/home/meermanr/projects/find_ext3 (master)
+# lsblk | grep SWAP
+└─sda5                                  8:5    0     6G  0 part [SWAP]
+└─sdb5                                  8:21   0     4G  0 part [SWAP]
+</code>
+<code>
+# meermanr@Ikari:/home/meermanr/projects/find_ext3 (master)
+# free -m
+             total       used       free     shared    buffers     cached
+Mem:          5969       5672        297          0        435        138
+-/+ buffers/cache:       5098        871
+Swap:        10234       3476       6758
+</code>
+===== Extending the snapshot volume =====
+<code>
+# lvdisplay /dev/vg_scratch/snap
+  --- Logical volume ---
+  LV Name                /dev/vg_scratch/snap
+  VG Name                vg_scratch
+  LV UUID                4EFJ8Y-bzWT-aif4-MlT9-4234-aS1d-qcipq0
+  LV Write Access        read/write
+  LV snapshot status     active destination for /dev/vg_scratch/lv_scratch
+  LV Status              available
+  # open                 1
+  LV Size                894.27 GiB
+  Current LE             228934
+  COW-table size         9.63 GiB
+  COW-table LE           2335
+  Allocated to snapshot  74.40%       <-- Do not want!
+  Snapshot chunk size    4.00 KiB
+  Segments               1
+  Allocation             inherit
+  Read ahead sectors     auto
+  - currently set to     256
+  Block device           252:1
+</code>
+As it happens, I had not allocated all of the volume group:
+<code>
+root@Ikari:~# vgs
+  VG         #PV #LV #SN Attr   VSize VFree
+  vg_scratch   1   4   1 wz--n- 1.73t    9.3g
+</code>
+So extending the snapshot is easy:
+<code>
+root@Ikari:~# lvextend /dev/vg_scratch/snap --extents +100%FREE
+</code>
+Verify:
+<code>
+# lvdisplay /dev/vg_scratch/snap
+  --- Logical volume ---
+  LV Name                /dev/vg_scratch/snap
+  VG Name                vg_scratch
+  LV UUID                4EFJ8Y-bzWT-aif4-MlT9-4234-aS1d-qcipq0
+  LV Write Access        read/write
+  LV snapshot status     active destination for /dev/vg_scratch/lv_scratch
+  LV Status              available
+  # open                 1
+  LV Size                894.27 GiB
+  Current LE             228934
+  COW-table size         18.63 GiB      <-- Has increased
+  COW-table LE           4769           <-- (Same thing, but measured in logical extents)
+  Allocated to snapshot  39.18%         <-- Much better!
+  Snapshot chunk size    4.00 KiB
+  Segments               1
+  Allocation             inherit
+  Read ahead sectors     auto
+  - currently set to     256
+  Block device           252:1
+</code>
+===== ... 2 weeks later =====
+It has been two weeks since I started ''fsck'', and it is still running. During this time I've not been able to use my desktop PC for gaming, and so I've decided to hit ^C and move it to another machine. Here are the forensics:
+Now:
+<code>
+# meermanr@Ikari:/home/meermanr (master *)
+# date
+Mon May 27 14:53:34 BST 2013
+</code>
+Size of block device:
+<code>
+root@Ikari:/home/meermanr/projects/find_ext3# python
+Python 2.7.3 (default, Aug  1 2012, 05:14:39)
+[GCC 4.6.3] on linux2
+Type "help", "copyright", "credits" or "license" for more information.
+>>> f = open("/dev/loop0")
+>>> f.seek(0, 2)
+>>> f.tell()
+960218560000
+>>> hex(f.tell())
+'0xdf917c7600'
+>>>
+</code>
+Offsets of ''fsck'' and ''python'':
+<code>
+Every 2.0s: lsof /dev/loop0                                                       Mon May 27 14:56:18 2013
+COMMAND     PID USER   FD   TYPE DEVICE     SIZE/OFF NODE NAME
+fsck.ext2 20182 root    4u   BLK    7,0 0x3f903ef000 5941 /dev/loop0
+python    23598 root    3r   BLK    7,0 0xdf917c7600 5941 /dev/loop0
+</code>
+That's approximately 28%. :-(
+<code>
+ STARTED %CPU %MEM   RSS CMD
+  May 13  0.0  0.0   364 su
+  May 13  0.0  0.0   528  \_ bash
+  May 13  0.0  0.0  1320      \_ watch lvdisplay /dev/vg_scratch/snap
+  May 13  0.0  0.0   364 su
+  May 13  0.0  0.0   536  \_ bash
+  May 13  0.0  0.0   464      \_ fsck /dev/loop0 -y
+  May 13 99.1 24.3 1488468          \_ fsck.ext2 -y /dev/loop0
+  May 14  0.0  0.0  1456 watch lsof /dev/loop0
+</code>
+So ''fsck'' has about 1.4GiB of resident memory (and 4696MiB of virtual memory according to top):
+<code>
+  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
+root      30  10 4696m 1.4g  784 R   94 24.3  19564:51 fsck.ext2 -y /dev/loop0
+</code>
+Total system memory:
+<code>
+# meermanr@Ikari:/home/meermanr (master *)
+# free -m
+             total       used       free     shared    buffers     cached
+Mem:          5969       5036        933          0         87        157
+-/+ buffers/cache:       4791       1178
+Swap:        10234       4764       5470
+</code>
+<code>
+Every 2.0s: lvdisplay /dev/vg_scratch/snap                                       Mon May 27 14:54:06 2013
+File descriptor 4 (pipe:[72594953]) leaked on lvdisplay invocation. Parent PID 23517: sh
+  --- Logical volume ---
+  LV Name                /dev/vg_scratch/snap
+  VG Name                vg_scratch
+  LV UUID                4EFJ8Y-bzWT-aif4-MlT9-4234-aS1d-qcipq0
+  LV Write Access        read/write
+  LV snapshot status     active destination for /dev/vg_scratch/lv_scratch
+  LV Status              available
+  # open                 1
+  LV Size                894.27 GiB
+  Current LE             228934
+  COW-table size         84.89 GiB
+  COW-table LE           21733
+  Allocated to snapshot  43.48%
+  Snapshot chunk size    4.00 KiB
+  Segments               2
+  Allocation             inherit
+  Read ahead sectors     auto
+  - currently set to     256
+  Block device           252:1
+</code>
+Output from ''fsck'' itself:
+<code>
+File ... (inode #9791282, mod time Thu Oct  5 01:40:26 2006)
+  has 11143 multiply-claimed block(s), shared with 5 file(s):
+	<filesystem metadata>
+	... (inode #9791794, mod time Thu Oct  5 01:40:26 2006)
+	... (inode #4115835, mod time Thu Aug 20 03:31:06 2009)
+	... (inode #4130006, mod time Mon Nov 29 16:38:10 2010)
+	... (inode #4784754, mod time Tue Jul 26 06:01:10 2005)
+Clone multiply-claimed blocks? yes
 </code>

RobMeerman.co.uk

User Tools

Site Tools

Differences

Page Tools