logger и пересылка логов для сервисом, которые не умеют слать логи в syslog.

В прекрасном и идеально мире каждый должен заниматься своим делом.
В частности я убежден что когда логи пишет логи самостоятельно — это неправильно. Более того совсем неправильно если приложение не умеет отправлять логи в syslog (через сокет или сеть). Сейчас пришел systemd и логи вообще можно писать в STDIN и не париться.

Например apache ну умеет писать логи в syslog. Но он умеет писать их в пайп. Пишем в конфиге

	ErrorLog "| /usr/bin/logger --tag example.org_apache-error -n 192.168.5.254"
	CustomLog "| /usr/bin/logger --tag example.org_apache -n 192.168.5.254" combined

и логи полетели на syslog-сервер 192.168.5.254. Или не указывает «-n» и логи уходят в локальный syslog.

Но сегодня наткнулся на debian7 (да древность, да нужно выкидывать уже, но тем не менее на данный момент оно еще поддерживается).
Запускаю «echo 123 | /usr/bin/logger -n 192.168.5.254» и на сервер ничего не доходит.
Проверил связанность, настройки фаерволов с обоих сторон, позапускал tcpdump, поперебирал разные варианты настроек и ничего. Взял strace:

	[root@d314 /var/log]# date | strace -f /usr/bin/logger  -n 192.168.5.254  
execve("/usr/bin/logger", ["/usr/bin/logger", "-n", "192.168.5.254"], [/* 22 vars */]) = 0
brk(0)                                  = 0xe26000
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ff32ee1f000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY)      = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=26469, ...}) = 0
mmap(NULL, 26469, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7ff32ee18000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\300\357\1\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1607696, ...}) = 0
mmap(NULL, 3721272, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7ff32e875000
mprotect(0x7ff32e9f9000, 2093056, PROT_NONE) = 0
mmap(0x7ff32ebf8000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x183000) = 0x7ff32ebf8000
mmap(0x7ff32ebfd000, 18488, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7ff32ebfd000
close(3)                                = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ff32ee17000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ff32ee16000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ff32ee15000
arch_prctl(ARCH_SET_FS, 0x7ff32ee16700) = 0
mprotect(0x7ff32ebf8000, 16384, PROT_READ) = 0
mprotect(0x603000, 4096, PROT_READ)     = 0
mprotect(0x7ff32ee21000, 4096, PROT_READ) = 0
munmap(0x7ff32ee18000, 26469)           = 0
brk(0)                                  = 0xe26000
brk(0xe47000)                           = 0xe47000
open("/usr/lib/locale/locale-archive", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=2709120, ...}) = 0
mmap(NULL, 2709120, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7ff32e5df000
close(3)                                = 0
getpid()                                = 2530
open("/etc/resolv.conf", O_RDONLY)      = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=19, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ff32ee1e000
read(3, "nameserver 8.8.8.8\n", 4096)   = 19
read(3, "", 4096)                       = 0
close(3)                                = 0
munmap(0x7ff32ee1e000, 4096)            = 0
uname({sys="Linux", node="d314", ...})  = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 3
connect(3, {sa_family=AF_INET, sin_port=htons(514), sin_addr=inet_addr("192.168.5.254")}, 16) = 0
close(1)                                = 0
fstat(0, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ff32ee1e000
read(0, "\320\241\321\200\320\264 \320\244\320\265\320\262 21 10:18:33 MSK 20"..., 4096) = 35
time([1519197513])                      = 1519197513
open("/etc/localtime", O_RDONLY)        = 1
fstat(1, {st_mode=S_IFREG|0644, st_size=1470, ...}) = 0
fstat(1, {st_mode=S_IFREG|0644, st_size=1470, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ff32ee1d000
read(1, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\r\0\0\0\r\0\0\0\0"..., 4096) = 1470
lseek(1, -903, SEEK_CUR)                = 567
read(1, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\16\0\0\0\16\0\0\0\0"..., 4096) = 903
close(1)                                = 0
munmap(0x7ff32ee1d000, 4096)            = 0
socket(PF_FILE, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 1
connect(1, {sa_family=AF_FILE, path="/dev/log"}, 110) = 0
sendto(1, "<13>Feb 21 10:18:33 logger: \320\241\321\200"..., 62, MSG_NOSIGNAL, NULL, 0) = 62
read(0, "", 4096)                       = 0
close(1)                                = 0
exit_group(0)                           = ?
[root@d314 /var/log]#  

Сокет до 192.168.5.254 открывается (строки 43-44), но почему-то UDP, в хелпе (и мане сказанно):

[root@d314 /var/log]# logger -h 

Usage:
 logger [options] [message]

Options:
 -d, --udp             use UDP (TCP is default)
 -i, --id              log the process ID too
 -f, --file <file>     log the contents of this file
 -h, --help            display this help text and exit
 -n, --server <name>   write to this remote syslog server
 -P, --port <number>   use this UDP port
 -p, --priority <prio> mark given message with this priority
 -s, --stderr          output message to standard error as well
 -t, --tag <tag>       mark every line with this tag
 -u, --socket <socket> write to this Unix socket
 -V, --version         output version information and exit

[root@d314 /var/log]# 

То есть должен быть tcp по умолчанию (опции «переключи на tcp» нет, только обратная ей «переключи на udp»), но у нас UDP (SOCK_DGRAM).
Но что самое интересное — в сокет даже не пытается ничего отправляться. Тупо открыли сокет до указанного сервера, потом открываем до локального syslog-а и отправляем в локальный.

Ладно, хер с ним. Беру и пишу свою реализацию logger’а (писать багрепорты на ОС, которую через месяц выкинул с поддержки смысла не вижу):

#!/usr/bin/env perl

use warnings;
use strict;
use Net::Syslog;

my $syslog=new Net::Syslog(Facility => 'local4',SyslogHost => '192.168.5.254', Name => 'tag' );

while(42){
	open(FIFO, "< /var/log/fifo") || die("Err opening a fifo: $!");

	while (42) {
		my $line = <FIFO>;
		if ( ! defined($line) ) {
			sleep 1;
			next;
		}
		$syslog->send( $line , Priority => 'info');
	}
}

Код конечто не идеальный, но хочется использовать именновой пайп (что бы не дергать лишний раз диск). Если из пайпа перестать выбирать данные, то тот, кто их туда пишет просто залипнет в состоянии D. Поэтому 2 бесконечных цикла в коде, а третий во врапере на баше был. Проверил, перероверирил и вот это все, убедился что само запуститься если там oom прибъет или еще почему-либо упадет. Захожу в мускуль говорю «вкдючай slow-лог и пиши вон в тот пайп, хуй там был.

2018-02-21 06:25:03 10912 [ERROR] Could not open /var/log/mysql/mysql-slow.log for logging (error 11). Turning logging off for the whole duration of the MySQL server process. To turn it on again: fix the cause, shutdown the MySQL server and restart it.

И только гугл нам подсказывает что ни я первый и единственный вариант — в новых версиях мускуля есть штатный механизм записи в syslog.

Пиздец в общем. Такую простую задачу вот так эпично сьфейлить.

You can leave a response, or trackback from your own site.

Leave a Reply

Subscribe to RSS Feed