Routingänderungen mit Linux protokollieren
"Die Kunden beschweren sich über Verbindungsabbrüche, kannst Du bitte mal diese Leitung überprüfen."
So oder so ähnlich höre ich es immer wieder von Kollegen. Die Leitung ist fehlerfrei, Überlast ist auch nicht zu entdecken, also scheint alles in Ordnung. Wenn eben nicht diese Verbindungsabbrüche wären, über die sich die Kunden beklagen.
Da wir ein relativ komplexes Netz haben, setzen wir auch Routingprotokolle ein, um die Netzpfade allen Gateways bekannt zu machen. Da liegt dann auch nahe, dass vielleicht eine Routingänderung für die Verbindungsabbrüche verantwortlich war. Aber wie kriege ich das raus? Und wenn sich die Routen geändert haben, passen diese Änderungen dann auch zu den beschriebenen Beeinträchtigungen?
Das beste wäre ein Protokoll aller Routingänderungen zu führen, das mir im Bedarfsfall hilft, einen Fehler beim Routing auszuschließen oder einzugrenzen.
Hier hilft mir die Programmsuite quagga weiter, die zum einen Dämonen für Routingprotokolle enthält und zum anderen mit zebra die Kernel-Routingtabelle überwachen und manipulieren kann.
Zebra kann die Routingänderungen auch an Syslog weiter melden. Dafür brauche ich nur die folgenden beiden Einträge in der Datei zebra.conf:
log syslog
debug zebra rib
Sobald diese aktiv sind, finde ich im Systemlog Einträge wie die folgenden für entfernte Routen:
Aug 26 10:16:43 netinfo1 zebra[1651]: rib_delnode: 10.10.0.0/16: rn 0xb7831b50, rib 0xb7833ec8, removing
Aug 26 10:16:43 netinfo1 zebra[1651]: rib_process: 10.10.0.0/16: Deleting fib 0xb7833ec8, rn 0xb7831b50
Aug 26 10:16:43 netinfo1 zebra[1651]: rib_process: 10.10.0.0/16: Removing existing route, fib 0xb7833ec8
Und solche bei hinzugefügte Routen:
Aug 26 10:16:47 netinfo1 zebra[17035]: rib_add_ipv4_multipath: called rib_addnode (0xb785db48, 0xb785e4d8) on new RIB entry
Aug 26 10:16:47 netinfo1 zebra[17035]: rib_add_ipv4_multipath: dump complete
Aug 26 10:16:47 netinfo1 zebra[17035]: rib_add_ipv4_multipath: dumping RIB entry 0xb785e4d8 for 10.147.0.0/16
Aug 26 10:16:47 netinfo1 zebra[17035]: rib_add_ipv4_multipath: metric == 10, distance == 110, flags == 0, status == 0
Aug 26 10:16:47 netinfo1 zebra[17035]: rib_add_ipv4_multipath: nexthop_num == 1, nexthop_active_num == 0, nexthop_fib_num == 0
Aug 26 10:16:47 netinfo1 zebra[17035]: rib_add_ipv4_multipath: NH 0.0.0.0 (0.0.0.0) with flags
Aug 26 10:16:47 netinfo1 zebra[17035]: rib_link: 10.147.0.0/16: new head, rn_status copied over
Aug 26 10:16:47 netinfo1 zebra[17035]: rib_link: 10.147.0.0/16: rn 0xb785db48, rib 0xb785e4d8
Aug 26 10:16:47 netinfo1 zebra[17035]: rib_process: 0.0.0.0/0: Adding route, select 0xb785e200
Aug 26 10:16:47 netinfo1 zebra[17035]: rib_process: 10.0.0.1/32: Adding route, select 0xb785d778
Aug 26 10:16:47 netinfo1 zebra[17035]: rib_process: 10.147.0.0/16: Adding route, select 0xb785db88
Aug 26 10:16:47 netinfo1 zebra[17035]: rib_process: 10.147.0.0/16: Updating existing route, select 0xb785db88, fib 0xb785db88
Aug 26 10:16:47 netinfo1 zebra[17035]: rib_process: 10.147.0.0/16: Updating existing route, select 0xb785db88, fib 0xb785db88
Diese Einträge sind schon sehr informativ, aber für einen schnellen Blick zu unübersichtlich. Hier kommt mir wieder Perl zu Hilfe. Ich nehme mein Standardgerüst für die Syslog-Auswertung und ergänze es um die folgenden Zeilen:
my $wanted = 'zebra';
my $re_ip4prefix = qr|(\d{1,3}(?:\.\d{1,3}){3}/\d{1,2})|;
my $re_ip6prefix = qr|([0-9a-f:]+/\d+)|;
sub process_line {
my ($time,$host,$name,$pid,$text) = @_;
if ($text =~ /^rib_process: $re_ip4prefix: Removing existing route/) {
print "$time $host $name: remove $1\n";
}
elsif ($text =~ /^rib_process: $re_ip6prefix: Removing existing route/) {
print "$time $host $name: remove $1\n";
}
elsif ($text =~ /^rib_process: $re_ip4prefix: Adding route, (.+)$/) {
print "$time $host $name: add $1\n";
}
elsif ($text =~ /^rib_process: $re_ip6prefix: Adding route, (.+)$/) {
print "$time $host $name: add $1\n";
}
}
Mit diesem Script erhalte ich dann diese Ausgabe:
Aug 26 10:16:43 netinfo1 zebra: remove 10.10.0.0/16
Aug 26 10:16:47 netinfo1 zebra: add 0.0.0.0/0
Aug 26 10:16:47 netinfo1 zebra: add 10.0.0.1/32
Aug 26 10:16:47 netinfo1 zebra: add 10.147.0.0/16
Alternativ kann ich die Änderungen auch mit Perl DBI in eine Datenbank schreiben und diese zur Auswertung heranziehen. Damit wäre es dann auch möglich, die Routingänderungen interaktiv, zum Beispiel über eine Webseite, abzufragen.
Bei den letzten Verbindungsabbrüchen stellte sich übrigens heraus, dass diese durch Routingänderungen verursacht wurden. Weitere Analysen der Logs ergaben Probleme beim OSPF-Protokoll. Wie ich diese untersuche, erzähle ich ein anderes mal.
Posted 2013-09-21