github-personal/firezone
1
0
Fork 0
mirror of https://github.com/outbackdingo/firezone.git synced 2026-01-27 18:18:55 +00:00
Code Issues Packages Projects Releases Wiki Activity

test(connlib): improve assertion logs (#5223)

Browse Source 
In #5207, I already added logs for which assertions we are performing on
ICMP packets. This PR does the same thing for the DNS queries that are
being to connlib. It also adds spans that add some more context to the
messages.

Here is an excerpt of what this looks like:

```
Applying transition 19/19: SendICMPPacketToResource { idx: Index(3210705382108961150), seq: 57053, identifier: 28234, src: TunnelIp6 }
2024-06-05T07:06:30.742455Z  INFO assertions: ✅ Performed the expected 2 ICMP handshakes
2024-06-05T07:06:30.742459Z  INFO icmp{seq=15543 identifier=63125}: assertions: ✅ dst IP of request matches src IP of response: 3fb8:a7b0:c912:a648:6c9:7910:92dc:8db
2024-06-05T07:06:30.742461Z  INFO icmp{seq=15543 identifier=63125}: assertions: ✅ src IP of request matches dst IP of response: fd00:2021:1111::a:3531
2024-06-05T07:06:30.742464Z  INFO icmp{seq=15543 identifier=63125}: assertions: ✅ 3fb8:a7b0:c912:a648:6c9:7910:92dc:8db is the correct resource
2024-06-05T07:06:30.742467Z  INFO icmp{seq=57053 identifier=28234}: assertions: ✅ dst IP of request matches src IP of response: 3fb8:a7b0:c912:a648:6c9:7910:92dc:8d8
2024-06-05T07:06:30.742470Z  INFO icmp{seq=57053 identifier=28234}: assertions: ✅ src IP of request matches dst IP of response: fd00:2021:1111::a:3531
2024-06-05T07:06:30.742473Z  INFO icmp{seq=57053 identifier=28234}: assertions: ✅ 3fb8:a7b0:c912:a648:6c9:7910:92dc:8d8 is the correct resource
2024-06-05T07:06:30.742477Z  INFO dns{query_id=58256}: assertions: ✅ dst IP of request matches src IP of response: fd00:2021:1111:8000:100:100:111:0
2024-06-05T07:06:30.742480Z  INFO dns{query_id=58256}: assertions: ✅ src IP of request matches dst IP of response: fd00:2021:1111::a:3531
2024-06-05T07:06:30.742483Z  INFO dns{query_id=58256}: assertions: ✅ dst port of request matches src port of response: 53
2024-06-05T07:06:30.742485Z  INFO dns{query_id=58256}: assertions: ✅ src port of request matches dst port of response: 9999
2024-06-05T07:06:30.742488Z  INFO dns{query_id=22568}: assertions: ✅ dst IP of request matches src IP of response: 100.100.111.1
2024-06-05T07:06:30.742491Z  INFO dns{query_id=22568}: assertions: ✅ src IP of request matches dst IP of response: 100.75.34.66
2024-06-05T07:06:30.742494Z  INFO dns{query_id=22568}: assertions: ✅ dst port of request matches src port of response: 53
2024-06-05T07:06:30.742497Z  INFO dns{query_id=22568}: assertions: ✅ src port of request matches dst port of response: 9999
2024-06-05T07:06:30.742500Z  INFO dns{query_id=58735}: assertions: ✅ dst IP of request matches src IP of response: fd00:2021:1111:8000:100:100:111:2
2024-06-05T07:06:30.742502Z  INFO dns{query_id=58735}: assertions: ✅ src IP of request matches dst IP of response: fd00:2021:1111::a:3531
2024-06-05T07:06:30.742505Z  INFO dns{query_id=58735}: assertions: ✅ dst port of request matches src port of response: 53
2024-06-05T07:06:30.742507Z  INFO dns{query_id=58735}: assertions: ✅ src port of request matches dst port of response: 9999
2024-06-05T07:06:30.742512Z  INFO dns{query_id=59096}: assertions: ✅ dst IP of request matches src IP of response: fd00:2021:1111:8000:100:100:111:1
2024-06-05T07:06:30.742514Z  INFO dns{query_id=59096}: assertions: ✅ src IP of request matches dst IP of response: fd00:2021:1111::a:3531
2024-06-05T07:06:30.742517Z  INFO dns{query_id=59096}: assertions: ✅ dst port of request matches src port of response: 53
2024-06-05T07:06:30.742519Z  INFO dns{query_id=59096}: assertions: ✅ src port of request matches dst port of response: 9999
2024-06-05T07:06:30.742522Z  INFO dns{query_id=41570}: assertions: ✅ dst IP of request matches src IP of response: fd00:2021:1111:8000:100:100:111:1
2024-06-05T07:06:30.742525Z  INFO dns{query_id=41570}: assertions: ✅ src IP of request matches dst IP of response: fd00:2021:1111::a:3531
2024-06-05T07:06:30.742527Z  INFO dns{query_id=41570}: assertions: ✅ dst port of request matches src port of response: 53
2024-06-05T07:06:30.742530Z  INFO dns{query_id=41570}: assertions: ✅ src port of request matches dst port of response: 9999
2024-06-05T07:06:30.742533Z  INFO dns{query_id=15028}: assertions: ✅ dst IP of request matches src IP of response: fd00:2021:1111:8000:100:100:111:1
2024-06-05T07:06:30.742536Z  INFO dns{query_id=15028}: assertions: ✅ src IP of request matches dst IP of response: fd00:2021:1111::a:3531
2024-06-05T07:06:30.742538Z  INFO dns{query_id=15028}: assertions: ✅ dst port of request matches src port of response: 53
2024-06-05T07:06:30.742541Z  INFO dns{query_id=15028}: assertions: ✅ src port of request matches dst port of response: 9999
```

It is a bit repetitive because all assertions always run on all state
transition. Nevertheless I've found it useful to be able to look at the
assertions and visually verify that they make sense.
This commit is contained in:
Thomas Eizinger
2024-06-06 07:50:30 +10:00
committed by GitHub
parent d0efc55918
commit 492d5c976e
1 changed files with 37 additions and 36 deletions
Download Patch File Download Diff File Expand all files Collapse all files

73
rust/connlib/tunnel/src/tests.rs
View File

@@ -2397,6 +2397,8 @@ fn assert_icmp_packets_properties(state: &mut TunnelTest, ref_state: &ReferenceS
.iter()
.zip(state.gateway_received_icmp_requests.iter())
{
let _guard = tracing::info_span!(target: "assertions", "icmp", %seq, %identifier).entered();
let client_sent_request = &state
.client_sent_icmp_requests
.get(&(*seq, *identifier))
@@ -2406,7 +2408,7 @@ fn assert_icmp_packets_properties(state: &mut TunnelTest, ref_state: &ReferenceS
.get(&(*seq, *identifier))
.expect("to have ICMP reply on client");
assert_correct_src_and_dst_ips(client_sent_request, client_received_reply, seq, identifier);
assert_correct_src_and_dst_ips(client_sent_request, client_received_reply);
assert_eq!(
gateway_received_request.source(),
@@ -2439,21 +2441,46 @@ fn assert_icmp_packets_properties(state: &mut TunnelTest, ref_state: &ReferenceS
fn assert_correct_src_and_dst_ips(
client_sent_request: &IpPacket<'_>,
client_received_reply: &IpPacket<'_>,
seq: &IcmpSeq,
identifier: &IcmpIdentifier,
) {
assert_eq!(
client_sent_request.destination(),
client_received_reply.source(),
"ICMP request destination == ICMP reply source"
"request destination == reply source"
);
tracing::info!(target: "assertions", "✅ dst IP of request matches src IP of response: {}", client_sent_request.destination());
assert_eq!(
client_sent_request.source(),
client_received_reply.destination(),
"ICMP request source == ICMP reply destination"
"request source == reply destination"
);
tracing::info!(target: "assertions", "✅ src and dst IP for ICMP request ({seq},{identifier}) are correct");
tracing::info!(target: "assertions", "✅ src IP of request matches dst IP of response: {}", client_sent_request.source());
}
fn assert_correct_src_and_dst_udp_ports(
client_sent_request: &IpPacket<'_>,
client_received_reply: &IpPacket<'_>,
) {
let client_sent_request = client_sent_request.as_udp().expect("packet to be UDP");
let client_received_reply = client_received_reply.as_udp().expect("packet to be UDP");
assert_eq!(
client_sent_request.get_destination(),
client_received_reply.get_source(),
"request destination == reply source"
);
tracing::info!(target: "assertions", "✅ dst port of request matches src port of response: {}", client_sent_request.get_destination());
assert_eq!(
client_sent_request.get_source(),
client_received_reply.get_destination(),
"request source == reply destination"
);
tracing::info!(target: "assertions", "✅ src port of request matches dst port of response: {}", client_sent_request.get_source());
}
fn assert_destination_is_cdir_resource(
@@ -2532,6 +2559,8 @@ fn assert_dns_packets_properties(state: &TunnelTest, ref_state: &ReferenceState)
);
for query_id in ref_state.expected_dns_handshakes.iter() {
let _guard = tracing::info_span!(target: "assertions", "dns", %query_id).entered();
let client_sent_query = state
.client_sent_dns_queries
.get(query_id)
@@ -2541,36 +2570,8 @@ fn assert_dns_packets_properties(state: &TunnelTest, ref_state: &ReferenceState)
.get(query_id)
.expect("to have DNS response on client");
assert_eq!(
client_sent_query.destination(),
client_received_response.source(),
"DNS query dIP == DNS response sIP"
);
assert_eq!(
client_sent_query.source(),
client_received_response.destination(),
"DNS query sIP == DNS response dIP"
);
{
let client_sent_query = client_sent_query
.as_udp()
.expect("DNS query to be UDP packet");
let client_received_response = client_received_response
.as_udp()
.expect("DNS response to be UDP packet");
assert_eq!(
client_sent_query.get_destination(),
client_received_response.get_source(),
"DNS query dport == DNS response sport"
);
assert_eq!(
client_sent_query.get_source(),
client_received_response.get_destination(),
"DNS query sport == DNS response dport"
);
}
assert_correct_src_and_dst_ips(client_sent_query, client_received_response);
assert_correct_src_and_dst_udp_ports(client_sent_query, client_received_response);
}
}