27 sept 2007

Haz copias de seguridad: La Ley de Murphy está a la vuelta de la esquina

Una odisea. No hay frase más corta capaz de definir lo que me ha pasado estos días.

Empecemos por el principio, trataré de ser conciso. Hace un mes pensé que necesitaba un disco duro externo para las copias de seguridad de mis datos personales (en linux la carpeta /home), que van aumentando según van pasando los años, previendo que podría tener algún problema con el disco duro SATA de 250 Gigas con 3 meses de antigüedad y que tenía encendido día y noche aunque sin estresarlo mucho.



Me compré una caja y metí en ella un disco IDE de 80 Gigas, en el que creé un par de volúmenes truecrypt. Luego me di cuenta de que no los había formateado con un formato más adecuado que FAT (ext2 por ejemplo), así que volví a formatear el disco duro externo, etc, y en estas estaba cuando el disco duro principal empezó a fallar; se apagaba sólo, dejando de girar, durante unos segundos al principio.
Me confié, cada vez tardaba más tiempo en recuperarse de estos "apagones" aleatorios, en los que el motor dejaba de girar, aunque el ordenador seguía como si nada hasta que se acumulaba la cola de lectura/escritura de disco y entonces se quedaba parado todo a la espera del disco.
Finalmente en una ocasión el ordenador se bloqueó de tanto esperar.

Y ya no arrancó, el sistema de archivos JFS se autochequeaba pero daba error 11. Y una sensación muy desagradable de impotencia y frustración se empezó a adueñar de mí. ¡Como es posible que se me haya corrompido la partición con todos mis datos justo cuando iba a hacer la copia de seguridad! La ley de Murphy en su máxima expresión.

Entonces me compré otro disco duro similar, con la esperanza de tratar de arreglarlo, ya que una de las ventajas de linux es que al ser todo abierto, aunque algo no funcione, con paciencia, ayuda de San Google y los conocimientos necesarios podría salvar los datos.

Busqué y encontré que jfsutils podría ayudarme. Hice un jfs_fsck y ¡me dió un Segmentation Fault*!
Empecé a maldecir entre dientes a los ingenieros de JFS, ¿cómo es que no podía corregir los errores, aunque fuera por un fallo hardware?

No me desesperé, y volví a consultar al santo. Y encontré que a alguien le había pasado lo mismo, así que seguí sus pasos (mis conocimientos de programación en C son muy, muy limitados), y seguí investigando mientras realizaba las pruebas; me dí de alta en su lista de correos en la página de JFS y les envié el correo siguiente, en los que indico información para depurar el Fallo de Segmentación (SIGSEGV)*, esperando que lo arreglaran para poder cargar el sistema. Finalmente vi que un tal Karl lo había resuelto con la opción --omit_journal_replay option y así lo arreglé:


Hello;

I build the latest version of jsfutils (1.1.12), and the problem
persists. I tried:

david@pcimanol:/sbin$ sudo jfs_debugfs /dev/sdb6
jfs_debugfs version 1.1.12, 24-Aug-2007

Aggregate Block Size: 4096

> su p
[1] s_magic: 'JFS1' [15] s_ait2.addr1: 0x00
[2] s_version: 1 [16] s_ait2.addr2: 0x00001cfe
[3] s_size: 0x000000001cdf39f0 s_ait2.address: 7422
[4] s_bsize: 4096 [17] s_logdev: 0x00000806
[5] s_l2bsize: 12 [18] s_logserial: 0x00000003
[6] s_l2bfactor: 3 [19] s_logpxd.len: 8192
[7] s_pbsize: 512 [20] s_logpxd.addr1: 0x00
[8] s_l2pbsize: 9 [21] s_logpxd.addr2: 0x039beea9
[9] pad: Not Displayed s_logpxd.address: 60550825
[10] s_agsize: 0x00080000 [22] s_fsckpxd.len: 1899
[11] s_flag: 0x10200900 [23] s_fsckpxd.addr1: 0x00
JFS_LINUX [24] s_fsckpxd.addr2: 0x039be73e
JFS_COMMIT JFS_GROUPCOMMIT s_fsckpxd.address: 60548926
JFS_INLINELOG [25] s_time.tv_sec: 0x4671cfc5
[26] s_time.tv_nsec: 0x00000000
[27] s_fpack: ''
[12] s_state: 0x00000001
FM_MOUNT
[13] s_compress: 0
[14] s_ait2.len: 4

display_super: [m]odify or e[x]it: x
> su s
[1] s_magic: 'JFS1' [15] s_ait2.addr1: 0x00
[2] s_version: 1 [16] s_ait2.addr2: 0x00001cfe
[3] s_size: 0x000000001cdf39f0 s_ait2.address: 7422
[4] s_bsize: 4096 [17] s_logdev: 0x00000806
[5] s_l2bsize: 12 [18] s_logserial: 0x00000002
[6] s_l2bfactor: 3 [19] s_logpxd.len: 8192
[7] s_pbsize: 512 [20] s_logpxd.addr1: 0x00
[8] s_l2pbsize: 9 [21] s_logpxd.addr2: 0x039beea9
[9] pad: Not Displayed s_logpxd.address: 60550825
[10] s_agsize: 0x00080000 [22] s_fsckpxd.len: 1899
[11] s_flag: 0x10200900 [23] s_fsckpxd.addr1: 0x00
JFS_LINUX [24] s_fsckpxd.addr2: 0x039be73e
JFS_COMMIT JFS_GROUPCOMMIT s_fsckpxd.address: 60548926
JFS_INLINELOG [25] s_time.tv_sec: 0x4671cfc5
[26] s_time.tv_nsec: 0x00000000
[27] s_fpack: ''
[12] s_state: 0x00000000
FM_CLEAN
[13] s_compress: 0
[14] s_ait2.len: 4

display_super: [m]odify or e[x]it: x
> logs
[1] magic: 0x0
[2] version: 0
[3] serial: 0
[4] log size (# blocks): 0 (at 4096 bytes/log block)
[5] agg block size: 0 (bytes)
[6] log2(agg blk size): 0
[7] flag: 0x00000000
[8] state: 0x00000000 LOGMOUNT
[9] end: 0x0 (d 0)
[10] uuid: 00000000-0000-0000-0000
-000000000000
[11] label: ' '
active file systems:
None active.

display_logsuper: [m]odify or e[x]it:

----- gdb -------

(gdb) file /home/david/tmp/jfsutils-1.1.12/fsck/jfs_fsck
Reading symbols from /home/david/tmp/jfsutils-1.1.12/fsck/jfs_fsck...done.
(gdb) run /dev/sdb6
Starting program: /home/david/tmp/jfsutils-1.1.12/fsck/jfs_fsck /dev/sdb6
/home/david/tmp/jfsutils-1.1.12/fsck/jfs_fsck version 1.1.12, 24-Aug-2007
processing started: 9/26/2007 23.27.7
Using default parameter: -p
The current device is: /dev/sdb6
Block size in bytes: 4096
Filesystem size in blocks: 60559017
**Phase 0 - Replay Journal Log

Program received signal SIGSEGV, Segmentation fault.
0xb7e5634c in memcpy () from /lib/tls/i686/cmov/libc.so.6
(gdb) where
#0 0xb7e5634c in memcpy () from /lib/tls/i686/cmov/libc.so.6
#1 0x08074ea5 in updatePage (ld=0xbffa95d0, logaddr=5812268) at log_work.c:2793
#2 0x08075fbd in doAfter (ld=0xbffa95d0, logaddr=5812268) at log_work.c:633
#3 0x08073098 in jfs_logredo (pathname=0xbffaa8f6 "/dev/sdb6",
fp=0x814e520, use_2nd_aggSuper=0) at logredo.c:691
#4 0x0806c59d in phase0_processing () at xchkdsk.c:1887
#5 0x0806ed67 in main (argc=Cannot access memory at address 0x3fff7520
) at xchkdsk.c:333

----- gdb --------

Another thing:

david@pcimanol:/$ sudo strace jfs_fsck /dev/sdb6
Password:
execve("/sbin/jfs_fsck", ["jfs_fsck", "/dev/sdb6"], [/* 37 vars */]) = 0
brk(0) = 0x813e000
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
mmap2(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7
fb5000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=51404, ...}) = 0
mmap2(NULL, 51404, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb7fa8000

{líneas eliminadas}

6
_llseek(3, 161256648704, [161256648704], SEEK_SET) = 0
write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0
\0\0\2\0\32\0\0\1\0\0\1\0\0"...,
4096) = 4
096
_llseek(3, 248021987328, [248021987328], SEEK_SET) = 0
read(3, "\343D\n\0\0\0\30\17\366A\366F
\32\326\316+i|\366F;\207\303"...,
4096) =
4096
--- SIGSEGV (Segmentation fault) @ 0 (0) ---
+++ killed by SIGSEGV (core dumped) +++
Process 11621 detached


Now I am goint to test the --omit_journal_replay option (read from older posts)

(5 min. later) It is checking files now, please solve this bug; jfs looks pretty unstable; It was a problem from the hd (it shutted down and restarted continuously for 1 hour and when rebooted I found that I had not access to my files).
I am going to post a review not very favourable to this filesystem in my blog, now I am using XFS.

Finally I got this:

david@pcimanol:/sbin$ sudo jfs_fsck /dev/sdb6 --omit_journal_replay
Password:
jfs_fsck version 1.1.12, 24-Aug-2007
processing started: 9/26/2007 23.32.29
Using default parameter: -p
The current device is: /dev/sdb6
Block size in bytes: 4096
Filesystem size in blocks: 60559017
**Phase 1 - Check Blocks, Files/Directories, and Directory Entries
**Phase 2 - Count links
Incorrect link counts have been detected. Will correct.
**Phase 3 - Duplicate Block Rescan and Directory Connectedness
**Phase 4 - Report Problems
File system object FF393486 is linked as: /var/log/syslog
cannot repair the data format error(s) in this file.
cannot repair FF393486. Will release.
**Phase 5 - Check Connectivity
**Phase 6 - Perform Approved Corrections
**Phase 7 - Rebuild File/Directory Allocation Maps
**Phase 8 - Rebuild Disk Allocation Maps
**Phase 9 - Reformat File System Log
242236068 kilobytes total disk space.
128008 kilobytes in 36377 directories.
228585950 kilobytes in 392892 user files.
324 kilobytes in extended attributes
358762 kilobytes reserved for system use.
13419040 kilobytes are available for use.
Filesystem is clean.


Thank you for your help. Continue with your hard working and congratulations for its speed,

kind regards,

David Losada
Y recibí esta respuesta a las pocas horas:


It looks like you got past this on your own. Thanks for all the details. I think I know what the problem is, and I'll fix jfs_fsck tomorrow. (I just found an older report which I think is the same trap, that I said I would fix, and somehow I lost track of it over a year ago.
My bad!)

David Kleikamp
IBM Linux Technology Center

15 minutos más tarde me dice:



I spoke too soon. I did fix that one. This one is different. I needto sanity check some more values that are based on data read from the
journal.


Shaggy
Entonces me disculpo, ya que al haber resuelto el problema ya no se pueden hacer más tests in situ (respuesta de Shaggy incluída):



> Dear Dave,
> I hope you have enough data to fix, I'm sorry if you have lost the
> test case with me. It was a hardware failure; the HD went to sleep for
> its own a lot of times; sometimes it didn't wake up until 3 or 4
> minutes later.


The stack trace pointed right to the line of code where it was crashing, and it was easy enough to see that reading bad data from the journal could lead to a bad memory access. It's just a matter of determining the best way to sanity check the data, and aborting the journal replay cleanly.

> The HD runs OK, but after some hours (even doing nothing) he feels
> it needs sleep ;-), in an ocassion I had to shutdown the computer
> because his sleeping last too long; so probably some journal data get
> corrupted?


I'm not sure exactly how the data got corrupted. Maybe one of the last writes before the hd shut down had errors. I could only guess.
>
> If I can help in something please tell me (I'm not a programmer but
> I learn fast).

I have enough information to fix this bug. Thanks for your help.

>
> Thank you, and regards from Spain,
>
> David Losada

Thanks,
Shaggy
--
David Kleikamp
IBM Linux Technology Center
No puedo más que quitarme el sombrero ante la eficiencia y rapidez en el soporte de la comunidad linux y los programadores de linux. Es la primera vez que he tenido un problema importante (cuando probé Mandriva, otra distro linux poco pulida, la comunidad era de poca ayuda) y se ha resuelto en el plazo de 2 horas.


Recomendaciones
- No te desesperes, cuando tengas un problema consulta la web, a otros les habrá pasado lo mismo, y si puedes ayudar comunicando el error a los responsables del programa para que no les vuelva a pasar a otros, mejor que mejor.
- Haz copias de seguridad al menos una vez al mes de tus datos más queridos.


Breve análisis de JFS
Es el más rápido en mi sistema, un ordenador equivalente a un P4 a 1 Ghz, pero puede que debido a que es un sistema orientado a servidores desarrollado por IBM, el programa que se encarga de hacer los cambios que se han quedado pendientes en el journal al apagar mal el disco no está muy maduro, y dependiendo de lo corruptos que estén los datos del journal puede cascar. Además permite archivos de hasta 4 Petabytes, ideal para grabar vídeos con alta calidad sin parar.
Y si reúsa montarse una partición JFS, puedes probar a perder los últimos cambios y ejecutar:

jfs_fsck /dev/partición --omit_journal_replay (sustituye partición por disco y número)


En breve realizaré un análisis más exhaustivo de este Sistema de Archivos, el mejor en máquinas poco potentes con permiso de Reiser4 y XFS.

Espero que no os pase lo que a mí, y que a alguien le sirva de ayuda.

Referencias y más información:
*Segmentation Fault: O fallo de segmentación se da en un ordenador cuando un programa intenta acceder a una zona de memoria a la que no tiene acceso o de una manera en la que no es posible acceder.
- Linux.com Cómo recuperar un sistema de archivos en linux (inglés)
- Ley de Murphy

3 comentarios:

  1. Me alegro de que al final hayas podido recuperar los datos. A mi todavía no me ha pasado eso de perder toda la información, pero antes de tentar a la suerte me monté un servidor de backup en el que tengo montado un raid 1 por si acaso. Ahora duermo por las noches mucho más tranquilo.

    Saludos, Iván.

    ResponderEliminar
  2. Pues sí, yo también me alegro de que no haya habido pérdida de datos.

    Como yo tengo en el ordenador un RAID0 con dos discos iguales, siempre voy muy precavido, porque las posibilidades de fallo se multiplican, así que también hago copias en un disco externo usando rsync, pero nunca me he fiado de XFS, JFS ni Reiser... Siempre he preferido mi lento pero fiable y requeteprobado ext3. Al final es una cuestión de estar tranquilo, ¿no?

    ResponderEliminar
  3. Bienvenido, Iván. Muy interesante tu blog para geeks como nosotros ;-).

    Y sí, menos mal que no perdí nada importante. Vosotros sí que andáis precavidos, pero no creo que al usuario normal que guarda fotos y unos cuantos textos le haga falta un RAID... más propenso al fallo y más complicado de preparar. Con tener un disco duro en el ordenador sólo para las copias y programar con algún programa las copias; el disco duro se apagará si no se usa ahorrando energía. Todo depende de las necesidades y conocimientos de cada uno... ¿no creeis?

    ResponderEliminar

Puede dejar su comentario, que tratará de ser moderado en los días siguientes. En caso de ser algo importante/urgente, por favor utilicen el formulario de arriba a la derecha para contactar.