Skip to content

Commit c0646d1

Browse files
troglobittroglobit
committed
test: new test to verify ospf debug logging
Signed-off-by: Joachim Wiberg <troglobit@gmail.com>
1 parent 7edc3c1 commit c0646d1

File tree

5 files changed

+297
-0
lines changed

5 files changed

+297
-0
lines changed

‎test/case/routing/Readme.adoc‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -9,6 +9,7 @@ Tests verifying standard routing protocols and configuration:
99
- OSPF multi-area configuration and inter-area routing
1010
- OSPF with BFD (Bidirectional Forwarding Detection)
1111
- OSPF default route advertisement and propagation
12+
- OSPF debug logging configuration and verification
1213
- Route preference handling for OSPF routes
1314
- Route preference handling for DHCP-learned routes
1415
- Administrative distance configuration (route preference 255)
@@ -37,6 +38,10 @@ include::ospf_default_route_advertise/Readme.adoc[]
3738

3839
<<<
3940

41+
include::ospf_debug/Readme.adoc[]
42+
43+
<<<
44+
4045
include::route_pref_ospf/Readme.adoc[]
4146

4247
<<<

‎test/case/routing/all.yaml‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -25,3 +25,6 @@
2525

2626
- name: OSPF Default route advertise
2727
case: ospf_default_route_advertise/test.py
28+
29+
- name: OSPF Debug Logging
30+
case: ospf_debug/test.py

‎test/case/routing/ospf_debug/Readme.adoc‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1 @@
1+
test.adoc

‎test/case/routing/ospf_debug/test.py‎

Lines changed: 256 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,256 @@
1+
#!/usr/bin/env python3
2+
"""OSPF Debug Logging
3+
4+
Verifies OSPF debug logging by configuring two routers (R1 and R2) with
5+
OSPF on their interconnecting link. The test enables specific OSPF debug
6+
categories and verifies that appropriate debug messages appear in
7+
/var/log/debug.
8+
9+
This test specifically validates:
10+
- Debug messages appear when debug options are enabled
11+
- No excessive debug messages when debug options are disabled
12+
- Individual categories (ism, nsm, packet) can be toggled independently
13+
14+
"""
15+
16+
import infamy
17+
import infamy.route as route
18+
from infamy.util import until, parallel
19+
20+
21+
def verify_debug_messages_present(ssh, logfile):
22+
"""Verify OSPF debug messages are present in the log file."""
23+
def check_log():
24+
rc = ssh.runsh(f"cat /var/log/{logfile} 2>/dev/null")
25+
log_content = rc.stdout if rc.returncode == 0 else ""
26+
27+
# Check for ISM (Interface State Machine) debug messages
28+
# Example: "ISM[e5:192.168.50.1]: Down (InterfaceUp)"
29+
has_ism = "ISM[" in log_content
30+
31+
# Check for NSM (Neighbor State Machine) debug messages
32+
# Example: "NSM[e5:192.168.50.1:192.168.200.1:default]: Down (HelloReceived)"
33+
has_nsm = "NSM[" in log_content
34+
35+
# Check for packet debug messages - look for Hello packet details
36+
# Example: "Type 1 (Hello)" or "ospf_recv_packet"
37+
has_packet = "ospf_recv_packet" in log_content or "Type 1 (Hello)" in log_content
38+
39+
return has_ism and has_nsm and has_packet
40+
41+
return check_log
42+
43+
44+
def verify_debug_messages_minimal(ssh, logfile):
45+
"""Verify OSPF debug messages are minimal/absent in the log file."""
46+
def check_log():
47+
rc = ssh.runsh(f"cat /var/log/{logfile} 2>/dev/null")
48+
log_content = rc.stdout if rc.returncode == 0 else ""
49+
50+
# When debug is disabled, we shouldn't see verbose debug messages
51+
lines = log_content.split('\n')
52+
# Look for ISM, NSM, and detailed packet dumps
53+
ospf_debug_lines = [l for l in lines if "ISM[" in l or "NSM[" in l or "ospf_recv_packet" in l or "Type 1 (Hello)" in l]
54+
55+
# Allow some residual messages but not many
56+
return len(ospf_debug_lines) <= 10
57+
58+
return check_log
59+
60+
61+
def config_target1(target, link, enable_debug=False):
62+
ospf_config = {
63+
"type": "infix-routing:ospfv2",
64+
"name": "default",
65+
"ospf": {
66+
"redistribute": {
67+
"redistribute": [{
68+
"protocol": "connected"
69+
}]
70+
},
71+
"areas": {
72+
"area": [{
73+
"area-id": "0.0.0.0",
74+
"interfaces": {
75+
"interface": [{
76+
"enabled": True,
77+
"name": link,
78+
"hello-interval": 1,
79+
"dead-interval": 3
80+
}]
81+
},
82+
}]
83+
}
84+
}
85+
}
86+
87+
if enable_debug:
88+
ospf_config["ospf"]["debug"] = {
89+
"ism": True,
90+
"nsm": True,
91+
"packet": True
92+
}
93+
94+
target.put_config_dicts({
95+
"ietf-interfaces": {
96+
"interfaces": {
97+
"interface": [{
98+
"name": link,
99+
"enabled": True,
100+
"ipv4": {
101+
"forwarding": True,
102+
"address": [{
103+
"ip": "192.168.50.1",
104+
"prefix-length": 24
105+
}]
106+
}
107+
}, {
108+
"name": "lo",
109+
"enabled": True,
110+
"ipv4": {
111+
"address": [{
112+
"ip": "192.168.100.1",
113+
"prefix-length": 32
114+
}]
115+
}
116+
}]
117+
}
118+
},
119+
"ietf-system": {
120+
"system": {
121+
"hostname": "R1"
122+
}
123+
},
124+
"ietf-syslog": {
125+
"syslog": {
126+
"actions": {
127+
"file": {
128+
"log-file": [{
129+
"name": "file:ospf-debug",
130+
"infix-syslog:property-filter": {
131+
"property": "programname",
132+
"operator": "isequal",
133+
"value": "ospfd"
134+
},
135+
"facility-filter": {
136+
"facility-list": [{
137+
"facility": "all",
138+
"severity": "debug"
139+
}]
140+
}
141+
}]
142+
}
143+
}
144+
}
145+
},
146+
"ietf-routing": {
147+
"routing": {
148+
"control-plane-protocols": {
149+
"control-plane-protocol": [ospf_config]
150+
}
151+
}
152+
}
153+
})
154+
155+
156+
def config_target2(target, link):
157+
target.put_config_dicts({
158+
"ietf-interfaces": {
159+
"interfaces": {
160+
"interface": [{
161+
"name": link,
162+
"enabled": True,
163+
"ipv4": {
164+
"forwarding": True,
165+
"address": [{
166+
"ip": "192.168.50.2",
167+
"prefix-length": 24
168+
}]
169+
}
170+
}, {
171+
"name": "lo",
172+
"enabled": True,
173+
"ipv4": {
174+
"address": [{
175+
"ip": "192.168.200.1",
176+
"prefix-length": 32
177+
}]
178+
}
179+
}]
180+
}
181+
},
182+
"ietf-system": {
183+
"system": {
184+
"hostname": "R2"
185+
}
186+
},
187+
"ietf-routing": {
188+
"routing": {
189+
"control-plane-protocols": {
190+
"control-plane-protocol": [{
191+
"type": "infix-routing:ospfv2",
192+
"name": "default",
193+
"ospf": {
194+
"redistribute": {
195+
"redistribute": [{
196+
"protocol": "connected"
197+
}]
198+
},
199+
"areas": {
200+
"area": [{
201+
"area-id": "0.0.0.0",
202+
"interfaces": {
203+
"interface": [{
204+
"enabled": True,
205+
"name": link,
206+
"hello-interval": 1,
207+
"dead-interval": 3
208+
}]
209+
}
210+
}]
211+
}
212+
}
213+
}]
214+
}
215+
}
216+
}
217+
})
218+
219+
220+
with infamy.Test() as test:
221+
with test.step("Set up topology and attach to target DUTs"):
222+
env = infamy.Env()
223+
R1 = env.attach("R1", "mgmt")
224+
R1ssh = env.attach("R1", "mgmt", "ssh")
225+
R2 = env.attach("R2", "mgmt")
226+
227+
with test.step("Clean up old log files from previous test runs"):
228+
R1ssh.runsh("sudo rm -f /var/log/ospf-debug")
229+
230+
with test.step("Configure R1 and R2 without debug enabled"):
231+
_, R1link = env.ltop.xlate("R1", "link")
232+
_, R2link = env.ltop.xlate("R2", "link")
233+
234+
parallel(config_target1(R1, R1link, enable_debug=False),
235+
config_target2(R2, R2link))
236+
237+
with test.step("Wait for OSPF adjacency to form"):
238+
until(lambda: route.ipv4_route_exist(R1, "192.168.200.1/32", proto="ietf-ospf:ospfv2"), attempts=200)
239+
until(lambda: route.ipv4_route_exist(R2, "192.168.100.1/32", proto="ietf-ospf:ospfv2"), attempts=200)
240+
241+
with test.step("Enable OSPF debug logging on R1"):
242+
config_target1(R1, R1link, enable_debug=True)
243+
244+
with test.step("Verify OSPF debug messages appear in log file"):
245+
until(verify_debug_messages_present(R1ssh, "ospf-debug"), attempts=30)
246+
247+
with test.step("Remove log file before disabling debug"):
248+
R1ssh.runsh("sudo rm -f /var/log/ospf-debug")
249+
250+
with test.step("Disable OSPF debug logging on R1"):
251+
config_target1(R1, R1link, enable_debug=False)
252+
253+
with test.step("Verify no OSPF debug messages when disabled"):
254+
until(verify_debug_messages_minimal(R1ssh, "ospf-debug"), attempts=30)
255+
256+
test.succeed()

‎test/case/routing/ospf_debug/topology.dot‎

Lines changed: 32 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,32 @@
1+
graph "ospf_debug" {
2+
layout="neato";
3+
overlap="false";
4+
esep="+20";
5+
size=10
6+
7+
node [shape=record, fontname="DejaVu Sans Mono, Book"];
8+
edge [color="cornflowerblue", penwidth="2", fontname="DejaVu Serif, Book"];
9+
10+
PC [
11+
label="PC | { <mgmt1> mgmt1 | <mgmt2> mgmt2 }",
12+
pos="20,30!",
13+
requires="controller",
14+
];
15+
16+
R1 [
17+
label="{ <mgmt> mgmt | <link> link} | R1 \n 192.168.100.1/32 \n(lo)",
18+
pos="160,60!",
19+
20+
requires="infix",
21+
];
22+
R2 [
23+
label="{ <link> link | <mgmt> mgmt } | R2 \n 192.168.200.1/32 \n(lo)",
24+
pos="160,30!",
25+
26+
requires="infix",
27+
];
28+
29+
PC:mgmt1 -- R1:mgmt [requires="mgmt", color="lightgray"]
30+
PC:mgmt2 -- R2:mgmt [requires="mgmt", color="lightgray"]
31+
R1:link -- R2:link [headlabel="192.168.50.2/24", taillabel="192.168.50.1/24", labeldistance=1, fontcolor="black", color="black"]
32+
}

0 commit comments

Comments
 (0)