Archivos log enormes

Distribuciones GNU Linux y software libre Asesoramiento sistemas Linux
1

Hola gente.
Hoy me ha pasado una cosa bien curiosa.
Resulta que mi sistema de repente ha dejado de funcionar, y al reiniciar, se me quedaba colgado haciendo un fsck de los discos, cosa que bueno, en principio no me ha extrañado hasta que ha pasado más de 20 minutos y he empezado a mosquearme.
Lo primero que he hecho es ir a /etc/fstab para indicar que no haga la comprobación rutinaria, pero el sistema no llegaba a arrancar las X.
Echando un ojo a los discos, me doy cuenta de que la partición que tengo para “/” está llena, y ya eso me ha extrañado, pero he pensado que llevaba mucho tiempo sin reiniciar, y he hecho un upgrade hace unos días. Pensé que quizá cuando instalé el sistema me pasé de rata al darle “solo” 30G a esa partición, por lo que arranco con una live con la intención de darle un poco mas de espacio a la partición /, y asunto arreglado.
Antes de asignarle más espacio, me ha picado la curiosidad y he buscado archivos de gran tamaño, y cual es mi sorpresa, que me encuentro en /var/log, al menos 3 archivos con más de 5 G. Uno era messages, otro syslog y otro user.log. He hecho unos tails a ver si veía algo raro, pero nada que me haya llamado la atención.
He vaciado estos archivos y el sistema vuelve a estar como nuevo.
Pero no quiero quedarme con la duda.
Ya a toro pasado recuerdo que me pasó algo similar en un servidor que tenía en la nube he hice lo mismo. Vacié los archivos y a seguir con mi vida. En ese momento lo achaque a un posible hackeo, o intento de hackeo, ya que ese servidor lo tenía para hacer pruebas y realmente estaba bastante inseguro.
Os ha pasado a alguien algo similar?, y/o sabéis a qué puede ser debido? está dentro de lo normal que estos archivos alcancen este tamaño?
Es la primera vez que me pasa algo así en un sistema de escritorio, al menos que yo sepa, y llevo cerca de 20 años usando linux exclusivamente en escritorio.

Muchas gracias de antemano

2

Hola Javierbu :slight_smile:
Te iba a responder hace unos días pero tu post ha despertado más dudas porque nunca realmente me había parado en pensar sobre la pertinencia de tener una partición /var dedicada.
Tu experiencia ilustra el por qué: Si se peta el log por la razón que sea, esto no te impide arrancar el sistema.
Ahora mirando en la documentación de red hat, centOS y otras distrib` más enfocadas a entorno de producción-servidores tampoco hablan de dedicar tanto espacio a la partición /var.
Hablan por ejemplo de 3-5GB y esto sabiendo que el log del firewall (acaba en /var y puede llegar a ser algo voluminoso) será mucho más importante que en una computadora personal.

Volviendo a lo tuyo el tamaño de los tres ficheros mencionados supera el entendimiento.
Dando vueltas me parece que hay dos cosas que podemos hacer: configurar rsyslog gracias a logrotate y journal

En mi sistema es la carpeta journal adentro de /var/log que ocupa más peso:

71M	/var/log/
57M	/var/log/journal

Hay un fichero de configuración que tiene decenas de parámetros anotados que podemos usar para controlar el tamaño de los logs journal: /etc/systemd/journald.conf
Creo que voy simplemente a des-anotar este tal cual:

#MaxFileSec=1month

Un mes de log me parece bastante para mi sobremesa que uso a diario,

Luego está rsyslog que se encarga de los ficheros que causaron tus problemas, esto es lo que sale en /etc/rsyslog.conf

[code]###############

RULES

###############

First some standard log files. Log by facility.

auth,authpriv.* /var/log/auth.log
.;auth,authpriv.none -/var/log/syslog
#cron.* /var/log/cron.log
daemon.* -/var/log/daemon.log
kern.* -/var/log/kern.log
lpr.* -/var/log/lpr.log
mail.* -/var/log/mail.log
user.* -/var/log/user.log
[/code]
Y es el paquete logrotate mediante su fichero de configuración que se encarga de borrar las viejas entradas
No lo he tocado y por defecto sería así:

[code]root@bob:~# cat /etc/logrotate.conf

see “man logrotate” for details

global options do not affect preceding include directives

rotate log files weekly

weekly

keep 4 weeks worth of backlogs

rotate 4

create new (empty) log files after rotating old ones

create

use date as a suffix of the rotated file

#dateext

uncomment this if you want your log files compressed

#compress

packages drop log rotation information into this directory

include /etc/logrotate.d

system-specific logs may also be configured here.

[/code]
Por defecto se guardan 4 semanas en ficheros “archivos” y el fichero en curso debería tener una semana de log,
Pero no hay ninguna contra-medida frente al problema que tuviste,
Según leo podríamos añadir un parámetro para anticipar esto: **maxsize **

[quote]maxsize size
Log files are rotated when they grow bigger than size bytes even before
the additionally specified time interval (daily, weekly, monthly,
or yearly). The related size option is similar except that it
is mutually exclusive with the time interval options, and it causes
log files to be rotated without regard for the last rotation time.
When maxsize is used, both the size and timestamp of a log file are
considered.[/quote]
Algo cómo

maxsize 50M

Debería ser (más) que suficiente.

3

Muchas gracias por tu respuesta y tus consejos para evitar que los archivos adquieran esos tamaños disparatados.

Realmente el sistema llega a arrancar, pero solo en modo recovery. Supongo que en cuento tenga que escribir algo en /tmp/, al no haber espacio en la partición (no tengo /tmp en partición separada), es cuando peta. Por eso no llega a arrancar las X.
Coincido que quizá fuera interesante crear una partición para /var/, y asi evitar este problema, pero tampoco parece que sea muy común y por fortuna muy sencillo de solucionar a priori siempre que des con él y no desfallezas en el intento de buscarlo.

Mi archivo /etc/rsyslog.conf difiere un poco del tuyo, pero tampoco se ve que haya nada raro, y huelga decir que nunca he editado este archivo.

[code]# /etc/rsyslog.conf configuration file for rsyslog

For more information install rsyslog-doc and see

/usr/share/doc/rsyslog-doc/html/configuration/index.html

#################

MODULES

#################

module(load=“imuxsock”) # provides support for local system logging
module(load=“imklog”) # provides kernel logging support
#module(load=“immark”) # provides --MARK-- message capability

provides UDP syslog reception

#module(load=“imudp”)
#input(type=“imudp” port=“514”)

provides TCP syslog reception

#module(load=“imtcp”)
#input(type=“imtcp” port=“514”)

###########################

GLOBAL DIRECTIVES

###########################

Use traditional timestamp format.

To enable high precision timestamps, comment out the following line.

$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat

Set the default permissions for all log files.

$FileOwner root
$FileGroup adm
$FileCreateMode 0640
$DirCreateMode 0755
$Umask 0022

Where to place spool and state files

$WorkDirectory /var/spool/rsyslog

Include all config files in /etc/rsyslog.d/

$IncludeConfig /etc/rsyslog.d/*.conf

###############

RULES

###############

First some standard log files. Log by facility.

auth,authpriv.* /var/log/auth.log
.;auth,authpriv.none -/var/log/syslog
#cron.* /var/log/cron.log
daemon.* -/var/log/daemon.log
kern.* -/var/log/kern.log
lpr.* -/var/log/lpr.log
mail.* -/var/log/mail.log
user.* -/var/log/user.log

Logging for the mail system. Split it up so that

it is easy to write scripts to parse these files.

mail.info -/var/log/mail.info
mail.warn -/var/log/mail.warn
mail.err /var/log/mail.err

Some “catch-all” log files.

.=debug;
auth,authpriv.none;
mail.none -/var/log/debug
.=info;.=notice;.=warn;
auth,authpriv.none;
cron,daemon.none;
mail.none -/var/log/messages

Emergencies are sent to everybody logged in.

.emerg :omusrmsg:
[/code]

Y el último que comentas, el /etc/logrotate.conf es idéntico al tuyo.

De momento voy a dejarlo todo como está, a ver si me vuelve a pasar con algo más de tiempo para entretenerme y buscar un motivo. De hecho no he realizado ninguna búsqueda seria sobre este tema buscando motivos ya que en ese momento me urgía tener mi sistema funcionando y no tanto las razones del crasheo.

Lo que me queda claro es que es un comportamiento totalmente anómalo que no responde a ninguna lógica.

-rw-r----- 1 root adm 5,4G mar 17 19:38 messages -rw-r----- 1 root adm 5,4G mar 17 19:39 syslog -rw-r----- 1 root adm 5,4G mar 17 19:38 user.log

4

[quote=javierbu]
Lo que me queda claro es que es un comportamiento totalmente anómalo que no responde a ninguna lógica.

-rw-r----- 1 root adm 5,4G mar 17 19:38 messages -rw-r----- 1 root adm 5,4G mar 17 19:39 syslog -rw-r----- 1 root adm 5,4G mar 17 19:38 user.log[/quote]
Es para ponerlo en un marco y colocarlo en tu salón. :smiley:
He observado el directorio /var/log todos estos días; los ficheros messages etc… raramente han sobrepasado el MB. Una vez comprimido en .gz para estar archivados pierden más de la mitad de su tamaño.
Si no pasa nada extraordinario la configuración por defecto de logrotate no causará problemas.

5

Los estoy monitoreando y tampoco parece que se estén pasando de la raya.

No sé si esto está dentro de la normalidad, pero de momento no me parece preocupante:

root@debian:/var/log# ls -lh syslog.3.gz -rw-r----- 1 root adm 5,6M mar 13 00:00 syslog.3.gz root@debian:/var/log# gzip -d syslog.3.gz root@debian:/var/log# ls -lh syslog.3 -rw-r----- 1 root adm 126M mar 13 00:00 syslog.3 root@debian:/var/log#

6

Hoy han sacado un articulo “para principiantes” que no está mal para entender la mecánica detrás de los ficheros syslog y sus amig@s:
[list=*]
]Beginner’s Guide to Syslogs in Linux @ **Linux Handbook Community **/]
[/list]

7

Hacía varias veces que leía posts cómo este:

kcdtv@bob:~$ sudo du -sh /var/log/ 2,8G /var/log/
No tenía el firmware instalado, lo he instalado una vez el adaptador enchufado, he hecho un reboot, y la cosa se ha vuelto así:

432M /var/log/messages 1,3M /var/log/messages.1 88K /var/log/messages.2.gz 116K /var/log/messages.3.gz 276K /var/log/messages.4.gz 432M /var/log/syslog 2,1M /var/log/syslog.1 140K /var/log/syslog.2.gz 188K /var/log/syslog.3.gz 436K /var/log/syslog.4.gz 16K /var/log/user.log 172K /var/log/user.log.1 4,0K /var/log/user.log.2.gz 12K /var/log/user.log.3.gz 16K /var/log/user.log.4.gz
No es lo mismo que tú ya que mi user.log está bajo control.
Total que tengo a esta secuencia que se repite en bucle:

pr 4 15:13:14 bob kernel: 3551.763194] ------------ cut here ]------------ Apr 4 15:13:14 bob kernel: 3551.763196] usb 7-2: BOGUS urb xfer, pipe 1 != type 3 Apr 4 15:13:14 bob kernel: 3551.763222] WARNING: CPU: 0 PID: 5217 at drivers/usb/core/urb.c:502 usb_submit_urb+0x468/0x6b0 [usbcore] Apr 4 15:13:14 bob kernel: 3551.763246] Modules linked in: qrtr ath9k_htc ath9k_common rtl8187 ath9k_hw ath mac80211 snd_hda_codec_realtek libarc4 cfg80211 snd_hda_codec_generic eeprom_93cx6 ledtrig_audio snd_hda_intel coretemp snd_intel_dspcfg rfkill kvm_intel snd_intel_sdw_acpi snd_hda_codec kvm snd_hda_core iTCO_wdt snd_hwdep irqbypass snd_pcm intel_pmc_bxt snd_timer iTCO_vendor_support snd watchdog soundcore sg evdev x38_edac serio_raw pcspkr acpi_cpufreq parport_pc ppdev lp parport fuse configfs ip_tables x_tables autofs4 ext4 crc16 mbcache jbd2 btrfs blake2b_generic zstd_compress raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c crc32c_generic raid1 raid0 multipath linear md_mod nouveau mxm_wmi sd_mod wmi video t10_pi hid_generic crc_t10dif i2c_algo_bit crct10dif_generic drm_ttm_helper ttm usbhid hid drm_kms_helper sr_mod cdrom crct10dif_common cec rc_core ata_generic xhci_pci xhci_hcd drm ahci firewire_ohci r8169 i2c_i801 libahci i2c_smbus pata_jmicron ata_piix Apr 4 15:13:14 bob kernel: 3551.763334] firewire_core realtek mdio_devres lpc_ich crc_itu_t uhci_hcd ehci_pci ehci_hcd usbcore libata libphy scsi_mod scsi_common usb_common button Apr 4 15:13:14 bob kernel: 3551.763349] CPU: 0 PID: 5217 Comm: kworker/0:0 Tainted: G W 5.16.0-6-amd64 #1 Debian 5.16.18-1 Apr 4 15:13:14 bob kernel: 3551.763352] Hardware name: Gigabyte Technology Co., Ltd. X48-DS5/X48-DS5, BIOS F5 03/06/2008 Apr 4 15:13:14 bob kernel: 3551.763354] Workqueue: events request_firmware_work_func Apr 4 15:13:14 bob kernel: 3551.763358] RIP: 0010:usb_submit_urb+0x468/0x6b0 [usbcore] Apr 4 15:13:14 bob kernel: 3551.763380] Code: 10 48 89 54 24 08 44 89 04 24 e8 83 16 3f dd 44 8b 04 24 44 89 f9 48 8b 54 24 08 48 89 c6 48 c7 c7 b0 2f 48 c0 e8 77 4d 69 dd <0f> 0b 44 8b 54 24 10 e9 58 fd ff ff 44 0f b6 c3 41 81 c0 84 03 00 Apr 4 15:13:14 bob kernel: 3551.763383] RSP: 0018:ffffa28203283c98 EFLAGS: 00010282 Apr 4 15:13:14 bob kernel: 3551.763386] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000 Apr 4 15:13:14 bob kernel: 3551.763388] RDX: 0000000000000001 RSI: ffffffff9e34e46e RDI: 00000000ffffffff Apr 4 15:13:14 bob kernel: 3551.763391] RBP: ffff970490a87300 R08: 0000000000000000 R09: ffffa28203283ac8 Apr 4 15:13:14 bob kernel: 3551.763393] R10: ffffa28203283ac0 R11: ffffffff9ead2468 R12: ffff9704901ac800 Apr 4 15:13:14 bob kernel: 3551.763395] R13: 0000000000000002 R14: 0000000000000002 R15: 0000000000000001 Apr 4 15:13:14 bob kernel: 3551.763397] FS: 0000000000000000(0000) GS:ffff970527c00000(0000) knlGS:0000000000000000 Apr 4 15:13:14 bob kernel: 3551.763400] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 Apr 4 15:13:14 bob kernel: 3551.763402] CR2: 00007fc21e1c2948 CR3: 00000001014ac000 CR4: 00000000000006f0 Apr 4 15:13:14 bob kernel: 3551.763405] Call Trace: Apr 4 15:13:14 bob kernel: 3551.763407] <TASK> Apr 4 15:13:14 bob kernel: 3551.763409] hif_usb_send+0x185/0x310 [ath9k_htc] Apr 4 15:13:14 bob kernel: 3551.763417] htc_init+0x14b/0x1a0 [ath9k_htc] Apr 4 15:13:14 bob kernel: 3551.763423] ath9k_init_htc_services.constprop.0+0x2b3/0x2c0 [ath9k_htc] Apr 4 15:13:14 bob kernel: 3551.763430] ? ath9k_htc_txstatus+0x170/0x170 [ath9k_htc] Apr 4 15:13:14 bob kernel: 3551.763437] ? ath9k_rx_tasklet+0x210/0x210 [ath9k_htc] Apr 4 15:13:14 bob kernel: 3551.763444] ath9k_htc_probe_device+0xd8/0x730 [ath9k_htc] Apr 4 15:13:14 bob kernel: 3551.763451] ? ath9k_hif_usb_alloc_urbs+0x457/0x5a0 [ath9k_htc] Apr 4 15:13:14 bob kernel: 3551.763458] ath9k_htc_hw_init+0xd/0x20 [ath9k_htc] Apr 4 15:13:14 bob kernel: 3551.763464] ath9k_hif_usb_firmware_cb+0x95/0x150 [ath9k_htc] Apr 4 15:13:14 bob kernel: 3551.763471] request_firmware_work_func+0x4d/0x90 Apr 4 15:13:14 bob kernel: 3551.763474] process_one_work+0x1e8/0x3c0 Apr 4 15:13:14 bob kernel: 3551.763479] worker_thread+0x50/0x3b0 Apr 4 15:13:14 bob kernel: 3551.763482] ? rescuer_thread+0x390/0x390 Apr 4 15:13:14 bob kernel: 3551.763486] kthread+0x16b/0x190 Apr 4 15:13:14 bob kernel: 3551.763489] ? set_kthread_struct+0x40/0x40 Apr 4 15:13:14 bob kernel: 3551.763492] ret_from_fork+0x22/0x30 Apr 4 15:13:14 bob kernel: 3551.763497] </TASK> Apr 4 15:13:14 bob kernel: 3551.763498] --- end trace dc40fc1918cd6537 ]--- Apr 4 15:13:14 bob kernel: 3551.764141] ath9k_htc 7-2:1.0: ath9k_htc: HTC initialized with 33 credits Apr 4 15:13:14 bob kernel: 3551.764153] ------------ cut here ]------------
La secuencia se repite más de diez veces cada segundo… Y esto durante 2 horas.
Así que por un problema de firmware-driver la cosa se puede poner fea…
Voy a hacer un reboot para probar un par de cosas y vuelvo por aquí

8

Este concretamente no es mi caso, ya que mi dispositivo wifi es Intel, y trabaja bajo iwlwifi.
Tengo un dispositivo usb atheros, pero nunca lo he usado con este portátil. Si acaso desde una máquina virtual, y en momentos muy puntuales que no coinciden en fecha con los problemas que estamos hablando.

Sigo esperando que me vuelva a pasar el tema y ver si como a tí, se me forma algún bucle y me despeja las dudas.

Otra cosa que nada tiene que ver:
Estoy inscrito a este tema para que me notifique por correo si hay alguna respuesta, pero no me las notifica. ?¿ . En otros temas sí me notifica, o me notificaba al menos.

9

Gracias por señalar el error

10

Faltaría más! Gracias a tí por tu trabajo

Me ha vuelto a pasar el problema misterioso, y ya he tirado del hilo un poco más.

La entrada en bucle en los 3 archivos en cuestión (messages, user.log y syslog, los 3 en /var/log/) es la siguiente:

Apr 17 12:27:14 debian /usr/libexec/gdm-x-session[6803]: [00007fc03044e840] vdpau_chroma filter error: video mixer attributes failure: An invalid handle value was provided. Apr 17 12:27:14 debian /usr/libexec/gdm-x-session[6803]: [00007fc03044e840] vdpau_chroma filter error: video mixer rendering failure: An invalid handle value was provided. Apr 17 12:27:14 debian /usr/libexec/gdm-x-session[6803]: [00007fc03044e840] vdpau_chroma filter error: video mixer features failure: An invalid handle value was provided.

Esto provoca cientos de esas líneas por segundo. Es escalofriante ver como los archivos van tomando tamaño.

Viendo esto, voy a ps a buscar el proceso 6803, y resulta que es vlc, que tengo abierto desde hace días con una peli en pausa para seguir viéndola cuando tenga tiempo para ello.
El caso es que lo tengo abierto hace días y es solo hoy cuando entra el bucle que está causando el problema. Ni confirmo ni desmiento que la otra vez que me pasó el tema tuviera abierto vlc. Soy muy dado a tenerlo abierto, pero no recuerdo.
Por otro lado, es un portátil que casi nunca lo reinicio, solo lo cierro, entra en suspensión y hasta que lo vuelvo a abrir. Desde que tengo abierto vlc, lo habré abierto y cerrado unas 15 veces como mínimo y solo hoy y al momento justo de abrirlo, es cuando se ha ocasionado el bucle.
Y por otro lado, como ya comenté, esto me ha pasado en otro sistema debian también, pero éste no solo no tenía vlc instalado, sino que no tenía ni servidor X, ya que se trata de un VPS que tengo en la nube al que solo accedo a través de ssh. En el bucle habla de “gdm-x-session”. Ahora mismo no estoy seguro si gdm tiene que existir aunque no haya ningún sistema de X instalado.

Ya con esa línea del bucle se podría tirar más del hilo pero no es el momento, que es domingo y hay que salir a tomar unas cañas aprovechando que vuelve a verse el sol después de unas semanas de nubes y mas nubes.

Volveré si hay más novedades.

11

Por lo menos este bug está bastante bien documentado, por ejemplo en este hilo I don’t know what is producing the gigabytes of error in syslog
Pausar un vídeo en vlc (quizá pasa con todos los reproductores) y cambiar de usuario o hibernar y despertar el sistema generan GB de basura en los logs.

Es muy extraño. A lo mejor has instalado algo que te ha puesto algo relacionado con gdm. Uso XFCE y tengo solamente a lightdm pero he quitado el “gnome-keyring”, No sé si viene instalado por defecto o si viene tras instalar un segundo navegador web. En todos casos es algo que no tiene xfce y te ponen la versión gnome. Creo que lo puedes quitar (gdm),
Respecto al bug del foro va a tomar algo de tiempo para arreglarlo, nuestro servidor está en Ucrania y bueno, es muy complicado ahora… Me gustaría mucho quedarme pero es desgraciadamente muy probable que no sea posible. Explicaré la situación cuando hayamos tomado una decisión.

12

Esta respuesta tuya sí me la ha notificado al correo. No sé si notifica cuando quiere, o ya está arreglado.

Lo del gdm, lightm, kdm, lxd y demás siempre me han causado más problemas que alegrías, y eso que no soy de cambiar el entorno de escritorio una vez que lo instalo. Ahora mismo uso mate con gdm3, lo probé hace unos años y me gustó bastante. De momento y hasta que se pervierta, seguirá siendo mi entorno favorito. Xfce lo suelo usar en máquinas virtuales por lo liviano, pero como entorno en mi compu de diario no me termina de llenar el ojo.

Gnome-keyring me suena que era eso que te salía de anillo de contraseñas o algo así? si es eso es posiblemente lo más cansino que se ha inventado en mucho tiempo. Es infumable, pero nadie dijo que la seguridad era cómoda. A gnome lo deje atrás hace mucho y esa es precisamente una de las razones.

Muy buena noticia ya saber que es vlc el causante de todo, y que es un bug documentado. No entiendo porqué no lo han arreglado ya que es muy incómodo y para alguien que no tenga soltura en linux creo que es muy fácil que termine formateando y echando pestes.

Queda la duda de què pasó en mi VPS. Si me vuelve a pasar (ahora ya tengo hasta ganas de me pase), tiraré del hilo a ver que me encontramos.

Muchas gracias por todo.

13

Parece que ya está arreglado, a mi también me llegó la notificación de tu respuesta :slight_smile:
Era un problema SMTP debido a las causas externas que comenté, no es porque lo hace cuando quiere, el bug era muy real.

Veo que estás familiarizado con está fantástica herramienta. :smiley: Cómo bien dices tiene su porqué: Si prestamos nuestra computadora a alguien es mejor si no tiene acceso a las contraseñas mail u otras que tienes guardadas. Se entiende que está, pero una vez entendido a que sirve lo podemos quitar sin problemas. Y quitamos muchas dependencias gdm que no nos interesan si usamos lightdm.

Lo que hago para que quede bonito es instalar los iconos y temas de Manjaro o Xubuntu. Últimamente me gusta mucho cómo queda Manjaro, colorido sin ser lo demasiado, me parece bien equilibrado, con una identidad.