Solucionar fallos de logs y PHP por cuota de disco en Virtualmin

Recientemente me enfrenté a un problema desconcertante en un servidor Virtualmin: un sitio web basado en PHP no estaba registrando ningún error, incluso cuando los provocaba intencionadamente. Lo más preocupante era que ciertas funcionalidades del sitio simplemente no se ejecutaban, a pesar de que la página cargaba y mostraba cambios visuales. Lo que inicialmente parecía un simple fallo de configuración de logs, se convirtió en una investigación más profunda que reveló un problema crítico de cuota de disco de usuario.

1. El Misterio de los Logs Vacíos

El primer síntoma fue la ausencia total de entradas en el log de errores de PHP. Mi configuración de Apache para el dominio sitio.cliente.com (anteriormente titulados.ucm.edu.ni) especificaba claramente dónde debían ir los errores:

<VirtualHost [IP del servidor]:443>
    ServerName sitio.cliente.com
    ServerAlias www.sitio.cliente.com
    ServerAlias mail.sitio.cliente.com
    ServerAlias webmail.sitio.cliente.com
    ServerAlias admin.sitio.cliente.com
    DocumentRoot /home/usuario_web/domains/sitio.cliente.com/public_html
    ErrorLog /var/log/virtualmin/sitio.cliente.com_error_log
    CustomLog /var/log/virtualmin/sitio.cliente.com_access_log combined
    DirectoryIndex index.php index.htm index.html
    <Directory /home/usuario_web/domains/sitio.cliente.com/public_html>
        Options -Indexes +IncludesNOEXEC +SymLinksIfOwnerMatch

Sin embargo, el archivo /var/log/virtualmin/sitio.cliente.com_error_log estaba vacío. Al revisar el directorio de logs del dominio, encontré un archivo php_log que también estaba en blanco:

root@servidor:/home/usuario_web/domains/sitio.cliente.com# ll logs/
total 28
drwxr-x--- 2 usuario_web usuario_web 4096 Nov 12 10:08 ./ 
drwxr-x--- 9 usuario_web usuario_web 4096 Nov 12 00:05 ../
lrwxrwxrwx 1 usuario_web usuario_web   51 Jan  2  2025 access_log -> /var/log/virtualmin/sitio.cliente.com_access_log
lrwxrwxrwx 1 usuario_web usuario_web   50 Jan  2  2025 error_log -> /var/log/virtualmin/sitio.cliente.com_error_log
-rw-r--r-- 1 usuario_web usuario_web    0 Nov 12 10:05 php_log

Para depurar, creé un archivo info.php con <?php phpinfo(); ?> y revisé las directivas clave:

display_errors => Off
log_errors => On
error_log => /home/usuario_web/domains/sitio.cliente.com/logs/php_log

Esto confirmó que PHP estaba configurado para enviar los errores a /home/usuario_web/domains/sitio.cliente.com/logs/php_log y que el registro de errores estaba activado. Sin embargo, el archivo seguía vacío.

2. Descartando Permisos y Configuración Básica de PHP-FPM

Mi siguiente paso fue verificar los permisos del archivo y el directorio de logs, así como el usuario bajo el que se ejecutaba PHP-FPM. Los comandos ls -ld y ps aux | grep php-fpm confirmaron que el directorio /home/usuario_web/domains/sitio.cliente.com/logs y el archivo php_log eran propiedad del usuario usuario_web, y que los procesos de PHP-FPM para este dominio también corrían bajo usuario_web.

root@servidor:/home/usuario_web/domains/sitio.cliente.com# ls -ld /home/usuario_web/domains/sitio.cliente.com/logs
drwxr-x--- 2 usuario_web usuario_web 4096 Nov 12 10:08 /home/usuario_web/domains/sitio.cliente.com/logs
root@servidor:/home/usuario_web/domains/sitio.cliente.com# ls -l /home/usuario_web/domains/sitio.cliente.com/logs/php_log
-rw-r--r-- 1 usuario_web usuario_web 0 Nov 12 10:05 /home/usuario_web/domains/sitio.cliente.com/logs/php_log

La salida de ps aux | grep php-fpm mostró que el pool de PHP-FPM para el dominio (`172191259088073`) se ejecutaba como `usuario_web`:

root         621  0.0  0.1 250148 34004 ?        Ss   Sep09   8:42 php-fpm: master process (/etc/php/8.0/fpm/php-fpm.conf)
www-data  474709  0.0  0.2 253956 56916 ?        S    Sep10   0:20 php-fpm: pool www
usuario_web 1649935  0.6  0.4 396828 110232 ?       S    10:11   0:09 php-fpm: pool 172191259088073
usuario_web 1649936  0.6  0.4 400212 114428 ?       S    10:11   0:09 php-fpm: pool 172191259088073

Descubrí que el archivo de configuración del pool de PHP-FPM (/etc/php/8.1/fpm/pool.d/1735832798228486.conf) usaba las directivas php_value[error_log] y php_value[log_errors]. Este fue un punto crítico, ya que para las versiones modernas de PHP-FPM (especialmente 8.1+), las directivas error_log y log_errors son de tipo PHP_INI_ALL y deben establecerse con php_admin_value y php_admin_flag para ser efectivas dentro de un pool.

Procedí a editar el archivo del pool para corregir esto:

[1735832798228486]
user = usuario_web
group = usuario_web
listen.owner = usuario_web
listen.group = usuario_web
listen.mode = 0660
listen = /run/php/1735832798228486.sock
pm = dynamic
pm.max_children = 16
pm.start_servers = 2
pm.min_spare_servers = 1
pm.max_spare_servers = 8
php_value[upload_tmp_dir] = /home/usuario_web/domains/sitio.cliente.com/tmp
php_value[session.save_path] = /home/usuario_web/domains/sitio.cliente.com/tmp
php_admin_value[error_log] = /home/usuario_web/domains/sitio.cliente.com/logs/php_log
php_admin_flag[log_errors] = on

Después de guardar los cambios, recargué PHP-FPM:

systemctl reload php8.1-fpm

Sin embargo, el problema persistía: el archivo php_log seguía vacío, aunque su marca de tiempo se actualizaba, indicando que el proceso de PHP lo abría pero no escribía nada.

3. El Enigma Persiste: Logs Vacíos y Código No Ejecutado

La persistencia del log vacío, incluso con la configuración corregida del pool, me llevó a sospechar que había algo más. Revisé el journalctl para PHP-FPM 8.1 y el php.ini global, confirmando que no había redirecciones a syslog ni configuraciones globales que anularan el log del pool. También intenté añadir catch_workers_output = yes y decorate_workers_output = no al pool, una solución común para problemas de logging con PHP-FPM y systemd, pero tampoco funcionó.

En este punto, la situación se volvió más crítica: me di cuenta de que el problema no era solo la falta de logs, sino que el sitio web no estaba ejecutando correctamente ciertas acciones PHP. La página cargaba, pero los formularios no procesaban, las actualizaciones no se aplicaban, etc. Esto sugería una incompatibilidad de versión de PHP o un error fatal que se estaba silenciando por completo.

Ante la desesperación, consideré degradar la versión de PHP del sitio a 7.4, que era la versión en la que el sitio funcionaba previamente. Fue en este proceso de cambio de versión en Virtualmin cuando apareció una pista crucial.

4. La Pista Definitiva: "Disk Quota Exceeded"

Al intentar acceder al enlace de phpinfo() proporcionado por Virtualmin para el dominio, recibí un error explícito:

Failed to write to /home/usuario_web/domains/sitio.cliente.com/public_html/file----phpinfo-sitio.cliente.com-1762969272+215184.php when closing : Disk quota exceeded

¡Eureka! Este mensaje era la clave. Inmediatamente verifiqué la cuota de disco del usuario usuario_web:

usuario_web@servidor:~/public_html$ quota -u usuario_web
Disk quotas for user usuario_web (uid 1003):
     Filesystem  blocks   quota   limit   grace   files   quota   limit   grace
      /dev/sda3 3302896* 3145728 3145728   6days   57710       0       0

El asterisco (*) junto a 3302896 confirmaba que el usuario usuario_web había excedido su cuota de disco de 3 GiB (3145728 bloques de 1KB). Aunque yo había "aumentado" la cuota en Virtualmin, el sistema operativo no la había aplicado correctamente o había un desajuste.

Además, al revisar los permisos del directorio public_html, noté un problema:

usuario_web@servidor:~/public_html$ ls -ld /home/usuario_web/domains/sitio.cliente.com/public_html
drwxr-x--- 9 www-data www-data 4096 Nov 12 14:06 /home/usuario_web/domains/sitio.cliente.com/public_html

El directorio era propiedad de www-data:www-data, pero el proceso PHP-FPM se ejecutaba como usuario_web. Esto significaba que, incluso si la cuota no fuera un problema, usuario_web no podría escribir en su propio directorio web, impidiendo la creación de sesiones, archivos temporales o logs.

Finalmente, al revisar el uso de espacio por el usuario, identifiqué algunos archivos grandes que contribuían al consumo de cuota:

root@servidor:/home/usuario_web/domains/sitio.cliente.com/public_html# du -sh /home/usuario_web/*
780K    /home/usuario_web/awstats
4.0K    /home/usuario_web/bin
4.0K    /home/usuario_web/cgi-bin
20K     /home/usuario_web/disable-search.2.1.zip
630M    /home/usuario_web/domains
81M     /home/usuario_web/eprints.3.3.16-26072024-0839.tar.gz
81M     /home/usuario_web/eprints.3.3.16-26072024-0942.tar.gz
80K     /home/usuario_web/etc
4.0K    /home/usuario_web/homes
16K     /home/usuario_web/koha
28K     /home/usuario_web/logs
35M     /home/usuario_web/Maildir
994M    /home/usuario_web/public_html
12K     /home/usuario_web/tabs-15102024.php
16K     /home/usuario_web/tabs.php
1.5M    /home/usuario_web/tic
16K     /home/usuario_web/titulos-widget.php
4.0K    /home/usuario_web/tmp
24K     /home/usuario_web/usuario_web
4.0K    /home/usuario_web/virtualmin-backup

5. La Solución: Ajustando la Cuota Correcta en Virtualmin y Permisos

La clave estaba en cómo Virtualmin gestiona las cuotas. Existen dos configuraciones principales:

• Total server quota: Un límite general para el dominio, incluyendo sub-servidores y usuarios de correo/FTP.
• Server administrator's quota: El límite real aplicado al usuario UNIX principal del dominio (en mi caso, usuario_web).

Yo había estado ajustando solo el "Total server quota", dejando la "Server administrator's quota" sin cambios, lo que mantenía al usuario usuario_web por encima de su límite real.

La solución fue sencilla una vez identificado el problema:

1. Aumentar la cuota del usuario usuario_web: Accedí a la sección "Quotas and limits" en la configuración del Virtual Server en Virtualmin y aumenté la opción "Server administrator's quota" a un valor superior al uso actual (por ejemplo, 5 GiB). Esto se reflejó inmediatamente al ejecutar quota -u usuario_web, donde el asterisco y el "grace period" desaparecieron.
2. Corregir la propiedad del directorio public_html: Para asegurar que PHP-FPM (ejecutándose como usuario_web) pudiera escribir en su propio directorio web, cambié la propiedad recursivamente:

chown -R usuario_web:usuario_web /home/usuario_web/domains/sitio.cliente.com/public_html
chmod -R 750 /home/usuario_web/domains/sitio.cliente.com/public_html

3. Limpiar archivos temporales y de log antiguos: Eliminé los archivos temporales de phpinfo y los logs comprimidos que pudieran estar ocupando espacio y contribuyendo al problema de cuota:

rm -f /home/usuario_web/domains/sitio.cliente.com/public_html/file----phpinfo*
rm -f /home/usuario_web/domains/sitio.cliente.com/logs/php_log.*
rm -f /home/usuario_web/tmp/*

Después de aplicar estos cambios, el sitio web volvió a funcionar con normalidad. Los logs de PHP comenzaron a registrar errores y el enlace de phpinfo() de Virtualmin se cargó correctamente.

6. Aprendizajes Clave y Reflexiones

Esta experiencia me dejó varias lecciones importantes:

• Prioridad de la cuota de disco: Un error de "Disk quota exceeded" es un problema fundamental que debe resolverse primero. Bloquea cualquier operación de escritura, incluyendo logs, sesiones y la ejecución de scripts que necesiten crear archivos temporales.
• Diferencias en cuotas de Virtualmin: Es crucial entender la distinción entre "Total server quota" y "Server administrator’s quota" en Virtualmin. El segundo es el que afecta directamente al usuario UNIX principal del dominio.
• Propiedad de directorios: Asegurarse de que el usuario bajo el que se ejecuta PHP-FPM (el usuario del dominio) tiene permisos de escritura en su propio directorio public_html es vital para el correcto funcionamiento de la aplicación.
• Logging de PHP-FPM y Systemd: Aunque no fue la causa raíz en este caso, la configuración de php_admin_value/php_admin_flag y catch_workers_output sigue siendo importante para asegurar que los logs de PHP-FPM se escriban correctamente en entornos con integración de systemd.