add more logging

ci/docker/tester/requirements.txt

@@ -1,6 +1,6 @@
 pytest==8.3.3
 # Used for running tests with --timeout flag
-pytest-timeout==2.0.1
+pytest-timeout==2.3.1
 requests==2.32.3
 sh==1.14.1
 paramiko==3.5.0

cmd/daemon/events_moose.go

@@ -25,7 +25,7 @@ func newAnalytics(
 	_ = os.Setenv("MOOSE_LOG_FILE", "Stdout")
 	logLevel := "error"
 	if !internal.IsProdEnv(env) {
-		logLevel = "debug"
+		logLevel = "error"
 	}
 	_ = os.Setenv("MOOSE_LOG", logLevel)
 	sub := &moose.Subscriber{

daemon/rpc_logout.go

@@ -57,7 +57,7 @@ func (r *RPC) Logout(ctx context.Context, in *pb.LogoutRequest) (payload *pb.Pay
 		return &pb.Payload{Type: internal.CodeFailure}, nil
 	}
 
-	if !r.ncClient.Revoke(internal.IsDevEnv(string(r.environment))) {
+	if !r.ncClient.Revoke(true) {
 		log.Println(internal.WarningPrefix, "error revoking NC token")
 	}
 

daemon/rpc_set_defaults.go

@@ -30,10 +30,8 @@ func (r *RPC) SetDefaults(ctx context.Context, in *pb.Empty) (*pb.Payload, error
 		log.Println(internal.WarningPrefix, err)
 	}
 
-	if internal.IsDevEnv(string(r.environment)) {
-		if !r.ncClient.Revoke(true) {
-			log.Println(internal.WarningPrefix, "error revoking token")
-		}
+	if !r.ncClient.Revoke(true) {
+		log.Println(internal.WarningPrefix, "error revoking token")
 	}
 
 	if err := r.cm.Reset(); err != nil {

events/moose/moose.go

@@ -100,7 +100,7 @@ func (s *Subscriber) Init() error {
 	}
 
 	timeBetweenEvents, _ := time.ParseDuration("100ms")
-	timeBetweenBatchesOfEvents, _ := time.ParseDuration("1s")
+	timeBetweenBatchesOfEvents, _ := time.ParseDuration("1h")
 	if internal.IsProdEnv(s.Environment) {
 		timeBetweenEvents, _ = time.ParseDuration("2s")
 		timeBetweenBatchesOfEvents, _ = time.ParseDuration("2h")

go.mod

@@ -106,4 +106,5 @@ require (
 	google.golang.org/genproto/googleapis/api v0.0.0-20240701130421-f6361c86f094 // indirect
 	google.golang.org/genproto/googleapis/rpc v0.0.0-20240701130421-f6361c86f094 // indirect
 	gopkg.in/yaml.v3 v3.0.1 // indirect
+	moose/events v0.0.0
 )

magefiles/mage.go

@@ -23,7 +23,7 @@ const (
 	imageSnapPackager      = registryPrefix + "snaper:0.0.4"
 	imageProtobufGenerator = registryPrefix + "generator:1.4.1"
 	imageScanner           = registryPrefix + "scanner:1.1.0"
-	imageTester            = registryPrefix + "tester:1.3.1"
+	imageTester            = registryPrefix + "tester:1.3.2"
 	imageQAPeer            = registryPrefix + "qa-peer:1.0.4"
 	imageRuster            = registryPrefix + "ruster:1.3.0"
 

test/qa/conftest.py

@@ -1,5 +1,8 @@
 import datetime
 import io
+import subprocess
+import signal
+import socket
 import threading
 import time
 
@@ -50,46 +53,75 @@ def setup_check_internet_connection():
 def start_system_monitoring():
     print("~~~start_system_monitoring: Start system monitoring")
 
-    connection_check_thread = threading.Thread(target=_check_connection_to_ip, args=("1.1.1.1",), daemon=True)
-    connection_out_vpn_check_thread = threading.Thread(target=_check_connection_to_ip_outside_vpn, args=("1.1.1.1",), daemon=True)
-    dns_resolver_thread = threading.Thread(target=_check_dns_resolution, args=("nordvpn.com",), daemon=True)
-    connection_check_thread.start()
-    connection_out_vpn_check_thread.start()
-    dns_resolver_thread.start()
+    # control running threads execution
+    stop_event = threading.Event()
 
+    threads = []
+
+    threads.append(threading.Thread(target=_check_connection_to_ip, args=["1.1.1.1", stop_event], daemon=True))
+    threads.append(threading.Thread(target=_check_connection_to_ip_outside_vpn, args=["1.1.1.1", stop_event], daemon=True))
+    threads.append(threading.Thread(target=_check_dns_resolution, args=["nordvpn.com", stop_event], daemon=True))
+    threads.append(threading.Thread(target=_capture_traffic, args=[stop_event], daemon=True))
+    print(threads)
+
+    for thread in threads:
+        thread.start()
+
+    # execute tests
     yield
 
+    # stop monitoring after execution
+    stop_event.set()
+    for thread in threads:
+        thread.join()
 
-def _check_connection_to_ip(ip_address):
-    while True:
+def _check_connection_to_ip(ip_address, stop_event):
+    print("start _check_connection_to_ip")
+    while not stop_event.is_set():
         try:
-            print(f"~~~_check_connection_to_ip: {ip_address}")
-            "icmp_seq=" in sh.ping("-c", "3", "-W", "3", ip_address) # noqa: B015
+            network.is_internet_reachable(ip_address=ip_address, retry=1)
             print(f"~~~_check_connection_to_ip: IN-PING {ip_address} SUCCESS")
-        except sh.ErrorReturnCode as e:
+        except Exception as e: # noqa: BLE001
             print(f"~~~_check_connection_to_ip: IN-PING {ip_address} FAILURE: {e}.")
-        time.sleep(_CHECK_FREQUENCY)
+            data = "\n".join(["_check_connection_to_ip: Default route:",
+                        str(os.popen("sudo ip route get 1.1.1.1").read()),
+                        "iptables stats",str(os.popen("sudo iptables -L -v -n").read())])
+            print(data)
+        stop_event.wait(_CHECK_FREQUENCY)
 
 
-def _check_connection_to_ip_outside_vpn(ip_address):
-    while True:
+def _check_connection_to_ip_outside_vpn(ip_address, stop_event):
+    print("start _check_connection_to_ip_outside_vpn")
+    while not stop_event.is_set():
         try:
-            print(f"~~~_check_connection_to_ip_outside_vpn: {ip_address}")
             "icmp_seq=" in sh.sudo.ping("-c", "3", "-W", "3", "-m", "57841", ip_address) # noqa: B015
             print(f"~~~_check_connection_to_ip_outside_vpn: OUT-PING {ip_address} SUCCESS")
-        except sh.ErrorReturnCode as e:
+        except Exception as e: # noqa: BLE001
             print(f"~~~_check_connection_to_ip_outside_vpn: OUT-PING {ip_address} FAILURE: {e}.")
-        time.sleep(_CHECK_FREQUENCY)
+        stop_event.wait(_CHECK_FREQUENCY)
 
 
-def _check_dns_resolution(domain):
-    while True:
+def _check_dns_resolution(domain, stop_event):
+    print("start _check_dns_resolution")
+    while not stop_event.is_set():
         try:
-            print(f"~~~_check_dns_resolution: {domain}")
             resolver = dns.resolver.Resolver()
             resolver.nameservers = ['8.8.8.8']
             resolver.resolve(domain, 'A')  # 'A' for IPv4
             print(f"~~~_check_dns_resolution: DNS {domain} SUCCESS")
         except Exception as e:  # noqa: BLE001
             print(f"~~~_check_dns_resolution: DNS {domain} FAILURE. Error: {e}")
-        time.sleep(_CHECK_FREQUENCY)
+        stop_event.wait(_CHECK_FREQUENCY)
+
+
+def _capture_traffic(stop_event):
+    print("start _capture_traffic")
+    # use circular log files, keep only 2 latest each 10MB size
+    command = ["tshark", "-a", "filesize:10240", "-b", "files:2", "-i", "any", "-w", os.environ["WORKDIR"] + "/dist/logs/tshark_capture.pcap"]
+    print("Starting tshark...")
+    process = subprocess.Popen(command, stdout=subprocess.PIPE, stderr=subprocess.PIPE, text=True)
+    stop_event.wait()
+    print("Stopping tshark with Ctrl+C...")
+    process.send_signal(signal.SIGINT)
+    print(f"tshark out {process.stdout.read().strip()} - {process.stderr.read().strip()}")
+    time.sleep(1)

test/qa/lib/firewall.py

@@ -367,7 +367,11 @@ def is_active(ports: list[Port] | None = None, subnets: list[str] | None = None)
 def is_empty() -> bool:
     """Returns True when firewall does not have DROP rules."""
     # under snap, also on host, ignore docker rules
-    return "DROP" not in os.popen("sudo iptables -S | grep -v DOCKER").read()
+    rules = os.popen("sudo iptables -S | grep -v DOCKER").read()
+    if "DROP" in rules:
+        logging.log(f"DROP in {rules}")
+        return False
+    return True
 
 
 def _get_iptables_rules() -> list[str]:

test/qa/lib/network.py

@@ -4,9 +4,9 @@
 from threading import Thread
 
 import dns.resolver
-import pytest
 import requests
 import sh
+import urllib
 
 from . import daemon, firewall, info, logging, settings
 
@@ -24,65 +24,77 @@
 FWMARK = 57841
 
 class PacketCaptureThread(Thread):
-    def __init__(self, connection_settings):
+    def __init__(self, connection_settings, duration: int):
         Thread.__init__(self)
-        self.packets_captured: int = -1
         self.connection_settings = connection_settings
+        self.packets = ""
+        self.duration=duration
 
     def run(self):
-        self.packets_captured = _capture_packets(self.connection_settings)
+        self.packets = self._capture_packets()
 
 
-def _capture_packets(connection_settings: (str, str, str)) -> int:
-    technology = connection_settings[0]
-    protocol = connection_settings[1]
-    obfuscated = connection_settings[2]
+    def _capture_packets(self) -> str:
+        technology = self.connection_settings[0]
+        protocol = self.connection_settings[1]
+        obfuscated = self.connection_settings[2]
 
-    # Collect information needed for tshark filter
-    server_ip = settings.get_server_ip()
+        # Collect information needed for tshark filter
+        server_ip = settings.get_server_ip()
 
-    # Choose traffic filter according to information collected above
-    if technology == "nordlynx" and protocol == "" and obfuscated == "":
-        traffic_filter = TSHARK_FILTER_NORDLYNX % server_ip
-    elif technology == "openvpn" and protocol == "udp" and obfuscated == "off":
-        traffic_filter = TSHARK_FILTER_UDP % server_ip
-    elif technology == "openvpn" and protocol == "tcp" and obfuscated == "off":
-        traffic_filter = TSHARK_FILTER_TCP % server_ip
-    elif technology == "openvpn" and protocol == "udp" and obfuscated == "on":
-        traffic_filter = TSHARK_FILTER_UDP_OBFUSCATED % server_ip
-    elif technology == "openvpn" and protocol == "tcp" and obfuscated == "on":
-        traffic_filter = TSHARK_FILTER_TCP_OBFUSCATED % server_ip
+        # Choose traffic filter according to information collected above
+        if technology == "nordlynx" and protocol == "" and obfuscated == "":
+            traffic_filter = TSHARK_FILTER_NORDLYNX % server_ip
+        elif technology == "openvpn" and protocol == "udp" and obfuscated == "off":
+            traffic_filter = TSHARK_FILTER_UDP % server_ip
+        elif technology == "openvpn" and protocol == "tcp" and obfuscated == "off":
+            traffic_filter = TSHARK_FILTER_TCP % server_ip
+        elif technology == "openvpn" and protocol == "udp" and obfuscated == "on":
+            traffic_filter = TSHARK_FILTER_UDP_OBFUSCATED % server_ip
+        elif technology == "openvpn" and protocol == "tcp" and obfuscated == "on":
+            traffic_filter = TSHARK_FILTER_TCP_OBFUSCATED % server_ip
 
-    # If enough packets are captured, do not wait the duration time, exit early, show compact output
-    tshark_result: str = sh.tshark("-i", "any", "-T", "fields", "-e", "ip.src", "-e", "ip.dst", "-a", "duration:3", "-a", "packets:1", "-f", traffic_filter)
-    #tshark_result: str = os.popen(f"sudo tshark -i any -T fields -e ip.src -e ip.dst -a duration:3 -a packets:1 -f {traffic_filter}").read()
+        command = ["-i", "any", "-a", f"duration:{self.duration}"]
+        if technology != "" :
+            command += "-f", traffic_filter
 
-    packets = tshark_result.strip().splitlines()
+        # If enough packets are captured, do not wait the duration time, exit early, show compact output
+        tshark_result: str = sh.tshark(command)
+        #tshark_result: str = os.popen(f"sudo tshark -i any -T fields -e ip.src -e ip.dst -a duration:3 -a packets:1 -f {traffic_filter}").read()
 
-    return len(packets)
+        return tshark_result.strip()
 
 
-def capture_traffic(connection_settings) -> int:
+def capture_traffic(connection_settings, duration: int=5) -> str:
     """Returns count of captured packets."""
 
     # We try to capture packets using other thread
-    t_connect = PacketCaptureThread(connection_settings)
+    t_connect = PacketCaptureThread(connection_settings, duration)
     t_connect.start()
 
-    sh.ping("-c", "2", "-w", "2", "1.1.1.1")
+    try:
+        # generate some traffic
+        req = urllib.request.Request("https://1.1.1.1", method="HEAD")
+        response = urllib.request.urlopen(req, timeout=1)
+        print(f"capture_traffic HTTP Status: {response.status}")
+    except Exception as e: # noqa: BLE001
+        logging.log(f"capture_traffic exception: {e}")
+        logging.log(t_connect.packets)
 
     t_connect.join()
 
-    return t_connect.packets_captured
+    return t_connect.packets
 
 
-def _is_internet_reachable(retry=5) -> bool:
+def is_internet_reachable(ip_address="1.1.1.1", port=443, retry=5) -> bool:
     """Returns True when remote host is reachable by its public IP."""
     i = 0
     while i < retry:
         try:
-            return "icmp_seq=" in sh.ping("-c", "1", "-w", "1", "1.1.1.1")
-        except sh.ErrorReturnCode:
+            sock = socket.create_connection((ip_address, port), timeout=1)
+            sock.close()
+            return True
+        except Exception: # noqa: BLE001
             time.sleep(1)
             i += 1
     return False
@@ -117,43 +129,15 @@ def _is_ipv6_internet_reachable(retry=5) -> bool:
 def _is_dns_resolvable(retry=5) -> bool:
     """Returns True when domain resolution is working."""
     i = 0
+    domain = "nordvpn.com"
     while i < retry:
         try:
-            # @TODO gitlab docker runner has public ipv6, but no connectivity. remove -4 once fixed
-            return "icmp_seq=" in sh.ping("-4", "-c", "1", "-w", "1", "nordvpn.com")
-        except sh.ErrorReturnCode:
-            time.sleep(1)
-            i += 1
-    return False
-
-
-def _is_dns_resolvable_outside_vpn(retry: int = 5) -> bool:
-    """Returns True when domain resolution outside vpn is not working."""
-    i = 0
-    while i < retry:
-        try:
-            # @TODO gitlab docker runner has public ipv6, but no connectivity. remove -4 once fixed
-            # @TODO need dns query to go arround vpn tunnel, here with regular ping it does not
-            return "icmp_seq=" in sh.ping("-4", "-c", "1", "-m", f"{FWMARK}", "-w", "1", "nordvpn.com")
-        except sh.ErrorReturnCode:
-            time.sleep(1)
-            i += 1
-    return False
-
-
-def _is_dns_not_resolvable(retry: int = 5) -> bool:
-    """Returns True when domain resolution is not working."""
-    i = 0
-    while i < retry:
-        try:
-            with pytest.raises((dns.resolver.NoNameservers, dns.resolver.LifetimeTimeout)):
-                resolver = dns.resolver.Resolver()
-                resolver.lifetime = 1
-                resolver.resolve("nordvpn.com")
+            resolver = dns.resolver.Resolver()
+            resolver.resolve(domain, 'A', lifetime=5)  # 'A' for IPv4
             return True
-        except:  # noqa: E722
+        except Exception as e:  # noqa: BLE001
+            print(f"_is_dns_resolvable: DNS {domain} FAILURE. Error: {e}")
             time.sleep(1)
-            i += 1
     return False
 
 
@@ -165,15 +149,13 @@ def is_not_available(retry=5) -> bool:
 
     # If assert below fails, and you are running Kill Switch tests on your machine, inside of Docker,
     # set DNS in resolv.conf of your system to anything else but 127.0.0.53
-    return not _is_internet_reachable(retry) and _is_dns_not_resolvable(retry)
+    return not is_internet_reachable(retry=retry)
 
 
 def is_available(retry=5) -> bool:
     """Returns True when network access is available or throws AssertionError otherwise."""
     assert _is_internet_reachable_outside_vpn(retry)
-    assert _is_internet_reachable(retry)
-    assert _is_dns_resolvable_outside_vpn(retry)
-    assert _is_dns_resolvable(retry)
+    assert is_internet_reachable(retry=retry)
     return True
 
 
@@ -236,10 +218,11 @@ def stop() -> str:
 
     if daemon.is_init_systemd():
         sh.sudo.nmcli.networking.off()
+        print("using nmcli")
     else:
         sh.sudo.ip.link.set.dev.eth0.down()
 
-    logging.log("stopping network")
+    logging.log("stopping network {default_gateway}")
     assert is_not_available()
     logging.log(info.collect())
     return default_gateway