Logghantering och felsökning

Loggfiler är till stor hjälp när vi felsöker ett linuxsystem. Linuxkärnan, tjänster som körs i systemet och många applikationer skriver loggfiler. Det finns flera loggfiler i systemet, syslog (systemloggen) är bland de viktigaste att känna till. Loggfilerna lagras i katalogen /var/log/ och där hittar vi ett par loggfiler.

/var/log/auth.log
innehåller information om anslutningar och inloggningar (och inloggningsförsök).
/var/log/dmesg
innehåller meddelanden från linuxkärnan, vi kan visa loggfilen med kommandot dmesg
/var/log/lastlog
innehåller information om vilka användare vi har på systemet och när de senast loggade in (och varifrån). Loggfilen är inte i textformat utan en databas, vi måste använda kommandot lastlog för att visa loggen.
/var/log/syslog
är sysloggen (på en del linuxsystem heter loggfilen /var/log/messages). Numera hamnar det mesta i journald-loggen.

Vi hittar också ett par kataloger i /var/log/. Katalogerna är för specifika tjänster i systemet. apt innehåller loggar från apt-kommandot. Installerar vi webbservern Apache på systemet kommer den logga till katalogen /var/log/apache2/.

Det är en tjänst som heter rsyslogd som hanterar loggfiler i Linux. rsyslogd har en konfigurationsfil som heter /etc/rsyslog.conf, den har också en katalog som heter /etc/rsyslog.d/ där vi kan lägga egen konfiguration till rsyslogd.

rsyslogd kan logga lokalt till systemets disk, eller till en rsyslogd-server över nätverk. Nätverkskommunikationen sker över port 514 med UDP- eller TCP-protokollet. Vi kan också logga både till en nätverksserver och den lokala disken samtidigt.

Scenario: vi får intrång i vår server och någon illasinnad hacker installerar en Bitcoin-miner. För att radera alla spår från intrånget raderar hackern allt i loggfilerna på disken som kan avslöja henne. Om vi hade loggat allt till en nätverksserver hade vi haft spåren kvar i loggfilerna på den servern.

rsyslogd har också ett system för att vi skall kunna fånga upp loggmeddelanden och skicka dem till rätt ställe: facilities och levels:

facilities
auth, authpriv, cron, daemon, ftp, kern, lpr, mail, news, syslog, user, uucp, local0, local1, local2, local3, local4, local5, local6, local7
levels
emerg, alert, crit, err, warning, notice, info, debug

Hur rsyslogd loggar de olika meddelandena specifierar vi i konfigurationen för rsyslogd: /etc/rsyslog.d/50-default.conf:

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

Raderna ovanför visar några exempel på vilka regler vi har i /etc/rsyslog.d/50-default.conf.

Om vi börjar med raden som ser ut så här: *.*;auth,authpriv.none -/var/log/syslog. Här är den första matchningen *.*, vilket betyder att alla facilities med alla levels skall loggas till /var/log/syslog. Vi provar att skapa ett meddelande med kommandot logger:

$ logger -p local4.info "hello local4 info"

Nu kan vi titta i /var/log/syslog om det kom in i loggfilen, vi kan till exempel använda kommandot grep för att söka efter strängar (tecken) i filen:

$ grep "local4" /var/log/syslog
Sep 25 22:41:06 ubuntu jonas: hello local4 info

Vi har en regel som säger cron.* /var/log/cron, allt som går till facility cron oavsett level skall hamna i filen /var/log/cron. För att prova denna måste vi avkommentera raden (ta bort #-tecknet) i filen /etc/rsyslog.d/50-default.conf:

$ sudo vi /etc/rsyslog.d/50-default.conf 
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

#-tecknet betyder att raden är en kommentar och skall ignoreras, det vill vi inte - så vi tar bort tecknet.

Nu startar vi om tjänsten rsyslog för att läsa in konfigurationen:

$ sudo systemctl restart rsyslog

För att skicka ett meddelande till facility cron kan vi använda kommandot logger igen:

$ logger -p cron.info "Hello cron"

Nu skapades filen /var/log/cron.log (om den inte redan fanns) och där kom meddelandet vi skickade med kommandot logger.

$ tail /var/log/cron.log
Sep 25 22:41:06 ubuntu jonas: Hello cron

Så med kommandot logger kan vi ange facility.level med -p. Om vi inte anger något kommer user.notice att användas som standard. Vi kan också tagga våra meddelanden, vilket kan vara bra om vi enkelt vill kunna söka efter dem. Då använder vi flaggan -t så här:

$ logger -p user.info -t JONAS "Hej Jonas"

Nu är det enkelt att hitta alla meddelanden som är taggade med JONAS med hjälp av kommandot grep:

$ grep JONAS /var/log/syslog
Sep 25 22:51:30 ubuntu JONAS: Hej Jonas

Taggning av meddelanden är användbart när vi skriver egna skript och enkelt vill kunna hitta meddelanden från skripten. Ett skript är en serie kommandon som skrivs in i en fil, för att sedan köras tillsammans.

Loggrotatation

Eftersom det skrivs i loggfilerna hela tiden kommer de bli stora och ta mycket plats på disken. Därför använder vi något som kallas logrotate. Logrotate har sin konfigurationsfil i /etc/logrotate.conf och katalogen /etc/logrotate.d/. I konfigurationen ställer vi in hur olika loggfiler skall hanteras av logrotate. Logrotate tar loggfilen och roterar den vilket innebär att den nuvarande loggfilen kan komprimeras och sparas undan i ett komprimerat format. Ofta döps roterade loggfiler till namnet och sedan filändelsen .1, .2 och så vidare. Komprimerar vi loggfilen kommer filnamnet sluta med .gz.

Logrotate körs varje dag med hjälp av schemaläggaren cron, jobbet för logrotate ligger i filen /etc/cron.daily/logrotate . För loggfilen /var/log/syslog ser logrotatejobbet ut så här:

/var/log/syslog
{
    rotate 7 <.>
    daily <.>
    missingok <.>
    notifempty <.> 
    delaycompress <.>
    compress <.> 
    postrotate <.>
        /usr/lib/rsyslog/rsyslog-rotate
    endscript 
}
  • rotate anger hur många gånger en fil skall roteras innan den skall raderas. Här sparar vi de senaste 7 filerna.
  • daily anger att vi skall rotera filerna varje dag
  • missingok om loggfilen saknas ignorerar logrotate den, vi får alltså inget felmeddelande. Motsatsen är nomissingok.
  • notifempty anger att vi inte skall rotera filen om den är tom.
  • delaycompress anger att vi skall komprimera den roterade loggfilen vid nästa tillfälle logrotate körs.
  • compress anger att vi skall komprimera (med gzip) loggfilerna som roteras.
  • postrotate börjar ett block med kommandon som slutar med endscript. De kommandon som står mellan postrotate och endscript kommer köras med kommandotolken /bin/sh när logrotate körs.

lastlog

Med kommandot lastlog kan vi se när användare senast loggade in på systemet. När vi kör lastlog visas alla användarkonton vi har i systemet. Vill vi bara se när en specifik användare loggade in senast använder vi -u användarnamn till kommandot. Så här för användaren root:

$ lastlog -u root

journald

Ubuntu använder uppstarts- och tjänstehanteraren systemd som kommer med logghanteraren journald. Med kommandot journalctl kan vi hämta information från alla loggar i systemet på ett enklare sätt, men detta fungerar bara med de linuxdistributioner som använder systemd. De flesta nya linuxdistributioner använder systemd, eftersom man vill standardisera på systemd. Saknar vi kommandot journalctl på datorn betyder det att vi får läsa loggfilerna manuellt, som vi gick igenom innan.

Det allra enklaste sättet att läsa loggarna med journalctl är att bara skriva kommandot och köra programmet:

$ journalctl

Loggarna visas och vi hoppar upp och ned med hjälp av Page Up/Page Down. Vi avslutar listningen genom att trycka på tangenten q.

Vill vi visa boot-loggen, det vill säga allt som loggats medan systemet startade upp skriver vi:

$ journalctl -b

För att enbart visa meddelanden från linuxkärnan skriver vi:

$ journalctl -k

Vi kan visa meddelanden som är taggade med något specifikt genom att skriva:

$ journalctl -t jonas

Här kommer vi få alla meddelanden som är taggade med jonas (se exemplet med kommandot logger tidigare i det här dokumentet).

I systemd finns något som kallas units, vi kommer till det senare i kursen när vi skall prata om systemd och tjänster. Journalctl kan visa meddelanden från units genom att skriva till exempel (för cron):

$ journalctl -u cron

Med -p kan vi filtrera på vilken prioritet ett meddelande har, för att till exempel se alla felmeddelanden (err) i loggarna skriver vi:

$ journalctl -p err

Det finns åtta olika nivåer av prioritet: emerg, alert, crit, err, warning, notice, info och debug.

För att följa en logg, det vill säga visa alla nya meddelanden som kommer in i loggen använder vi -f:

$ journalctl -f

Vi avbryter genom att hålla nere tangenten CTRL och trycka på c samtidigt.

Vi kan välja från vilket datum och tid och till vilket datum och tid vi vill visa loggmeddelanden. Tiden anger vi i formatet "2016-09-01 07:00:00", om vi inte anger tiden utan bara datum "2016-09-01" kommer tiden 00:00:00 användas. Vi kan också ange tiden som yesterday, today, tomorrow och now. Vi använder flaggorna --since= och --until= för att filtrera på tid, till exempel:

$ journalctl --since="2016-08-01" --until "2016-08-02 16:04:08"
$ journalctl --since="2016-08-01"

Det första kommandot kommer visa alla loggmeddelanden från 2016-08-01 00:00:00 till 2016-08-02 00:00:00. Det andra kommandot kommer visa alla loggmeddelanden från 2016-08-01 00:00:00 till nu.

Vi kan hämta loggar från specifika program och tjänster som körs i systemet. Vi har till exempel en SSH-server igång som standard i Ubuntu. Den tjänsten körs av programmet /usr/sbin/sshd och för att visa loggfilerna från tjänsten skriver vi:

$ journalctl /usr/sbin/sshd

Vi kan också kombinera många av valen till journalctl, till exempel om vi bara vill visa felmeddelanden från tjänsten cron skriver vi:

$ journalctl -p err -u cron