Una descripción detallada de las búsquedas de errores de la tarea GitLab que condujo al parche para el kernel de Linux
El 14 de septiembre, el soporte de GitLab informó un problema crítico que le ocurrió a uno de nuestros clientes: primero, GitLab funciona bien, y luego los usuarios obtienen un error. Intentaron clonar algunos repositorios a través de Git, y de repente apareció un mensaje incomprensible sobre un archivo obsoleto: Stale file error obsoleto. El error persistió durante mucho tiempo y no funcionó hasta que el administrador del sistema inició manualmente ls en el directorio mismo.
Tuve que estudiar los mecanismos internos de Git y el sistema de archivos de red NFS. Como resultado, encontramos un error en el cliente Linux v4.0 NFS, Trond Myklebust escribió un parche para el núcleo , y desde el 26 de octubre, este parche se ha incluido en el núcleo principal de Linux .
En esta publicación, te contaré cómo estudiamos el problema, en qué dirección pensamos y qué herramientas utilizamos para rastrear el error. Nos inspiró el excelente trabajo de detective de Oleg Dashevsky que se describe en la publicación "Cómo busqué una fuga de memoria en Ruby durante dos semanas" .
También es un gran ejemplo de cómo la depuración de código abierto es un deporte de equipo que involucra a muchas personas, empresas y países. El lema de GitLab, " Todos pueden contribuir " , es cierto no solo para GitLab en sí, sino también para otros proyectos de código abierto, como el kernel de Linux.
Reproducción de errores
Mantuvimos NFS en GitLab.com durante muchos años, pero luego dejamos de usarlo para acceder a los datos del repositorio en máquinas con aplicaciones. Hemos trasladado todas las llamadas de Git a Gitaly . Admitimos NFS para clientes que administran sus instalaciones en GitLab pero que nunca han tenido el mismo problema que el cliente mencionado anteriormente.
El cliente dio algunas sugerencias útiles :
- Texto de error completo:
fatal: Couldn't read ./packed-refs: Stale file handle . - Aparentemente, el problema surgió cuando el cliente inició manualmente la recolección de basura en Git con el comando
git gc . - El error desapareció cuando el administrador del sistema inició la utilidad
ls en el directorio. - El error desapareció cuando
git gc proceso git gc .
Está claro que los dos primeros puntos están conectados. Cuando envía cambios a la rama de Git, Git crea un enlace débil: un nombre de archivo largo que indica el nombre de la rama para la confirmación. Por ejemplo, cuando se envía a master , se creará un archivo llamado refs/heads/master en el repositorio:
$ cat refs/heads/master 2e33a554576d06d9e71bfd6814ee9ba3a7838963
El comando git gc realiza varias tareas. Por ejemplo, recopila estos enlaces débiles (referencias) y los empaqueta en un solo archivo llamado packed-refs . Esto acelera un poco el trabajo, porque leer un archivo grande es más fácil que muchos pequeños. Por ejemplo, después de ejecutar el comando git gc , el archivo packed-refs podría verse así:
# pack-refs with: peeled fully-peeled sorted 564c3424d6f9175cf5f2d522e10d20d781511bf1 refs/heads/10-8-stable edb037cbc85225261e8ede5455be4aad771ba3bb refs/heads/11-0-stable 94b9323033693af247128c8648023fe5b53e80f9 refs/heads/11-1-stable 2e33a554576d06d9e71bfd6814ee9ba3a7838963 refs/heads/master
¿Cómo se crea el archivo packed-refs ? Para averiguarlo, strace git gc comando strace git gc donde teníamos un enlace débil. Aquí están las líneas que son relevantes:
28705 open("/tmp/libgit2/.git/packed-refs.lock", O_RDWR|O_CREAT|O_EXCL|O_CLOEXEC, 0666) = 3 28705 open(".git/packed-refs", O_RDONLY) = 3 28705 open("/tmp/libgit2/.git/packed-refs.new", O_RDWR|O_CREAT|O_EXCL|O_CLOEXEC, 0666) = 4 28705 rename("/tmp/libgit2/.git/packed-refs.new", "/tmp/libgit2/.git/packed-refs") = 0 28705 unlink("/tmp/libgit2/.git/packed-refs.lock") = 0
Las llamadas al sistema mostraron que el comando git gc :
- Abierto
packed-refs.lock . Esto le dice a otros procesos que el archivo de packed-refs está bloqueado y no puede cambiar. - Abierto
packed-refs.new . packed-refs.new enlaces débiles en packed-refs.new .- Renombrado
packed-refs packed-refs.new a packed-refs packed-refs.new . - Se eliminó el
packed-refs.lock . - Se eliminaron los enlaces débiles.
El punto clave aquí es el cuarto, es decir, el cambio de nombre, donde Git presenta el archivo de packed-refs . git gc no solo recopila enlaces débiles, sino que también realiza una tarea que requiere muchos más recursos: busca y elimina objetos no utilizados. En repositorios grandes, esto puede durar más de una hora.
Y nos preguntamos: ¿en los repositorios grandes, git gc mantiene el archivo abierto durante la limpieza? Estudiamos los registros de strace , lanzamos la utilidad lsof , y esto es lo que aprendimos sobre el proceso git gc :
Como puede ver, el archivo de packed-refs cierra al final, después del proceso potencialmente largo de Garbage collect objects .
Entonces surgió la siguiente pregunta: ¿cómo se comporta NFS cuando el archivo de packed-refs está abierto en un nodo y el otro lo renombra en ese momento?
"Con fines científicos", le pedimos al cliente que realizara un experimento en dos máquinas diferentes (Alice y Bob):
1) En el volumen compartido NFS, cree dos archivos: test1.txt y test2.txt con diferentes contenidos, para que sea más fácil distinguirlos:
alice $ echo "1 - Old file" > /path/to/nfs/test1.txt alice $ echo "2 - New file" > /path/to/nfs/test2.txt
2) En la máquina de Alice, el archivo test1.txt debería estar abierto:
alice $ irb irb(main):001:0> File.open('/path/to/nfs/test1.txt')
3) En la máquina de Alice, muestre continuamente el contenido de test1.txt :
alice $ while true; do cat test1.txt; done
4) Luego, en la máquina de Bob, ejecute el comando:
bob $ mv -f test2.txt test1.txt
El último paso reproduce lo que hace git gc con el archivo de packed-refs al sobrescribir un archivo existente.
En la máquina del cliente, el resultado se parecía a esto:
1 - Old file 1 - Old file 1 - Old file cat: test1.txt: Stale file handle
Hay! Parece que hemos controlado el problema de manera controlada. Pero en el mismo experimento en un servidor NFS de Linux, este problema no ocurrió. El resultado era esperado; después de renombrar el nuevo contenido fue aceptado:
1 - Old file 1 - Old file 1 - Old file 2 - New file <--- RENAME HAPPENED 2 - New file 2 - New file
¿De dónde viene esta diferencia de comportamiento? Resulta que el cliente usó el almacenamiento Isilon NFS , que solo era compatible con NFS v4.0. Cuando cambiamos la configuración de conexión a v4.0 usando el parámetro vers=4.0 en /etc/fstab , la prueba mostró un resultado diferente para el servidor NFS de Linux:
1 - Old file 1 - Old file 1 - Old file 1 - Old file <--- RENAME HAPPENED 1 - Old file 1 - Old file
En lugar del Stale file handle obsoleto Stale file handle servidor Linux NFS v4.0 muestra contenido obsoleto. Resulta que la diferencia de comportamiento puede explicarse por las especificaciones NFS. De RFC 3010 :
El descriptor de archivo puede quedar obsoleto o caducar cuando se cambia el nombre, pero no siempre. Se recomienda a los implementadores del servidor que tomen medidas para garantizar que los descriptores de archivos no caduquen y no caduquen de esta manera.
En otras palabras, los servidores NFS pueden elegir cómo comportarse cuando se cambia el nombre de un archivo, y el servidor NFS devuelve razonablemente un Stale file error en tales casos. Sugerimos que la causa del problema es la misma, aunque los resultados fueron diferentes. Sospechamos que se trataba de una comprobación de caché, porque la utilidad ls en el directorio eliminó el error. Ahora teníamos un escenario de prueba reproducible y recurrimos a expertos: mantenedores de Linux NFS.
False Trace: Delegación en un servidor NFS
Cuando logramos reproducir el error paso a paso, escribí a los contactos de Linux NFS sobre lo que aprendimos. Me comuniqué con Bruce Fields, el encargado del mantenimiento del servidor NFS de Linux durante una semana, y me sugirió que el error estaba en NFS y que necesitaba estudiar el tráfico de la red. Pensó que el problema era delegar tareas en el servidor NFS.
¿Qué es la delegación en un servidor NFS?
En pocas palabras, la versión NFS v4 tiene una función de delegación para acelerar el acceso a los archivos. El servidor puede delegar el acceso de lectura o escritura al cliente para que el cliente no tenga que preguntarle constantemente al servidor si otro cliente ha cambiado el archivo. En pocas palabras, delegar un registro es como prestarle a alguien su cuaderno y decir: "Usted escribe aquí, y lo recogeré cuando esté listo". Y una persona no tiene que pedir un cuaderno cada vez que necesita escribir algo: tiene total libertad de acción hasta que se lo quite. En NFS, una solicitud para devolver un cuaderno se llama revocación de delegación.
Un error en la revocación de la delegación NFS podría explicar el problema de Stale file handle . Recuerde cómo se abrió test1.txt en el test1.txt de Alice, y luego test2.txt reemplazó. Tal vez el servidor no pudo revocar la delegación para test1.txt , y esto llevó a un estado no válido. Para probar esta teoría, registramos el tráfico NFC con la utilidad tcpdump y lo visualizamos usando Wireshark.
Wireshark es una gran herramienta de código abierto para analizar el tráfico de red, especialmente para explorar NFS en acción. Registramos la traza utilizando el siguiente comando en un servidor NFS:
tcpdump -s 0 -w /tmp/nfs.pcap port 2049
Este comando registra todo el tráfico NFS que generalmente pasa por el puerto TCP 2049. Dado que nuestro experimento fue exitoso con NFS v4.1, pero no con NFS v4.0, podríamos comparar el comportamiento de NFS en el caso de trabajo y no trabajo. Con Wireshark, vimos el siguiente comportamiento:
NFS v4.0 (archivo en desuso)
Este diagrama muestra que en el paso 1, Alice abre test1.txt y recibe un descriptor de archivo NFS con el identificador stateid 0x3000. Cuando Bob intenta cambiar el nombre del archivo, el servidor NFS solicita volver a intentarlo enviando el mensaje NFS4ERR_DELAY , y recuerda la delegación de Alice a través del mensaje CB_RECALL (paso 3). Alice devuelve la delegación (DELEGRETURN en el paso 4) y Bob intenta enviar el mensaje RENAME nuevamente (paso 5). RENAME se ejecuta en ambos casos, pero Alice continúa leyendo el archivo con el mismo descriptor.
NFS v4.1 (caso de trabajo)
Aquí la diferencia es visible en el paso 6. En NFS v4.0 (con un archivo obsoleto) Alice intenta usar el mismo stateid . En NFS v4.1 (caso de trabajo), Alice realiza operaciones adicionales de LOOKUP y OPEN , por lo que el servidor devuelve un stateid diferente. En v4.0, no envía ningún mensaje adicional. Esto explica por qué Alice ve contenido desactualizado: usa un descriptor antiguo.
¿Por qué Alice de repente decide una LOOKUP extra? Aparentemente, el retiro de la delegación fue exitoso, pero aparentemente se mantuvo algún problema. Por ejemplo, se omite el paso de discapacidad. Para verificar esto, excluimos la delegación NFS en el servidor NFS con este comando:
echo 0 > /proc/sys/fs/leases-enable
Repetimos el experimento, pero el problema no desapareció. Nos aseguramos de que el problema no estuviera en el servidor NFS o en la delegación, y decidimos mirar el cliente NFS en el núcleo.
Profundizando: cliente NFS de Linux
La primera pregunta que tuvimos que responder a los mantenedores de NFS fue:
¿Este problema persiste en la última versión del kernel?
El problema ocurrió en los núcleos CentOS 7.2 y Ubuntu 16.04 con las versiones 3.10.0-862.11.6 y 4.4.0-130, respectivamente. Pero ambos núcleos se quedaron atrás de la última versión, que en ese momento era 4.19-rc2.
Implementamos la nueva máquina virtual Ubuntu 16.04 en Google Cloud Platform (GCP), clonamos el último kernel de Linux y configuramos el entorno de desarrollo del kernel. Creamos el archivo .config usando menuconfig y verificamos que:
- El controlador NFS se compila como un módulo (
CONFIG_NFSD=m ). - Los parámetros correctos del núcleo GCP se especifican correctamente.
La genética rastrea la evolución en tiempo real por Drosophila, y con el primer elemento pudimos hacer rápidamente correcciones al cliente NFS sin reiniciar el núcleo. El segundo punto garantiza que el núcleo se iniciará después de la instalación. Afortunadamente, estábamos satisfechos con los parámetros predeterminados del kernel.
Nos aseguramos de que el problema del archivo obsoleto no desapareciera en la última versión del kernel. Nos preguntamos a nosotros mismos:
- ¿Dónde surge exactamente el problema?
- ¿Por qué sucede esto en NFS v4.0, pero no en v4.1?
Para responder a estas preguntas, profundizamos en el código fuente NFS. No teníamos un depurador del núcleo, por lo que enviamos dos tipos de llamadas al código fuente:
pr_info() ( printk ).dump_stack() : muestra el seguimiento de la pila para la llamada a la función actual.
Por ejemplo, lo primero que hicimos fue conectarnos a la función nfs4_file_open() en fs/nfs/nfs4file.c :
static int nfs4_file_open(struct inode *inode, struct file *filp) { ... pr_info("nfs4_file_open start\n"); dump_stack();
Por supuesto, podríamos dprintk con la depuración dinámica de Linux o usar rpcdebug , pero queríamos agregar nuestros propios mensajes para verificar los cambios.
Después de cada cambio, recompilamos el módulo y lo reinstalamos en el kernel usando los comandos:
make modules sudo umount /mnt/nfs-test sudo rmmod nfsv4 sudo rmmod nfs sudo insmod fs/nfs/nfs.ko sudo mount -a
Con el módulo NFS, pudimos repetir experimentos y recibir mensajes para comprender el código NFS. Por ejemplo, puede ver de inmediato lo que sucede cuando la aplicación llama a open() :
Sep 24 20:20:38 test-kernel kernel: [ 1145.233460] Call Trace: Sep 24 20:20:38 test-kernel kernel: [ 1145.233462] dump_stack+0x8e/0xd5 Sep 24 20:20:38 test-kernel kernel: [ 1145.233480] nfs4_file_open+0x56/0x2a0 [nfsv4] Sep 24 20:20:38 test-kernel kernel: [ 1145.233488] ? nfs42_clone_file_range+0x1c0/0x1c0 [nfsv4] Sep 24 20:20:38 test-kernel kernel: [ 1145.233490] do_dentry_open+0x1f6/0x360 Sep 24 20:20:38 test-kernel kernel: [ 1145.233492] vfs_open+0x2f/0x40 Sep 24 20:20:38 test-kernel kernel: [ 1145.233493] path_openat+0x2e8/0x1690 Sep 24 20:20:38 test-kernel kernel: [ 1145.233496] ? mem_cgroup_try_charge+0x8b/0x190 Sep 24 20:20:38 test-kernel kernel: [ 1145.233497] do_filp_open+0x9b/0x110 Sep 24 20:20:38 test-kernel kernel: [ 1145.233499] ? __check_object_size+0xb8/0x1b0 Sep 24 20:20:38 test-kernel kernel: [ 1145.233501] ? __alloc_fd+0x46/0x170 Sep 24 20:20:38 test-kernel kernel: [ 1145.233503] do_sys_open+0x1ba/0x250 Sep 24 20:20:38 test-kernel kernel: [ 1145.233505] ? do_sys_open+0x1ba/0x250 Sep 24 20:20:38 test-kernel kernel: [ 1145.233507] __x64_sys_openat+0x20/0x30 Sep 24 20:20:38 test-kernel kernel: [ 1145.233508] do_syscall_64+0x65/0x130
¿Qué son estas vfs_open do_dentry_open y vfs_open ? Linux tiene un sistema de archivos virtual ( VFS ), una capa de abstracción que proporciona una interfaz común para todos los sistemas de archivos. La documentación de VFS dice:
VFS implementa open (2), stat (2), chmod (2) y otras llamadas al sistema. El sistema VFS utiliza el argumento del nombre de ruta que se les pasa para buscar entradas de directorio en el caché (dentry cache o dcache). Esto proporciona un motor de búsqueda muy rápido que convierte el nombre de la ruta (o el nombre del archivo) en un dentry específico. Dentry reside en la RAM y nunca se guarda en el disco; existen solo para el rendimiento.
Y nos dimos cuenta: ¿qué pasa si el problema está en el caché de dentry?
Notamos que el caché de dentry generalmente se verifica en fs/nfs/dir.c Estábamos especialmente interesados en la función nfs4_lookup_revalidate() , y como experimento, lo hicimos funcionar antes:
diff --git a/fs/nfs/dir.cb/fs/nfs/dir.c index 8bfaa658b2c1..ad479bfeb669 100644 --- a/fs/nfs/dir.c +++ b/fs/nfs/dir.c @@ -1159,6 +1159,7 @@ static int nfs_lookup_revalidate(struct dentry *dentry, unsigned int flags) trace_nfs_lookup_revalidate_enter(dir, dentry, flags); error = NFS_PROTO(dir)->lookup(dir, &dentry->d_name, fhandle, fattr, label); trace_nfs_lookup_revalidate_exit(dir, dentry, flags, error); + goto out_bad; if (error == -ESTALE || error == -ENOENT) goto out_bad; if (error)
Y en este experimento, ¡no ocurrió un problema de archivo obsoleto! Finalmente, atacamos el camino.
Para descubrir por qué el problema no ocurrió en NFS v4.1, agregamos llamadas pr_info() a cada bloque if en esta función. Experimentamos con NFS v4.0 y v4.1 y encontramos una condición especial en la versión v4.1:
if (NFS_SB(dentry->d_sb)->caps & NFS_CAP_ATOMIC_OPEN_V1) { goto no_open; }
¿Qué es NFS_CAP_ATOMIC_OPEN_V1 ? Este parche del kernel dice que esta es una característica de NFS v4.1, y el código en fs/nfs/nfs4proc.c confirmó que este parámetro está en v4.1 pero no en v4.0:
static const struct nfs4_minor_version_ops nfs_v4_1_minor_ops = { .minor_version = 1, .init_caps = NFS_CAP_READDIRPLUS | NFS_CAP_ATOMIC_OPEN | NFS_CAP_POSIX_LOCK | NFS_CAP_STATEID_NFSV41 | NFS_CAP_ATOMIC_OPEN_V1
Por lo tanto, las versiones se comportaron de manera diferente: en v4.1, goto no_open llama a más comprobaciones en la función nfs_lookup_revalidate() , y en v4.0 la función nfs4_lookup_revalidate() regresa antes. ¿Y cómo resolvimos el problema?
Solución
Hablé sobre nuestros hallazgos en la lista de correo NFS y sugerí un parche primitivo . Una semana después, Trond Myklebust envió una serie de parches con correcciones de errores a la lista de correo y encontró otro problema relacionado en NFS v4.1 .
Resulta que la solución para el error NFS v4.0 era más profunda en la base del código de lo que pensábamos. Trond lo describió bien en el parche :
Es necesario asegurarse de que el inodo y la dentry estén correctamente verificados dos veces cuando se abre un archivo ya abierto. En este momento no estamos verificando dos veces NFSv4.0, porque el archivo abierto está en caché. Arreglemos esto y guardemos en caché los archivos abiertos solo en casos especiales: para restaurar los archivos abiertos y devolver la delegación.
Nos aseguramos de que esta solución resolviera el problema del archivo obsoleto y enviara informes de errores a los equipos de Ubuntu y RedHat .
Entendemos bien que los cambios aún no se realizarían en la versión estable del kernel, por lo que agregamos una solución temporal a este problema en Gitaly . Experimentamos y verificamos que llamar a stat() en el archivo de packed-refs hace que el núcleo verifique dos veces el archivo renombrado en el caché de dentry. Para simplificar, implementamos esto en Gitaly para cualquier sistema de archivos, no solo NFS. La validación se realiza solo una vez antes de que Gitaly abra el repositorio, y para otros archivos ya hay otras llamadas stat() .
Que hemos aprendido
Un error puede ocultarse en cualquier rincón de la pila de software y, a veces, debe buscarlo fuera de la aplicación. Si tiene conexiones útiles en el mundo de código abierto, esto facilitará su trabajo.
Muchas gracias a Trond Myuklebust por solucionar el problema, y a Bruce Fields por responder nuestras preguntas y ayudarnos a resolver NFS. Es por tal capacidad de respuesta y profesionalismo que valoramos la comunidad de desarrolladores de código abierto.