W poprzednim moim artykule dostępnym tutaj pokazaliśmy podstawy pracy z plikami w języku Python. Stwórzmy teraz proste narzędzie do analizy logów zapisywanych w formacie syslog. Celem naszego skryptu jest reagowanie, gdy ktoś przejdzie do trybu konfiguracji routera działającego pod kontrolą systemu IOS XE. Użyję tego przykładu, gdyż jest on mi najbliższy natomiast jeżeli zrozumiesz całą ideę i sposób kodowania w prosty sposób dopasujesz kod do własnych wymagań i analizy logów, która jest ci potrzebna w codziennej pracy.

Konfiguracja Cisco

Aby ułatwić Ci testowanie rozwiązania w domowym labie poniżej konfiguracja wysyłania logów z mojego routera:

service timestamps log datetime msec localtime show-timezone
hostname C8000v
clock timezone CET 1 0
clock summer-time CEST recurring last Sun Mar 2:00 last Sun Oct 3:00
logging trap debugging
logging origin-id hostname
logging host 172.20.8.11
event manager applet LOG_ALL_COMMANDS
 event cli pattern ".*" sync no skip no
 action 1.0 syslog msg "Command Executed: $_cli_msg"

Event manager ma na celu włączenie logowania wszystkich wydanych na urządzeniu komend. Poniżej przykład z logów, które zostały wysłane do zewnętrznego serwera.

May 31 20:27:26 172.20.1.51 239: C8000v: *May 31 20:27:24.519 CEST: %SSH-5-SSH2_SESSION: SSH2 Session request from 192.168.1.2 (tty = 0) using crypto cipher 'chacha20-poly1305@openssh.com', hmac 'hmac-sha2-512-etm@openssh.com' Succeeded
May 31 20:27:29 172.20.1.51 240: C8000v: *May 31 20:27:27.470 CEST: %SEC_LOGIN-5-LOGIN_SUCCESS: Login Success [user: ansible] [Source: 192.168.1.2] [localport: 22] at 20:27:27 CEST Fri May 31 2024
May 31 20:27:29 172.20.1.51 241: C8000v: *May 31 20:27:27.470 CEST: %SSH-5-SSH2_USERAUTH: User 'ansible' authentication for SSH2 Session from 192.168.1.2 (tty = 0) using crypto cipher 'chacha20-poly1305@openssh.com', hmac 'hmac-sha2-512-etm@openssh.com' Succeeded
May 31 20:27:38 172.20.1.51 242: C8000v: *May 31 18:27:34.949: %HA_EM-6-LOG: LOG_ALL_COMMANDS: Command Executed: show logging
May 31 20:27:57 172.20.1.51 243: C8000v: *May 31 18:27:53.711: %HA_EM-6-LOG: LOG_ALL_COMMANDS: Command Executed: show ip bgp
May 31 20:27:57 172.20.1.51 244: C8000v: *May 31 18:27:56.442: %HA_EM-6-LOG: LOG_ALL_COMMANDS: Command Executed: configure terminal
May 31 20:28:01 172.20.1.51 245: C8000v: *May 31 20:27:58.483 CEST: %SYS-5-CONFIG_I: Configured from console by ansible on vty0 (192.168.1.2)
May 31 20:28:01 172.20.1.51 246: C8000v: *May 31 18:27:58.486: %HA_EM-6-LOG: LOG_ALL_COMMANDS: Command Executed: exit

Na tych logach będziemy teraz pracowali. Znajdziesz je w pliku logi.txt dołączonego do tego artykułu.

Syslog

Syslog, czyli system logowania zdarzeń, jest jednym z najważniejszych standardów wykorzystywanych w zarządzaniu infrastrukturą IT. Jest to protokół komunikacyjny, który został opracowany w celu umożliwienia centralizacji logów generowanych przez różnorodne urządzenia i aplikacje w sieci. Dzięki syslog, administratorzy mogą efektywnie monitorować stan systemów, identyfikować problemy oraz podejmować działania naprawcze na podstawie szczegółowych zapisów zdarzeń. Choć syslog powoli jest wypierany przez mechanizmy oparte na telemetrii, w wielu sytuacjach nadal pozostaje niezastąpiony i jest szeroko stosowany.

Standard syslog został zaprojektowany z myślą o prostocie i skalowalności. W jego architekturze wyróżniamy trzy główne komponenty: nadawcę (source), odbiorcę (collector) oraz przetwarzanie (processing). Nadawcami mogą być urządzenia sieciowe, serwery, a nawet aplikacje, które generują komunikaty logów. Odbiorcą jest zazwyczaj centralny serwer logów, który zbiera i przechowuje te komunikaty, umożliwiając ich analizę i archiwizację. Proces przetwarzania obejmuje filtrowanie, formatowanie i analizę komunikatów w celu uzyskania wartościowych informacji.

Syslog operuje na określonym formacie wiadomości, który składa się z trzech głównych części: nagłówka, PRI (priority) oraz wiadomości. Nagłówek zawiera informacje o dacie i godzinie zdarzenia, nazwie hosta oraz identyfikatorze procesu. PRI oznacza priorytet wiadomości, który określa jej ważność oraz źródło. Wiadomość zawiera szczegółowy opis zdarzenia, co pozwala na dokładną identyfikację problemów i zdarzeń w systemie.

Skrypt Python

Nasz skrypt w języku Python został stworzony w celu przeszukiwania pliku logów logi.txt w poszukiwaniu konkretnej frazy: „%HA_EM-6-LOG: LOG_ALL_COMMANDS: Command Executed: configure terminal”. Ta fraza wskazuje na przejście użytkownika w tryb konfiguracji i jest generowana przez skonfigurowany przez nas mechanizm Event Manager. Jeśli fraza zostanie znaleziona, skrypt wyświetli na konsoli szczegółową informację zawierającą datę, godzinę oraz nazwę urządzenia.

import re

# Otwieramy plik do odczytu
with open('logi.txt', 'r') as file:
    logs = file.readlines()

# Definiujemy frazę do wyszukania
search_phrase = "%HA_EM-6-LOG: LOG_ALL_COMMANDS: Command Executed: configure terminal"

# Przetwarzamy każdy wiersz logów
for log in logs:
    if search_phrase in log:
        # Wyciągamy datę i godzinę z sysloga
        date_time_syslog_match = re.search(r'(\w+ \d+ \d+:\d+:\d+)', log)
        date_time_syslog = date_time_syslog_match.group(1) if date_time_syslog_match else "nieznana data i godzina"
        
        # Wyciągamy nazwę urządzenia
        device_info_match = re.search(r'\d+\.\d+\.\d+\.\d+ \d+: (\w+):', log)
        device_info = device_info_match.group(1) if device_info_match else "nieznane urządzenie"
        
        # Wyciągamy tylko godzinę z sysloga (ponieważ chcemy tylko godzinę dla ostatecznego komunikatu)
        time_syslog = date_time_syslog.split()[2]
        
        # Wyciągamy tylko datę z sysloga (ponieważ chcemy tylko datę dla ostatecznego komunikatu)
        date_syslog = " ".join(date_time_syslog.split()[:2])
        
        # Wyświetlamy informacje na konsoli
        print(f"O godzinie {time_syslog} dnia {date_syslog} na urządzeniu {device_info} użytkownik przeszedł w tryb konfiguracji.")

Na naszych danych testowych wywołanie skryptu zwróci następujący output:

(py311-venv) $ python3 skrypt.py 
O godzinie 20:27:57 dnia May 31 na urządzeniu C8000v użytkownik przeszedł w tryb konfiguracji.

Skrypt korzysta z systemowej biblioteki do wyrażeń regularnych (re). Biblioteka re w Pythonie jest podstawowym narzędziem do pracy z wyrażeniami regularnymi. Wyrażenia regularne są potężnym językiem formalnym do wyszukiwania i manipulacji tekstu, umożliwiającym dopasowywanie wzorców w ciągu znaków. Biblioteka re pozwala na wykorzystanie tych wzorców do przeszukiwania, dopasowywania, zamiany i rozdzielania tekstu w elastyczny i efektywny sposób.

Wyrażenia regularne mają specyficzną składnię, która pozwala na tworzenie zaawansowanych wzorców dopasowań:

• Metaznaki: Znaki o specjalnym znaczeniu, takie jak . (dowolny znak), ^ (początek ciągu), $ (koniec ciągu), * (zero lub więcej wystąpień), + (jedno lub więcej wystąpień), ? (zero lub jedno wystąpienie).
• Znaki ucieczki: Używanie \ przed metaznakiem, aby dopasować dosłownie (np. \. dopasowuje kropkę).
• Grupy przechwytywania: Nawiasy () tworzą grupy, które mogą być używane do przechwytywania części dopasowania.
• Znaki klasowe: Nawiasy kwadratowe [] definiują zestawy znaków do dopasowania (np. [a-z] dopasowuje każdy mały znak alfabetu).

W naszym skrypcie wykorzystujemy bibliotekę re do wyodrębnienia kluczowych informacji z każdego z wpisów. Przeanalizujmy je:

date_time_syslog_match = re.search(r'(\w+ \d+ \d+:\d+:\d+)', log)

Wyrażenie r'(\w+ \d+ \d+:\d+:\d+)’ dopasowuje datę i godzinę w formacie „May 31 20:27:57”. \w+ odpowiada nazwie miesiąca (np. „May”), \d+ odpowiada dniowi miesiąca (np. „31”), \d+:\d+:\d+ odpowiada godzinie w formacie HH:MM (np. „20:27:57”). Całe wyrażenie jest otoczone nawiasami, co tworzy grupę przechwytywania, dzięki czemu możemy uzyskać wyodrębniony tekst.

device_info_match = re.search(r'\d+\.\d+\.\d+\.\d+ \d+: (\w+):', log)

Wyrażenie r’\d+\.\d+\.\d+\.\d+ \d+: (\w+):’ dopasowuje adres IP i numer logu, a następnie przechwytywanie nazwy urządzenia. \d+\.\d+\.\d+\.\d+ odpowiada adresowi IP (np. „172.20.1.51”), \d+: odpowiada numerowi wpisu w logu (np. „243:”), (\w+) odpowiada nazwie urządzenia (np. „C8000v”) i jest grupą przechwytywania. Całość jest zakończona dwukropkiem, aby zapewnić dokładne dopasowanie.

Mając wyekstraktowane te dane za pomocą wyrażeń regularnych operujemy już na listach. Dlatego tutaj konieczna jest znajomość operacji na zmiennych.

time_syslog = date_time_syslog.split()[2]

Metoda split() dzieli wyodrębnioną datę i godzinę na części, a [2] wybiera trzeci element, który jest godziną (np. „20:27:57”).

date_syslog = " ".join(date_time_syslog.split()[:2])

Ponownie używamy split(), który dzieli wyodrębnioną datę i godzinę na części, a [:2] wybiera pierwsze dwa elementy, które są miesiącem i dniem (np. „May 31”), natomiast join() łączy te elementy z powrotem w jednej string.

Operatory warunkowe

W skrypcie, który analizuje logi syslog, użyta została konstrukcja warunkowa zwana operatorem warunkowym (ang. conditional expression), który w Pythonie ma postać X if C else Y. Jest to sposób na skondensowane zapisanie prostego warunku. Zastosowanie tej konstrukcji pozwala na przypisanie wartości do zmiennej w zależności od spełnienia określonego warunku. Konstrukcje warunkowe, takie jak operator warunkowy, są kluczowym narzędziem w Pythonie, umożliwiającym bardziej zwięzły i czytelny kod, szczególnie w przypadku prostych warunków, jak w naszym skrypcie do analizy logów syslogowych.

date_time_syslog = date_time_syslog_match.group(1) if date_time_syslog_match else "nieznana data i godzina"

Zmienna date_time_syslog_match zawiera wynik dopasowania wyrażenia regularnego re.search(r'(\w+ \d+ \d+:\d+:\d+)’, log). Jeśli re.search znajdzie dopasowanie, date_time_syslog_match będzie obiektem Match. Jeśli nie znajdzie to będzie type None. Następnie warunek if date_time_syslog_match sprawdza, czy date_time_syslog_match nie jest None. Jeśli warunek jest prawdziwy (czyli istnieje dopasowanie), wykonuje się część po lewej stronie if: date_time_syslog_match.group(1). Jeśli warunek jest fałszywy (czyli brak dopasowania), wykonuje się część po prawej stronie else: „nieznana data i godzina”.  Wartość z warunku zostanie przypisane do zmiennej date_time_syslog.

W naszym skrypcie do analizy logów, ta konstrukcja warunkowa pozwala na szybkie przypisanie odpowiednich wartości zmiennym bez potrzeby pisania rozbudowanych instrukcji warunkowych. Zapewnia, że nawet w przypadku braku dopasowania (braku daty i godziny w logu), skrypt będzie kontynuował działanie, przypisując zmiennej wartość domyślną („nieznana data i godzina”), co jest bardziej przyjazne użytkownikowi niż błąd wykonania.

Logi – wyjaśnienie rozbieżności w datach

W logach syslogowych często pojawiają się różnice w datach i godzinach wynikające z różnych stref czasowych lub opóźnień w rejestrowaniu zdarzeń. Syslog rejestruje czas na podstawie ustawień lokalnych serwera syslogowego, podczas gdy urządzenie może mieć własne ustawienia czasu, co prowadzi do niewielkich różnic w zapisie czasu. Analizując logi syslogowe, należy uwzględniać te różnice, aby prawidłowo interpretować zdarzenia i odpowiednio reagować na zmiany w infrastrukturze sieciowej. Stąd w naszych logach rozbieżność dat w jednym wpisie. Świadomie wybrałem korzystanie z daty zapisu do dziennika, czyli nie daty podawanej przez urządzenie.

Zadanie domowe

Jako zadanie domowe rozbuduj skrypt w taki sposób, aby wyświetlał na ekranie dane na każdym z etapów przetwarzania wyrażeń regularnych. Zmodyfikuj też skrypt w taki sposób, aby zamiast daty systemowej zapisania logów wyświetlał datę zwróconą przez urządzenie.