Přístup k logům mailserveru

[_Tomáš_]

Skus pozret Vector od datadog https://vector.dev/ je to dost lightweight, vie to transformaciu a posiela to na rozne outputy (aj na viacere naraz)

vector je zajímavý projekt, hlavně mají skvělé testy všech dalších logovátek, což je velice užitečné i samostatně, ale hlavně ty testy ukazují, že ještě tak lightweight nejsou a ještě jim nějaká práce chybí.

Na produkci takový SW dnes nedoporučuji, obsahuje pořád drobné bugy a není vyladěný, viz třeba memory leak https://github.com/vectordotdev/vector/issues/11863, https://github.com/vectordotdev/vector/issues/11821 nebo leak otevřeného descriptoru https://github.com/vectordotdev/vector/issues/11742. To jsou bugy za poslední měsic ve stabilní verzi.

Věnuji se kritické infrastruktuře v enterprise sféře, v labu tyhle nástroje postupně testujeme, ale je to pořád bídá, spíše nestabilní bída. Je potřeba si ty proklamace na webu ověřovat a udělat si testy. Zatím to nepoužívá tolik firem v produkci, aby se ukázaly všechny nedostatky. S logováním je největší problém, že ho člověk kriticky potřebuje v momentě, kdy se dějí nějaké problémy a pokud ty problémy zároveň sestřelí logovací nástroj, mám na stole skoro katastrofu. Aby nástroj na sbírání logů bral více paměti než aplikace, kterou loguje je již na pováženou, stejně když tyhle nástroje obsahují nějakou formu dynamické alokace a GC (např. filebeat), lze čekat problémy s paměti, pauzováním procesu a nestabilními latencemi.

[Reklama]

[M_D]

Zmiňuje se tu rsyslog a jeho REPL protokol - je šance na něco spolehlivého, pokud potřebuji, aby rsyslog předával svoje data na syslog-ng server? Pokud vím, tak syslog-ng nepodporuje REPL protokol. Takže maximum je tak TCP spojení s lokálním bafrem.

[czechsys]

Tak jsem jeste narazil na systemd-journal-remote resp. systemd-journal-upload a systemd-journal-gatewayd. Ani jsem netusil, ze to existuje...

[czechsys]

Tak jsem jeste narazil na systemd-journal-remote resp. systemd-journal-upload a systemd-journal-gatewayd. Ani jsem netusil, ze to existuje...

Pridam si sem popis, jak to muze fungovat:
https://www.digitalocean.com/community/tutorials/how-to-centralize-logs-with-journald-on-debian-10
https://sematext.com/blog/journald-logging-tutorial/

[czechsys]

Tak zkousim doporucenou rsyslog variantu, ctu z mail.log, zapisuju primo do vzdalene psql databaze, zatez to umi udelat peknou Takze me zatim zaujal restart rsyslogu  :

Kód: [Vybrat]

Apr 20 14:25:31 HOSTNAME kernel: [778771.993811] rsyslogd[57142]: segfault at 1a ip 00007fa80c9ba73c sp 00007fff55af8ee0 error 4 in libc-2.31.so[7fa80c955000+14b000]
Apr 20 14:25:31 mail-11 kernel: [778771.993826] Code: 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 48 83 ec 18 48 8b 05 cd 37 13 00 48 8b 00 48 85 c0 0f 85 81 00 00 00 48 85 ff 74 74 <48> 8b 47 f8 48 8d 77 f0 a8 02 75 38 48 8b 15 29 36 13 00 64 48 83


[Reklama]

[_Tomáš_]

Tak zkousim doporucenou rsyslog variantu, ctu z mail.log, zapisuju primo do vzdalene psql databaze, zatez to umi udelat peknou Takze me zatim zaujal restart rsyslogu  :

Kód: [Vybrat]

Apr 20 14:25:31 HOSTNAME kernel: [778771.993811] rsyslogd[57142]: segfault at 1a ip 00007fa80c9ba73c sp 00007fff55af8ee0 error 4 in libc-2.31.so[7fa80c955000+14b000]
Apr 20 14:25:31 mail-11 kernel: [778771.993826] Code: 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 48 83 ec 18 48 8b 05 cd 37 13 00 48 8b 00 48 85 c0 0f 85 81 00 00 00 48 85 ff 74 74 <48> 8b 47 f8 48 8d 77 f0 a8 02 75 38 48 8b 15 29 36 13 00 64 48 83


jaký máš OS a jakou verzi systemd, verzi rsyslogd?

Tohle je hodně netradiční chyba, error 4 vznikl v libc-2.31.so a ta 4 znamená čtení nemapované paměti. Chytl to traps.h, to vypadá buď na nějaký divný bug nebo nekonzistentní knihovny.

[czechsys]

Tak zkousim doporucenou rsyslog variantu, ctu z mail.log, zapisuju primo do vzdalene psql databaze, zatez to umi udelat peknou Takze me zatim zaujal restart rsyslogu  :

Kód: [Vybrat]

Apr 20 14:25:31 HOSTNAME kernel: [778771.993811] rsyslogd[57142]: segfault at 1a ip 00007fa80c9ba73c sp 00007fff55af8ee0 error 4 in libc-2.31.so[7fa80c955000+14b000]
Apr 20 14:25:31 mail-11 kernel: [778771.993826] Code: 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 48 83 ec 18 48 8b 05 cd 37 13 00 48 8b 00 48 85 c0 0f 85 81 00 00 00 48 85 ff 74 74 <48> 8b 47 f8 48 8d 77 f0 a8 02 75 38 48 8b 15 29 36 13 00 64 48 83


jaký máš OS a jakou verzi systemd, verzi rsyslogd?

Tohle je hodně netradiční chyba, error 4 vznikl v libc-2.31.so a ta 4 znamená čtení nemapované paměti. Chytl to traps.h, to vypadá buď na nějaký divný bug nebo nekonzistentní knihovny.

Debian 11:

Kód: [Vybrat]

systemd:
  Installed: 247.3-7
  Candidate: 247.3-7
  Version table:
     250.4-1~bpo11+1 450
        450 http://ftp.cz.debian.org/debian bullseye-backports/main amd64 Packages
 *** 247.3-7 990
        990 http://ftp.cz.debian.org/debian bullseye/main amd64 Packages
        100 /var/lib/dpkg/status

rsyslog:
  Installed: 8.2102.0-2
  Candidate: 8.2102.0-2
  Version table:
     8.2110.0-4~bpo11+1 450
        450 http://ftp.cz.debian.org/debian bullseye-backports/main amd64 Packages
 *** 8.2102.0-2 990
        990 http://ftp.cz.debian.org/debian bullseye/main amd64 Packages
        100 /var/lib/dpkg/status


Kód: [Vybrat]


Apr 21 10:06:59 mail-10 systemd[1]: Stopping System Logging Service...
Apr 21 10:06:59 mail-10 kernel: [849694.727937] rsyslogd[56410]: segfault at 1a ip 00007f56c2eda73c sp 00007ffe21e8dca0 error 4 in libc-2.31.so[7f56c2e75000+14b000]
Apr 21 10:06:59 mail-10 kernel: [849694.727949] Code: 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 48 83 ec 18 48 8b 05 cd 37 13 00 48 8b 00 48 85 c0 0f 85 81 00 00 00 48 85 ff 74 74 <48> 8b 47 f8 48 8d 77 f0 a8 02 75 38 48 8b 15 29 36 13 00 64 48 83
Apr 21 10:06:59 mail-10 rsyslogd: [origin software="rsyslogd" swVersion="8.2102.0" x-pid="56410" x-info="https://www.rsyslog.com"] exiting on signal 15.
Apr 21 10:06:59 mail-10 systemd[1]: rsyslog.service: Main process exited, code=killed, status=11/SEGV
Apr 21 10:06:59 mail-10 systemd[1]: rsyslog.service: Failed with result 'signal'.
Apr 21 10:06:59 mail-10 systemd[1]: Stopped System Logging Service.
Apr 21 10:06:59 mail-10 systemd[1]: rsyslog.service: Consumed 1min 23.945s CPU time.
Apr 21 10:06:59 mail-10 systemd[1]: Starting System Logging Service...
Apr 21 10:06:59 mail-10 rsyslogd: imuxsock: Acquired UNIX socket '/run/systemd/journal/syslog' (fd 3) from systemd.  [v8.2102.0]
Apr 21 10:06:59 mail-10 rsyslogd: [origin software="rsyslogd" swVersion="8.2102.0" x-pid="177746" x-info="https://www.rsyslog.com"] start
Apr 21 10:06:59 mail-10 systemd[1]: Started System Logging Service.


[_Tomáš_]

díky to vypadá na bug rsyslogu, můžeš ukázat jeho konfiguraci? Hodil by se i core dump a výstup gdb pro stacktrace.

Jak máš nastavené timeouty v systemd, nezabiješ rsyslog příliš brzy?

[czechsys]

Rsyslog a systemd timeouty mam v defaultni podobe z Debian 11. Jedine upravy jsou:

cat /etc/rsyslog.d/*:

Kód: [Vybrat]

##graylog
*.* @@SOMEFQDN:1514;RSYSLOG_SyslogProtocol23Format

##postfix
# Ansible managed
# Transfer postfix logs to postgresql

#Load the imfile input module
module(load="imfile")

#Load the ompgsql output module
module(load="ompgsql")

#Define a template for row insertion of data
template(name="postgresql" type="list" option.sql="on") {
 constant(value="INSERT INTO maillog.maillog (message, timereported) values('")
 property(name="msg")
 constant(value="','")
 property(name="timereported" dateformat="pgsql" date.inUTC="on")
 constant(value="')")
}

ruleset(name="postfix_to_postgresql") {
 action(
  type="ompgsql"
  server="SOMEFQDN"
  user="SOMEUSER"
  pass="SOMEPASS"
  db="maillog"
  template="postgresql"
  queue.filename="postfix-queue"
  queue.maxDiskSpace="2G"
  queue.type="LinkedList"
  queue.timeoutWorkerthreadShutdown="1000"
  queue.timeoutEnqueue="10000"
  queue.workerthreads="5"
  queue.workerthreadMinimumMessages="1000"
  queue.SaveOnShutdown="on"
  action.resumeRetryCount="-1"
  action.resumeInterval="30"
 )
}


input
(
 type="imfile"
 file="/var/log/mail.log"
 tag="postfix"
 ruleset="postfix_to_postgresql"
 PersistStateInterval="10"
)

##postfix package
# Create an additional socket in postfix's chroot in order not to break
# mail logging when rsyslog is restarted.  If the directory is missing,
# rsyslog will silently skip creating the socket.
$AddUnixListenSocket /var/spool/postfix/dev/log

core dumpy a gdb nemam.

[czechsys]

Narazil jsem na problem s predavanim logu do postgresql z rsyslogu.

mail.log:

Kód: [Vybrat]

Jan  6 00:07:50 SOMEHOST postfix/smtp[462873]: 4Np2F15wZMz1YK: to=<SOMEMAIL>, relay=eur.olc.protection.outlook.com[104.47.18.161]:25, delay=0.92, delays=0.1/0/0.79/0.02, dsn=5.7.1, status=bounced (host eur.olc.protection.outlook.com[104.47.18.161] said: 550 5.7.1 Unfortunately, messages from [SOMEIP] weren't sent. Please contact your Internet service provider since part of their network is on our block list (S3150). You can also refer your provider to http://mail.live.com/mail/troubleshooting.aspx#errors. [AM7EUR06FT064.eop-eur06.prod.protection.outlook.com] (in reply to MAIL FROM command))
postgresql.log:

Kód: [Vybrat]

2023-01-06 00:07:50.778 CET [3445242] USER@DB ERROR:  syntax error at or near "t" at character 390
2023-01-06 00:07:50.778 CET [3445242] USER@DB STATEMENT:  INSERT INTO SOMETABLE (message, timereported) values('Jan  6 00:07:50 SOMEHOST postfix/smtp[462873]: 4Np2F15wZMz1YK: to=<SOMEUSER>, relay=eur.olc.protection.outlook.com[104.47.18.161]:25, delay=0.92, delays=0.1/0/0.79/0.02, dsn=5.7.1, status=bounced (host eur.olc.protection.outlook.com[104.47.18.161] said: 550 5.7.1 Unfortunately, messages from [SOMEIP] weren\'t sent. Please contact your Internet service provider since part of their network is on our block list (S3150). You can also refer your provider to http://mail.live.com/mail/troubleshooting.aspx#errors. [AM7EUR06FT064.eop-eur06.prod.protection.outlook.com] (in reply to MAIL FROM command))','2023-01-05 23:07:50')

Predpokladam, ze je to zpusobeno

Kód: [Vybrat]

weren't ktere je v sql dotazu jako

Kód: [Vybrat]

weren\t.

Jaka je nejlepsi cesta? Funkce na strane postgre? Nejaka extra uprava (jaka?) na strane rsyslogu (viz ta ##postfix konfigurace o prispevek vyse)?

[_Jenda]

To jako opravdu lepí do SQL dotazu escapovaný uživatelský vstup? SQL injection v logách poštovního serveru v roce 2023?!

[tecka]

Narazil jsem na problem s predavanim logu do postgresql z rsyslogu.

Od Pg 9.1 je escapování zpětným lomítkem vypnuté. V tom template použij values(E' nebo option.stdsql.

[czechsys]

Narazil jsem na problem s predavanim logu do postgresql z rsyslogu.

Od Pg 9.1 je escapování zpětným lomítkem vypnuté. V tom template použij values(E' nebo option.stdsql.

Dik, vyzkousim option.stdsql. Se zdvojovanim ' nemam zkusenosti, tak jsem pouzil to defaultni option.sql.