diff --git a/.github/workflows/integration-tests.yml b/.github/workflows/integration-tests.yml index 2ab0edf93d..538ab87ede 100644 --- a/.github/workflows/integration-tests.yml +++ b/.github/workflows/integration-tests.yml @@ -55,7 +55,7 @@ jobs: - name: Upload Artifacts if: always() - uses: actions/upload-artifact@v5 + uses: actions/upload-artifact@v6 with: # Replaces slashes with underscores for valid artifact naming name: ${{ github.run_id }}-${{ strategy.job-index }}-integration-output diff --git a/.github/workflows/unit-tests.yml b/.github/workflows/unit-tests.yml index 5a19ba3b3c..98427b1945 100644 --- a/.github/workflows/unit-tests.yml +++ b/.github/workflows/unit-tests.yml @@ -56,7 +56,7 @@ jobs: - name: Upload Artifacts if: always() - uses: actions/upload-artifact@v5 + uses: actions/upload-artifact@v6 with: name: test_slips-output-${{ strategy.job-index }} path: | diff --git a/.secrets.baseline b/.secrets.baseline index 42de85b9f8..86c4471ba3 100644 --- a/.secrets.baseline +++ b/.secrets.baseline @@ -149,7 +149,7 @@ "filename": "config/slips.yaml", "hashed_secret": "4cac50cee3ad8e462728e711eac3e670753d5016", "is_verified": false, - "line_number": 268 + "line_number": 278 } ], "dataset/test14-malicious-zeek-dir/http.log": [ @@ -7185,5 +7185,5 @@ } ] }, - "generated_at": "2026-03-02T22:46:58Z" + "generated_at": "2026-03-27T14:25:16Z" } diff --git a/AGENTS.md b/AGENTS.md new file mode 100644 index 0000000000..48cb9d39e9 --- /dev/null +++ b/AGENTS.md @@ -0,0 +1,42 @@ +# AGENTS.md + +## Project overview +- Entry point: `slips.py` (starts the main process, spawns modules, runs in interactive/daemon modes). +- Core framework code lives in `slips/`, `slips_files/`, and `managers/`. +- Detection/analysis modules are in `modules/` (implement the `IModule` interface). +- Configuration is in `config/` (main config: `config/slips.yaml`). +- Tests live under `tests/` (unit + integration suites). +- Documentation is in `docs/` (see `docs/contributing.md` for contribution workflow, branching, and PR expectations). +- UIs/tools: `SlipsWeb/`, `webinterface/`, `webinterface.sh`, and `kalipso.sh`. + +## Build and test commands +- Run locally (no build step): + - `./slips.py -e 1 -f dataset/test7-malicious.pcap -o output_dir` +- Build the Docker image (from `docs/installation.md`): + - `docker build --no-cache -t slips -f docker/Dockerfile .` + - If build networking fails: `docker build --network=host --no-cache -t slips -f docker/Dockerfile .` +- Run the Docker image: + - `docker run -it --rm --net=host slips` + +## Code style guidelines +- Python formatting is enforced via pre-commit: + - Black with `--line-length 79` (see `.pre-commit-config.yaml`). + - Ruff is used for linting and autofixes. +- Keep docstrings at the top of files where present (pre-commit `check-docstring-first`). +- Maintain clean whitespace (no trailing whitespace, final newline). +- Follow existing module patterns (`IModule` in `slips_files/common/abstracts/module.py`). + +## Testing instructions +- The canonical test runner is `tests/run_all_tests.sh` (runs unit tests then integration tests). +- Equivalent manual sequence (from `tests/run_all_tests.sh`): + - `./slips.py -cc` + - `printf "0" | ./slips.py -k` + - `python3 -m pytest tests/ --ignore="tests/integration_tests" -n 7 -p no:warnings -vvvv -s` + - `python3 tests/destrctor.py` + - `./slips.py -cc` + - `printf "0" | ./slips.py -k` + - `python3 -m pytest -s tests/integration_tests/test_portscans.py -p no:warnings -vv` + - `python3 -m pytest -s tests/integration_tests/test_dataset.py -p no:warnings -vv` + - `python3 -m pytest -s tests/integration_tests/test_config_files.py -p no:warnings -vv` + - `printf "0" | ./slips.py -k` + - `./slips.py -cc` diff --git a/CHANGELOG.md b/CHANGELOG.md index 626bf6caff..1347ce71b9 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,3 +1,11 @@ +1.1.19 (Mar 31st, 2026) + +* Add SSH bruteforce detection based on Zeek SSH, software, and notice logs. +* Improve performance under high-throughput traffic with parallel evidence handling, profiler/input optimizations. +* Fix issues while slips is shutting down. +* Add optional performance plots and CSV metrics for latency, throughput, and resource usage. +* Fix skipped first-flow processing and reduce shutdown race conditions on small files and PCAPs. + 1.1.18 (Mar 3rd, 2026) * Add the HTTPS anomaly detection module with adaptive baselines, confidence scoring, and detailed evidence reasons. diff --git a/README.md b/README.md index 48a8f035e5..300e2c629a 100644 --- a/README.md +++ b/README.md @@ -1,5 +1,5 @@

-Slips v1.1.18 +Slips v1.1.19

diff --git a/VERSION b/VERSION index 852ed67cfd..4e036596e2 100644 --- a/VERSION +++ b/VERSION @@ -1 +1 @@ -1.1.18 +1.1.19 diff --git a/config/slips.yaml b/config/slips.yaml index 5e307f143e..4ef67bf309 100644 --- a/config/slips.yaml +++ b/config/slips.yaml @@ -163,6 +163,16 @@ parameters: # client_ips : [10.0.0.1, 11.0.0.0/24] client_ips: [] +############################# +Debug: + # Generate latency, throughput, and other performance related CSV files and plots in output/performance_plots/ for debugging + # When enabled, Slips records extra per-flow/per-minute performance data from + # input, profiler workers, and evidence handling, then generates summary plots + # during shutdown. Keep this disabled for normal runs because it adds extra + # bookkeeping and disk writes. + # available options are true/false + generate_performance_plots: false + ############################# detection: @@ -215,6 +225,12 @@ flowmldetection: # 'Malicious' data in order for the test to work. mode: test +############################# +bruteforcing: + # Minimum number of SSH attempts from one source to one destination + # before Slips considers it brute forcing. + ssh_attempt_threshold: 9 + ############################# anomaly_detection_https: # Number of initial hours used to train the baseline model assuming benign traffic. diff --git a/dataset/test19-malicious-ssh/README.md b/dataset/test19-malicious-ssh/README.md new file mode 100644 index 0000000000..4630f1f68e --- /dev/null +++ b/dataset/test19-malicious-ssh/README.md @@ -0,0 +1,5 @@ +## SSH Bruteforce +Using nmap to bruteforce SSH with 1 user and 40 passwords in port 902/TCP with SSH. + +Command +`nmap -p 902 --script ssh-brute --script-args userdb=users.lst,passdb=pass.lst,ssh-brute.timeout=4s 147.32.80.37 -sV` diff --git a/dataset/test19-malicious-ssh/malicious-ssh-bruteforce.pcap b/dataset/test19-malicious-ssh/malicious-ssh-bruteforce.pcap new file mode 100644 index 0000000000..6d7da20145 Binary files /dev/null and b/dataset/test19-malicious-ssh/malicious-ssh-bruteforce.pcap differ diff --git a/docs/bruteforcing.md b/docs/bruteforcing.md new file mode 100644 index 0000000000..5bc23a0d9f --- /dev/null +++ b/docs/bruteforcing.md @@ -0,0 +1,120 @@ +# Bruteforcing Module + +The `Bruteforcing` module detects SSH bruteforcing by combining repeated SSH sessions, Zeek SSH metadata, client software banners, and Zeek notice confirmations. + +This module is loaded automatically by Slips like the rest of the modules in `modules/`, unless it is explicitly disabled in `config/slips.yaml`. + +## Inputs + +The module subscribes to the following Slips channels: + +- `new_ssh` +- `new_software` +- `new_notice` +- `tw_closed` + +These channels are populated from Zeek logs: + +- `ssh.log` +- `software.log` +- `notice.log` + +## What It Detects + +The module tracks repeated SSH activity from the same source IP to the same destination IP and destination port inside the same time window. + +It uses the following inputs: + +- `ssh.log` to count repeated SSH sessions and authentication attempts +- `software.log` to extract the `SSH::CLIENT` banner and identify likely automation libraries such as `libssh`, `libssh2`, `paramiko`, `hydra`, `medusa`, or `ncrack` +- `notice.log` to consume Zeek `SSH::Password_Guessing` confirmations + +## Detection Logic + +### Counting Attempts + +For each SSH flow, the module first checks the Zeek SSH authentication outcome: + +- If `auth_success` is `true` or `T`, the flow is ignored for bruteforcing. +- If `auth_attempts` is greater than `0`, that value is added to the bruteforce campaign counter. +- If `auth_attempts` is `0` or missing, but the SSH session is not marked successful, the module counts the session as one suspected password attempt. + +The last rule is important for datasets where Zeek records repeated SSH handshakes without recording explicit authentication attempts, such as the `malicious-ssh-bruteforce.pcap` sample. + +### Threshold and Reporting + +The default SSH bruteforcing threshold is `9` attempts. + +After the threshold is reached, the module does not alert on every new attempt. Instead, it uses sparse bucketed reporting so alerts become less frequent over time but never completely stop. With the default threshold, the alert points are: + +- 9 +- 10 +- 12 +- 16 +- 24 +- 40 +- ... + +### Confidence + +The evidence threat level is `medium`. + +Confidence grows with the number of attempted passwords: + +- first bruteforcing evidence starts at the configured threshold +- full confidence is reached at `30` attempts +- suspicious SSH client banners add a small confidence bonus +- a Zeek `SSH::Password_Guessing` notice acts as confirmation and promotes confidence using Zeek's confirmed connection count + +## Evidence Produced + +The module emits `PASSWORD_GUESSING` evidence with: + +- source attacker IP +- destination victim IP when available +- TCP destination port +- time window +- accumulated UIDs +- threat level `medium` +- confidence based on the number of attempts and confirmation data + +Example description: + +```text +SSH bruteforcing from 147.32.80.40 to 147.32.80.37 on SSH 902/tcp. Attempts observed: 24. Client banner: libssh libssh2_1.11.0 from software.log. Confidence: 0.89. by Slips +``` + +## Zeek Confirmation + +If Zeek raises `SSH::Password_Guessing` in `notice.log`, the module: + +- emits an evidence immediately based on the notice +- stores the notice as confirmation for later bruteforcing evidence +- uses the confirmed connection count from the Zeek notice to increase confidence + +If Zeek does not generate `notice.log` for SSH password guessing, the module still detects bruteforcing from `ssh.log` and `software.log`. + +## Configuration + +The module currently exposes: + +```yaml +bruteforcing: + ssh_attempt_threshold: 9 +``` + +This value is read from `config/slips.yaml`. + +## Relationship With Flow Alerts + +SSH bruteforcing is now handled by the `Bruteforcing` module. + +The `Flow Alerts` module still handles: + +- successful SSH detections +- Zeek port-scan notices +- certificate alerts +- DNS and connection heuristics +- SMTP bruteforce and the rest of the single-flow detections + +It no longer owns SSH password guessing detection. diff --git a/docs/contributing.md b/docs/contributing.md index bfe1d528c9..320e775ca1 100644 --- a/docs/contributing.md +++ b/docs/contributing.md @@ -167,6 +167,14 @@ Once all modules are done processing, EvidenceHandler is killed by the Process m - It runs the unit tests first, then the integration tests. - Please get familiar with pytest first https://docs.pytest.org/en/stable/how-to/output.html +### What does `generate_performance_plots` do? + +- `Debug.generate_performance_plots` in [config/slips.yaml](config/slips.yaml) is a developer-only debugging switch for performance investigations. +- When it is `true`, Slips writes extra CSVs under `output/performance_plots/csv/`, including alert latency (`latency.csv`), profiler worker latency (`profiler_worker_*_latency.csv`), and throughput (`flows_per_minute.csv`). +- On shutdown, the process manager turns those CSVs into plots and metrics under `output/performance_plots/` and `output/metrics.txt`. +- Leave it `false` for normal development and production-style runs. Enabling it adds Redis bookkeeping, file writes, and plot-generation work that are only useful when diagnosing throughput or latency behavior. +- The plots shown in [docs/immune/stress_testing.md](docs/immune/stress_testing.md) were generated with this parameter enabled. + ### Where and how do we get the GW info? Using one of these 3 ways diff --git a/docs/detection_modules.md b/docs/detection_modules.md index a12c9538c5..0a8cacec9d 100644 --- a/docs/detection_modules.md +++ b/docs/detection_modules.md @@ -95,7 +95,12 @@ tr:nth-child(even) { Flow Alerts - Finds malicious behaviours by analyzing only one flow. Now detects: self-signed certificates, TLS certificates which validation failed, vertical port scans detected by Zeek (contrary to detected by Slips), horizontal port scans detected by Zeek (contrary to detected by Slips), password guessing in SSH as detected by Zeek, long connection, successful ssh + Finds malicious behaviours by analyzing one flow at a time. It detects self-signed certificates, invalid TLS certificates, Zeek vertical and horizontal port-scan notices, long connections, successful SSH, DNS and connection heuristics, SMTP bruteforce, and related per-flow behaviours. + ✅ + + + Bruteforcing + Detects SSH bruteforcing from repeated SSH sessions, SSH authentication metadata, client banners from software.log, and Zeek SSH password-guessing notices. ✅ @@ -126,6 +131,22 @@ tr:nth-child(even) { +## Bruteforcing Module + +The `Bruteforcing` module is responsible for SSH bruteforcing detection. + +It consumes: + +- `ssh.log` +- `software.log` +- `notice.log` + +It correlates repeated SSH sessions by source IP, destination IP, destination port, and time window. It starts alerting at `9` attempts by default, reports sparsely as the count grows, uses the SSH client banner to adjust confidence, and uses Zeek `SSH::Password_Guessing` notices as confirmation. + +For the full design and configuration details, see: + +- [Bruteforcing Module](bruteforcing.md) + ## HTTPS Anomaly Detection Module For the full technical description of the HTTPS anomaly detector (features, training, adaptation, z-score logic, evidence format, and configuration), see: diff --git a/docs/features.md b/docs/features.md index 415c5a7dbd..3b2335d155 100644 --- a/docs/features.md +++ b/docs/features.md @@ -21,7 +21,7 @@ The detection techniques are: - Malicious JA3 hashes - Connections to port 0 - Multiple reconnection attempts -- Alerts from Zeek: Self-signed certs, invalid certs, port-scans and address scans, and password guessing +- Alerts from Zeek: Self-signed certs, invalid certs, port-scans and address scans - DGA - Connection to multiple ports - Malicious SSL certificates @@ -507,7 +507,12 @@ tr:nth-child(even) { flowalerts - Finds malicious behaviours by analyzing only one flow. Now detects: self-signed certificates, TLS certificates which validation failed, vertical port scans detected by Zeek (contrary to detected by Slips), horizontal port scans detected by Zeek (contrary to detected by Slips), password guessing in SSH as detected by Zeek, long connection, successful ssh + Finds malicious behaviours by analyzing one flow at a time. It detects self-signed certificates, invalid TLS certificates, Zeek vertical and horizontal port-scan notices, long connections, successful SSH, DNS and connection heuristics, SMTP bruteforce, and related per-flow behaviours. + ✅ + + + bruteforcing + Detects SSH bruteforcing from repeated SSH sessions, SSH authentication metadata, client banners from software.log, and Zeek SSH password-guessing notices. ✅ diff --git a/docs/flowalerts.md b/docs/flowalerts.md index 2195d9216b..bf6ea58069 100644 --- a/docs/flowalerts.md +++ b/docs/flowalerts.md @@ -13,7 +13,7 @@ The detection techniques are: - Malicious JA3 hashes - Connections to port 0 - Multiple reconnection attempts -- Alerts from Zeek: Self-signed certs, invalid certs, port-scans and address scans, and password guessing +- Alerts from Zeek: Self-signed certs, invalid certs, port-scans and address scans - DGA - Connection to multiple ports - Malicious SSL certificates @@ -184,9 +184,7 @@ the same destination IP on the same destination port. ## Zeek alerts By default, Slips depends on Zeek for detecting different behaviours, for example -Self-signed certs, invalid certs, port-scans, address scans, and password guessing. - -Password guessing is detected by zeek when 30 failed ssh logins happen over 30 mins. +Self-signed certs, invalid certs, port-scans, and address scans. Some scans are also detected by Slips independently of Zeek, like ICMP sweeps and vertical/horizontal portscans. Check @@ -197,11 +195,13 @@ section for more info Slips alerts when 3+ invalid SMTP login attempts occurs within 10s -## Password Guessing +## SSH Bruteforcing + +SSH bruteforcing is documented in the dedicated `Bruteforcing` module page: + +- [Bruteforcing Module](bruteforcing.md) -Password guessing is detected using 2 ethods in slips -1. by Zeek engine. when 30 failed ssh logins happen over 30 mins. -2. By slips. when 20 failed ssh logins happen over 1 tiemwindow. +The `Flow Alerts` module still detects successful SSH sessions, but SSH password guessing is no longer owned by `Flow Alerts`. ## DGA diff --git a/docs/images/immune/c3/stress_testing/after_optimizations.jpg b/docs/images/immune/c3/stress_testing/after_optimizations.jpg new file mode 100644 index 0000000000..51616858f0 Binary files /dev/null and b/docs/images/immune/c3/stress_testing/after_optimizations.jpg differ diff --git a/docs/images/immune/c3/stress_testing/baseline/CTU-Mixed-Capture-1_flows_per_min_for_all_profilers_combined.png b/docs/images/immune/c3/stress_testing/baseline/CTU-Mixed-Capture-1_flows_per_min_for_all_profilers_combined.png new file mode 100644 index 0000000000..96bfba94c0 Binary files /dev/null and b/docs/images/immune/c3/stress_testing/baseline/CTU-Mixed-Capture-1_flows_per_min_for_all_profilers_combined.png differ diff --git a/docs/images/immune/c3/stress_testing/baseline/CTU-Mixed-Capture-1_flows_per_minute_for_each_profiler.png b/docs/images/immune/c3/stress_testing/baseline/CTU-Mixed-Capture-1_flows_per_minute_for_each_profiler.png new file mode 100644 index 0000000000..f59d4de776 Binary files /dev/null and b/docs/images/immune/c3/stress_testing/baseline/CTU-Mixed-Capture-1_flows_per_minute_for_each_profiler.png differ diff --git a/docs/images/immune/c3/stress_testing/baseline/CTU-Mixed-Capture-1_latency_over_time.png b/docs/images/immune/c3/stress_testing/baseline/CTU-Mixed-Capture-1_latency_over_time.png new file mode 100644 index 0000000000..53f71e8e13 Binary files /dev/null and b/docs/images/immune/c3/stress_testing/baseline/CTU-Mixed-Capture-1_latency_over_time.png differ diff --git a/docs/images/immune/c3/stress_testing/baseline/CTU-Mixed-Capture-2_flows_per_min_for_all_profilers_combined.png b/docs/images/immune/c3/stress_testing/baseline/CTU-Mixed-Capture-2_flows_per_min_for_all_profilers_combined.png new file mode 100644 index 0000000000..7d28ca447a Binary files /dev/null and b/docs/images/immune/c3/stress_testing/baseline/CTU-Mixed-Capture-2_flows_per_min_for_all_profilers_combined.png differ diff --git a/docs/images/immune/c3/stress_testing/baseline/CTU-Mixed-Capture-2_flows_per_minute_for_each_profiler.png b/docs/images/immune/c3/stress_testing/baseline/CTU-Mixed-Capture-2_flows_per_minute_for_each_profiler.png new file mode 100644 index 0000000000..4b833e4431 Binary files /dev/null and b/docs/images/immune/c3/stress_testing/baseline/CTU-Mixed-Capture-2_flows_per_minute_for_each_profiler.png differ diff --git a/docs/images/immune/c3/stress_testing/baseline/CTU-Mixed-Capture-2_latency_over_time.png b/docs/images/immune/c3/stress_testing/baseline/CTU-Mixed-Capture-2_latency_over_time.png new file mode 100644 index 0000000000..76805f1ade Binary files /dev/null and b/docs/images/immune/c3/stress_testing/baseline/CTU-Mixed-Capture-2_latency_over_time.png differ diff --git a/docs/images/immune/c3/stress_testing/baseline/CTU-Normal-18_flows_per_min_for_all_profilers_combined.png b/docs/images/immune/c3/stress_testing/baseline/CTU-Normal-18_flows_per_min_for_all_profilers_combined.png new file mode 100644 index 0000000000..3ebbb4d48f Binary files /dev/null and b/docs/images/immune/c3/stress_testing/baseline/CTU-Normal-18_flows_per_min_for_all_profilers_combined.png differ diff --git a/docs/images/immune/c3/stress_testing/baseline/CTU-Normal-18_flows_per_minute_for_each_profiler.png b/docs/images/immune/c3/stress_testing/baseline/CTU-Normal-18_flows_per_minute_for_each_profiler.png new file mode 100644 index 0000000000..81dbf095ff Binary files /dev/null and b/docs/images/immune/c3/stress_testing/baseline/CTU-Normal-18_flows_per_minute_for_each_profiler.png differ diff --git a/docs/images/immune/c3/stress_testing/baseline/CTU-Normal-18_latency_over_time.png b/docs/images/immune/c3/stress_testing/baseline/CTU-Normal-18_latency_over_time.png new file mode 100644 index 0000000000..6b50992273 Binary files /dev/null and b/docs/images/immune/c3/stress_testing/baseline/CTU-Normal-18_latency_over_time.png differ diff --git a/docs/images/immune/c3/stress_testing/soak_testing/soak_testing_6_flows_per_min_for_all_profilers_combined.png b/docs/images/immune/c3/stress_testing/soak_testing/soak_testing_6_flows_per_min_for_all_profilers_combined.png new file mode 100644 index 0000000000..ee021a3360 Binary files /dev/null and b/docs/images/immune/c3/stress_testing/soak_testing/soak_testing_6_flows_per_min_for_all_profilers_combined.png differ diff --git a/docs/images/immune/c3/stress_testing/soak_testing/soak_testing_6_flows_per_minute_for_each_profiler.png b/docs/images/immune/c3/stress_testing/soak_testing/soak_testing_6_flows_per_minute_for_each_profiler.png new file mode 100644 index 0000000000..cf52a8465e Binary files /dev/null and b/docs/images/immune/c3/stress_testing/soak_testing/soak_testing_6_flows_per_minute_for_each_profiler.png differ diff --git a/docs/images/immune/c3/stress_testing/soak_testing/soak_testing_6_latency_over_time.png b/docs/images/immune/c3/stress_testing/soak_testing/soak_testing_6_latency_over_time.png new file mode 100644 index 0000000000..1f886c6d25 Binary files /dev/null and b/docs/images/immune/c3/stress_testing/soak_testing/soak_testing_6_latency_over_time.png differ diff --git a/docs/images/immune/c3/stress_testing/sudden_spikes/sudden_spikes_flows_per_min_for_all_profilers_combined.png b/docs/images/immune/c3/stress_testing/sudden_spikes/sudden_spikes_flows_per_min_for_all_profilers_combined.png new file mode 100644 index 0000000000..519a6cd0fb Binary files /dev/null and b/docs/images/immune/c3/stress_testing/sudden_spikes/sudden_spikes_flows_per_min_for_all_profilers_combined.png differ diff --git a/docs/images/immune/c3/stress_testing/sudden_spikes/sudden_spikes_flows_per_minute_for_each_profiler.png b/docs/images/immune/c3/stress_testing/sudden_spikes/sudden_spikes_flows_per_minute_for_each_profiler.png new file mode 100644 index 0000000000..325665293b Binary files /dev/null and b/docs/images/immune/c3/stress_testing/sudden_spikes/sudden_spikes_flows_per_minute_for_each_profiler.png differ diff --git a/docs/images/immune/c3/stress_testing/sudden_spikes/sudden_spikes_latency_over_time.png b/docs/images/immune/c3/stress_testing/sudden_spikes/sudden_spikes_latency_over_time.png new file mode 100644 index 0000000000..48cb5dbb2a Binary files /dev/null and b/docs/images/immune/c3/stress_testing/sudden_spikes/sudden_spikes_latency_over_time.png differ diff --git a/docs/immune/Immune.md b/docs/immune/Immune.md index 384e953197..621b5f6f4b 100644 --- a/docs/immune/Immune.md +++ b/docs/immune/Immune.md @@ -15,6 +15,7 @@ This is the main guide to the documentation related to the changes done to Slips - [Testing](https://stratospherelinuxips.readthedocs.io/en/develop/immune/testing.html) - [LLM Research and Selection](https://stratospherelinuxips.readthedocs.io/en/develop/immune/research_and_selection_of_llm_candidates.html) - [LLM RPI Performance](https://stratospherelinuxips.readthedocs.io/en/develop/immune/research_rpi_llm_performance.html) +- [Stress Testing](https://stratospherelinuxips.readthedocs.io/en/develop/immune/stress_testing.html) ### Security & Network Configuration diff --git a/docs/immune/stress_testing.md b/docs/immune/stress_testing.md new file mode 100644 index 0000000000..f02d3c887b --- /dev/null +++ b/docs/immune/stress_testing.md @@ -0,0 +1,287 @@ +# Stress Testing Slips + +- [Stress Testing Slips](#stress-testing-slips) + * [Goal](#goal) + * [Context](#context) + * [Baseline](#baseline) + + [Baseline experiments overview](#baseline-experiments-overview) + + [Baseline Experiment 1 - CTU-Mixed-Capture-1](#baseline-experiment-1---ctu-mixed-capture-1) + + [Baseline Experiment 2 - CTU-Mixed-Capture-2](#baseline-experiment-2---ctu-mixed-capture-2) + + [Baseline Experiment 3 - CTU-Normal-18](#baseline-experiment-3---ctu-normal-18) + + [Baseline conclusions](#baseline-conclusions) + * [Stress testing](#stress-testing) + + [Sudden traffic spikes](#sudden-traffic-spikes) + - [Sudden-spikes experiment overview](#sudden-spikes-experiment-overview) + - [Percentile metrics](#percentile-metrics) + - [Sudden-spikes plots and commentary](#sudden-spikes-plots-and-commentary) + - [Flows/min for all profilers combined](#flows-min-for-all-profilers-combined) + - [Flows/min for each profiler](#flows-min-for-each-profiler) + - [Latency over time](#latency-over-time) + - [Sudden-spikes conclusions](#sudden-spikes-conclusions) + + [Soak testing - sustained high traffic (scenario 2)](#soak-testing---sustained-high-traffic--scenario-2-) + - [Soak testing experiment overview](#soak-testing-experiment-overview) + - [Percentile metrics](#percentile-metrics-1) + - [Soak-testing plots and commentary](#soak-testing-plots-and-commentary) + - [Flows/min for all profilers combined](#flows-min-for-all-profilers-combined-1) + - [Flows/min for each profiler](#flows-min-for-each-profiler-1) + - [Latency over time](#latency-over-time-1) + - [Soak-testing conclusions](#soak-testing-conclusions) + * [Fixes](#fixes) + +## Goal + +The goal of the following expirements is to figure out the pressure at which Slips breaks. + +Slips breaks may take one of the following forms: + +**Soft Break** +The state of Slips at which Slips shows significantly reduced unacceptable performance. (for example, when input reading speed diverges from profiler throughput, or latency increases sharply). + +**Hard Break** +Complete system crash or failure of the Slips processes. + + +But before trying to break Slips, we first need to identify what is normal (the baseline). This answers the question, “How does Slips behave under normal conditions?” Then, during stress testing, when we observe something that deviates from the baseline, we can identify it easily. + +## Context + +In the following experiments we will be focusing mainly on the performance of the Input and Profilers of Slips as they are the two main performance bottlenecks, and we will be comparing them to the amount of flows slips receives to determin latency and speed issues. + +The latency we're interested in here means "how long did Slips take to detect a given attack after the attack was completed". + +Please check [how Slips works](https://stratospherelinuxips.readthedocs.io/en/develop/immune/performance_evaluation.html#how-slips-works) for context on what profilers/input process are. + +All throughput and latency plots in this document were generated with +`Debug.generate_performance_plots: true` in config/slips.yaml. +That flag makes Slips record extra performance CSVs during the run and render +the plots during shutdown. + +## Baseline + +### Baseline experiments overview + +We conducted 3 experiments on mixed traffic (normal and malicious) to measure slips performance. These PCAPs were chosen because they mimic normal user traffic. mostly benign with a few malicious/suspicious things going on every now and then. + + +
+ +| Experiment name | Input avg (flows/min) | Input peak (flows/min) | Profiler avg (flows/min) | Avg gap (input vs profiler) | Latency avg (seconds) | Latency p95 | Latency p99 | Max latency | Summary (plots + metrics) | +|---|---:|---:|---:|---:|---:|---:|---:|---:|---| +| CTU-Mixed-Capture-1 | 10,836.20 | 23,404 | 10,426.60 | 3.78% | 0.04 | 0 | 0 | 32 | Five throughput samples only; small average gap and only two non-zero latency samples. | +| CTU-Mixed-Capture-2 | 7,607.50 | 15,215 | 7,425.00 | 2.40% | 1.93 | 20 | 29 | 32 | Two throughput samples only; profiler drains backlog after input falls to zero and latency tail is short. | +| CTU-Normal-18 | 11,688.33 | 21,277 | 8,925.00 | 23.64% | 1.44 | 8.40 | 30 | 52 | Largest baseline throughput gap, but latency is still mostly zero aside from a few isolated spikes. | + +
+ + +### Baseline Experiment 1 - CTU-Mixed-Capture-1 + +**Traffic** + +https://mcfp.felk.cvut.cz/publicDatasets/CTU-Mixed-Capture-1/ + + +**Flows/min for all profilers combined** + +![](../images/immune/c3/stress_testing/baseline/CTU-Mixed-Capture-1_flows_per_min_for_all_profilers_combined.png) + +Input peaks at 23,404 flows/min, while combined profiler throughput peaks at 11,967 flows/min and continues draining after input drops to zero. + +**Flows/min for each profiler** + +![](../images/immune/c3/stress_testing/baseline/CTU-Mixed-Capture-1_flows_per_minute_for_each_profiler.png) + +The five profilers are closely balanced; their per-minute peaks range from 2,316 to 2,514 flows/min. + +**Latency over time** + +![](../images/immune/c3/stress_testing/baseline/CTU-Mixed-Capture-1_latency_over_time.png) + +Latency is effectively flat: 1,214 of 1,216 samples are 0s, with only two spikes at 18s and 32s. + +### Baseline Experiment 2 - CTU-Mixed-Capture-2 + +**Traffic** + +https://mcfp.felk.cvut.cz/publicDatasets/CTU-Mixed-Capture-2/ + +**Flows/min for all profilers combined** + +![](../images/immune/c3/stress_testing/baseline/CTU-Mixed-Capture-2_flows_per_min_for_all_profilers_combined.png) + +There are only two throughput samples: 15,215 input flows/min followed by a drain minute where profiler throughput reaches 9,636 flows/min after input is already zero. + +**Flows/min for each profiler** + +![](../images/immune/c3/stress_testing/baseline/CTU-Mixed-Capture-2_flows_per_minute_for_each_profiler.png) + +The workers remain fairly even during the drain minute, peaking between 1,876 and 2,080 flows/min. + +**Latency over time** + +![](../images/immune/c3/stress_testing/baseline/CTU-Mixed-Capture-2_latency_over_time.png) + +Latency is mostly 0s, with a short early tail up to 32s; p95 is 20s and p99 is 29s. + +### Baseline Experiment 3 - CTU-Normal-18 + +**Traffic** + +https://mcfp.felk.cvut.cz/publicDatasets/CTU-Normal-18/ + +**Flows/min for all profilers combined** + +![](../images/immune/c3/stress_testing/baseline/CTU-Normal-18_flows_per_min_for_all_profilers_combined.png) + +The first minute reaches 21,277 input flows/min versus 6,402 profiled, and the profilers keep draining until they peak at 10,355 flows/min after input stops. + +**Flows/min for each profiler** + +![](../images/immune/c3/stress_testing/baseline/CTU-Normal-18_flows_per_minute_for_each_profiler.png) + +Profiler load is still balanced overall, with worker 2 slightly ahead and peaking at 2,239 flows/min. + +**Latency over time** + +![](../images/immune/c3/stress_testing/baseline/CTU-Normal-18_latency_over_time.png) + +Most latency samples are 0s; the tail comes from a handful of spikes, including a single 52s maximum. + +--- + +### Baseline conclusions +| Check | Result | Reason | +|---|---|---| +| Soft Break FPS | Not reached in baseline | CTU-Mixed-Capture-1 and CTU-Mixed-Capture-2 stay at 3.78% and 2.40% average throughput gap. CTU-Normal-18 reaches a 23.64% gap, but its latency still stays mostly at 0s with p95 at 8.40s. | +| Hard Break | Not observed | All experiments produced metrics and plots; no indication of process failure in outputs. | + +--- + +## Stress testing + +Now we try to get Slips to break. + +### Sudden traffic spikes + + +This scenario covers sudden-spikes experiment. The input traffic pattern is designed to simulate sudden bursts of network activity, with spikes reaching up to 10,281 flows/min every 10 minutes. The goal is to evaluate how Slips handles these abrupt increases in load and whether it can maintain performance without significant degradation or failure. + +#### Sudden-spikes experiment overview +
+ +| Experiment name | Input avg (flows/min) | Input peak (flows/min) | Profiler avg (flows/min) | Profiler peak (flows/min) | Avg gap (input vs profiler) | Latency avg (seconds) | Latency p95 | Latency p99 | Summary (plots + metrics) | +|---|---:|---:|---:|---:|---:|---:|---:|---:|---| +| sudden_spikes | 439.08 | 10,281 | 439.07 | 10,281 | 0.0006% | 1,134.63 | 11,610 | 17,715 | Combined throughput almost perfectly matches input, but latency degrades severely late in the run. | + +
+ +#### Percentile metrics +
+ +| Metric | p50 | p95 | p99 | Avg | +|---|---:|---:|---:|---:| +| Input flows/min | 253.5 | 944.5 | 5,200.44 | 439.08 | +| Profiler flows/min (all) | 254.0 | 1,222.2 | 5,049.02 | 439.07 | +| Latency (seconds) | 166.0 | 11,610.0 | 17,715.0 | 1,134.63 | + +
+ +#### Sudden-spikes plots and commentary + +#### Flows/min for all profilers combined + +![](../images/immune/c3/stress_testing/sudden_spikes/sudden_spikes_flows_per_min_for_all_profilers_combined.png) + +The combined profiler series matches input exactly in 310 of 378 minutes; the visible mismatches are short catch-up periods immediately after large bursts. + +#### Flows/min for each profiler + +![](../images/immune/c3/stress_testing/sudden_spikes/sudden_spikes_flows_per_minute_for_each_profiler.png) + +Spike load is spread fairly evenly across the profilers, but worker 5 does not contribute until 10 minutes into the run. + +#### Latency over time + +![](../images/immune/c3/stress_testing/sudden_spikes/sudden_spikes_latency_over_time.png) + +Latency starts in the low hundreds of seconds and then explodes late in the run; the last quarter alone pushes p95 to 17,715s and the maximum to 17,718s. + +#### Sudden-spikes conclusions +| Check | Result | Reason | +|---|---|-----------------------------------------------------------------------------------------------------------------| +| Soft Break FPS | Reached (latency-driven) | Throughput keeps up with input, but latency rises to 19 mins on average with p95 at 11,610s and p99 at 17,715s. | +| Hard Break | Not observed | Metrics and plots are complete; no evidence of a process crash. | + + + +--- +### Soak testing - sustained high traffic (scenario 2) + +This scenario covers soak-testing experiment. The input traffic pattern is designed to simulate sustained high traffic activity. The goal is to evaluate how Slips handles these increases in load for a long period of time and whether it can maintain performance without significant degradation or failure. + +#### Soak testing experiment overview +
+ +| Experiment name | Input avg (flows/min) | Input peak (flows/min) | Profiler avg (flows/min) | Profiler peak (flows/min) | Avg gap (input vs profiler) | Latency avg (seconds) | Latency p95 | Latency p99 | Summary (plots + metrics) | +|---|---:|---:|---:|---:|---:|---:|---:|---:|---| +| soak_testing | 8,686.36 | 10,391 | 4,974.73 | 5,892 | 42.73% | 688.37 | 1,134.0 | 1,206.76 | Profiler throughput stays well below input throughout the run, and latency keeps rising instead of stabilizing. | + +
+ +#### Percentile metrics +
+ +| Metric | p50 | p95 | p99 | Avg | +|---|---:|---:|---:|---:| +| Input flows/min | 8,846.0 | 9,991.05 | 10,381.54 | 8,686.36 | +| Profiler flows/min (all) | 5,343.0 | 5,770.70 | 5,878.24 | 4,974.73 | +| Latency (seconds) | 708.0 | 1,134.0 | 1,206.76 | 688.37 | + +
+ +#### Soak-testing plots and commentary + + +#### Flows/min for all profilers combined +![](../images/immune/c3/stress_testing/soak_testing/soak_testing_6_flows_per_min_for_all_profilers_combined.png) + +Input stays high between 2,643 and 10,391 flows/min, while combined profiler throughput never exceeds 5,892 flows/min. + +#### Flows/min for each profiler + + +![](../images/immune/c3/stress_testing/soak_testing/soak_testing_6_flows_per_minute_for_each_profiler.png) + +Only workers 0-2 carry traffic at the start; workers 3, 4, and 5 begin contributing roughly 10, 15, and 20 minutes into the run because slips adds more workers the more throughput it detects. here, the throughput gap remains large. + +#### Latency over time + +![](../images/immune/c3/stress_testing/soak_testing/soak_testing_6_latency_over_time.png) + +Latency grows through the run instead of flattening. This is considered a soft break. Slips is unable to keep up a tolerable performance under constant heavy load. We consider this the main issue that needs to be solved. + + + +#### Soak-testing conclusions +| Check | Result | Reason | +|---|-------------|----------------------------------------| +| Soft Break FPS | Reached | Profiler throughput averages 4,974.73 flows/min against 8,686.36 input flows/min, and latency grows from a 708s median to a 2,166s maximum. | +| Hard Break | Not observed | The CSV series continue through the end of the run, so the data shows severe degradation but not a crash. | + + +## Fixes +After many experiments, trials and failures, and optimizations, we managed to get acceptable latency in Slips under high traffic + + +![](../images/immune/c3/stress_testing/after_optimizations.jpg) + +**PRs solving the above issues, and resource-related issues discovered while testing can be found here:** + +* DoS Protector: https://github.com/stratosphereips/StratosphereLinuxIPS/issues/1767 +* Latency issue https://github.com/stratosphereips/StratosphereLinuxIPS/issues/1838 and https://github.com/stratosphereips/StratosphereLinuxIPS/pull/1858 +* Incomplete processing of flows: https://github.com/stratosphereips/StratosphereLinuxIPS/issues/1848 + +Resource related issues: + +http://github.com/stratosphereips/StratosphereLinuxIPS/issues/1827 +https://github.com/stratosphereips/StratosphereLinuxIPS/issues/1815 diff --git a/docs/index.rst b/docs/index.rst index 14669fe5ac..51eb2d4625 100644 --- a/docs/index.rst +++ b/docs/index.rst @@ -17,6 +17,8 @@ This documentation gives an overview how Slips works, how to use it and how to h - **Detection modules**. Explanation of detection modules in Slips, types of input and output. See :doc:`Detection modules `. +- **Bruteforcing**. Dedicated documentation for the SSH bruteforcing detection module. See :doc:`Bruteforcing `. + - **HTTPS anomaly detection**. Detailed design and behavior of the HTTPS anomaly detector. See :doc:`HTTPS anomaly detection `. - **Architecture**. Internal architecture of Slips (profiles, timewindows), the use of Zeek and connection to Redis. See :doc:`Architecture `. @@ -51,6 +53,7 @@ This documentation gives an overview how Slips works, how to use it and how to h usage architecture detection_modules + bruteforcing https_anomaly_detection flowalerts features diff --git a/install/requirements.txt b/install/requirements.txt index e52f249fb0..92e9b3362e 100644 --- a/install/requirements.txt +++ b/install/requirements.txt @@ -36,7 +36,7 @@ yappi==1.7.3 pytest-sugar==1.1.1 aid_hash cachetools -black==25.9.0 +black==26.3.1 ruff==0.14.3 pre-commit==4.3.0 coverage==7.11.0 diff --git a/managers/process_manager.py b/managers/process_manager.py index 876809b9da..13e295f943 100644 --- a/managers/process_manager.py +++ b/managers/process_manager.py @@ -37,6 +37,7 @@ from slips_files.common.abstracts.imodule import ( IModule, ) +from slips_files.common.plotter import Plotter from slips_files.common.style import green from slips_files.common.input_type import InputType @@ -786,6 +787,13 @@ def shutdown_gracefully(self): """ try: print = self.get_print_function() + if self.main.conf.generate_performance_plots() is True: + self.plotter = Plotter(self.main.args.output, print) + self.plotter.plot_latency_csv() + self.plotter.plot_profiler_latency_csvs() + self.plotter.plot_throughput_csv() + self.plotter.write_throughput_metrics() + self.plotter.plot_flows_from_conn_log() if not self.main.args.stopdaemon: print("\n" + "-" * 27) diff --git a/managers/redis_manager.py b/managers/redis_manager.py index 4ed104b17a..49fd8306ee 100644 --- a/managers/redis_manager.py +++ b/managers/redis_manager.py @@ -334,7 +334,13 @@ def print_open_redis_servers(self): file, port, pid = line[1], line[2], line[3] there_are_ports_to_print = True to_print += f"[{line_number}] {file} - port {port}\n" - open_servers[line_number] = (int(port), int(pid)) + try: + open_servers[line_number] = (int(port), int(pid)) + except ValueError: + # sometimes slips can't get the server pid and logs "False" + # in the logfile instead of the PID + # there's nothing we can do about it, we just skip this line + pass except FileNotFoundError: print( f"{self.running_logfile} is not found. Can't get open redis servers. Stopping." diff --git a/modules/bruteforcing/__init__.py b/modules/bruteforcing/__init__.py new file mode 100644 index 0000000000..8b13789179 --- /dev/null +++ b/modules/bruteforcing/__init__.py @@ -0,0 +1 @@ + diff --git a/modules/bruteforcing/bruteforcing.py b/modules/bruteforcing/bruteforcing.py new file mode 100644 index 0000000000..017026ef2d --- /dev/null +++ b/modules/bruteforcing/bruteforcing.py @@ -0,0 +1,466 @@ +# SPDX-FileCopyrightText: 2021 Sebastian Garcia +# SPDX-License-Identifier: GPL-2.0-only + +import json +import math +import re +from dataclasses import dataclass, field +from typing import Dict, List + +from slips_files.common.abstracts.imodule import IModule +from slips_files.common.flow_classifier import FlowClassifier +from slips_files.common.parsers.config_parser import ConfigParser +from slips_files.common.slips_utils import utils +from slips_files.core.structures.evidence import ( + Attacker, + Direction, + Evidence, + EvidenceType, + IoCType, + ProfileID, + Proto, + ThreatLevel, + TimeWindow, + Victim, +) + + +AUTOMATION_BANNER_TOKENS = ( + "libssh", + "libssh2", + "paramiko", + "hydra", + "medusa", + "ncrack", + "net::ssh", + "net-ssh", + "asyncssh", + "jsch", + "sshj", +) + +KNOWN_CLIENT_BANNER_TOKENS = ( + "openssh", + "putty", + "dropbear", + "winscp", +) + + +@dataclass +class SSHBruteforceCampaign: + profileid: str + twid: str + saddr: str + daddr: str + dport: str + first_timestamp: str + last_timestamp: str + attempts: int = 0 + uids: List[str] = field(default_factory=list) + reported_bucket: int = -1 + + +class Bruteforcing(IModule): + name = "Bruteforcing" + description = ( + "Detect SSH bruteforcing using ssh.log, software.log, and Zeek notices." + ) + authors = ["Sebastian Garcia", "OpenAI"] + ssh_full_confidence_attempts = 30 + + def init(self): + self.classifier = FlowClassifier() + self.campaigns: Dict[str, SSHBruteforceCampaign] = {} + self.client_software: Dict[str, Dict[str, str]] = {} + self.zeek_confirmations: Dict[str, Dict[str, str]] = {} + self.read_configuration() + + def subscribe_to_channels(self): + self.c1 = self.db.subscribe("new_ssh") + self.c2 = self.db.subscribe("new_software") + self.c3 = self.db.subscribe("new_notice") + self.c4 = self.db.subscribe("tw_closed") + self.channels = { + "new_ssh": self.c1, + "new_software": self.c2, + "new_notice": self.c3, + "tw_closed": self.c4, + } + + def pre_main(self): + utils.drop_root_privs_permanently() + + def read_configuration(self): + conf = ConfigParser() + self.ssh_attempt_threshold = conf.ssh_bruteforcing_threshold() + + @staticmethod + def _campaign_key(profileid: str, twid: str, daddr: str, dport: str) -> str: + return f"{profileid}_{twid}:dst:{daddr}:dport:{dport}" + + @staticmethod + def _source_tw_key(profileid: str, twid: str) -> str: + return f"{profileid}_{twid}" + + @staticmethod + def _is_successful_ssh(flow) -> bool: + return str(flow.auth_success).lower() in ("true", "t") + + @staticmethod + def _is_failed_ssh(flow) -> bool: + return str(flow.auth_success).lower() in ("false", "f") + + @staticmethod + def _get_twid_number(twid: str) -> int: + return int(str(twid).replace("timewindow", "")) + + @staticmethod + def _format_client_banner(software_name: str, version: str) -> str: + parts = [] + if software_name: + parts.append(software_name) + if version and version not in parts: + parts.append(version) + return " ".join(parts).strip() + + def _parse_attempt_increment(self, flow) -> int: + try: + auth_attempts = int(flow.auth_attempts or 0) + except (TypeError, ValueError): + auth_attempts = 0 + + if self._is_successful_ssh(flow): + return 0 + + if auth_attempts <= 0: + # Some SSH bruteforce tools trigger repeated SSH sessions where + # Zeek does not record auth attempts or auth_success. Count each + # non-successful session as one suspected password attempt. + return 1 + + if self._is_failed_ssh(flow): + return auth_attempts + + # If Zeek observed auth attempts but did not mark the session as + # successful, treat them as failed attempts. + return auth_attempts + + def _get_reporting_bucket(self, attempts: int) -> int: + if attempts < self.ssh_attempt_threshold: + return -1 + # Emit frequently near the threshold, then increasingly sparsely. + return int(math.log2(max(1, attempts - self.ssh_attempt_threshold + 1))) + + def _get_banner_bonus(self, banner: str, source: str) -> float: + if not banner: + return 0.0 + + bonus = 0.0 + if source == "software.log": + bonus += 0.03 + + normalized_banner = banner.lower() + if any(token in normalized_banner for token in AUTOMATION_BANNER_TOKENS): + bonus += 0.07 + elif any( + token in normalized_banner for token in KNOWN_CLIENT_BANNER_TOKENS + ): + bonus += 0.02 + + return min(0.1, bonus) + + def _get_banner_context(self, flow) -> Dict[str, str]: + software_info = self.client_software.get(flow.saddr, {}) + if software_info: + return { + "banner": software_info["banner"], + "source": "software.log", + } + + banner = flow.client or "" + return {"banner": banner, "source": "ssh.log" if banner else ""} + + def _calculate_confidence( + self, + attempts: int, + banner: str, + banner_source: str, + confirmed_attempts: int = 0, + ) -> float: + effective_attempts = max(attempts, confirmed_attempts) + full_confidence_attempts = max( + self.ssh_attempt_threshold, + self.ssh_full_confidence_attempts, + ) + + if effective_attempts >= full_confidence_attempts: + return 1.0 + + attempts_ratio = min( + 1.0, + max(0, effective_attempts - self.ssh_attempt_threshold) + / max( + 1, + full_confidence_attempts - self.ssh_attempt_threshold, + ), + ) + confidence = 0.5 + (0.4 * attempts_ratio) + confidence += self._get_banner_bonus(banner, banner_source) + return round(min(0.99, confidence), 2) + + @staticmethod + def _parse_confirmed_attempts(value) -> int: + try: + return int(value or 0) + except (TypeError, ValueError): + return 0 + + def _parse_port(self, port) -> int: + try: + return int(port) + except (TypeError, ValueError): + return None + + def _get_port_label(self, dport: str) -> str: + if not dport: + return "" + portproto = f"{dport}/tcp" + port_info = self.db.get_port_info(portproto) or "" + return f"{port_info} {portproto}".strip() + + def _build_campaign_description( + self, + campaign: SSHBruteforceCampaign, + banner: str, + banner_source: str, + confidence: float, + zeek_confirmed: bool, + ) -> str: + port_label = self._get_port_label(campaign.dport) + target = campaign.daddr or "an SSH server" + destination = ( + f"{target} on {port_label}" if port_label else target + ) + description = ( + f"SSH bruteforcing from {campaign.saddr} to {destination}. " + f"Attempts observed: {campaign.attempts}." + ) + if banner: + description += ( + f" Client banner: {banner}" + f"{f' from {banner_source}' if banner_source else ''}." + ) + if zeek_confirmed: + description += " Confirmed by Zeek notice.log." + description += f" Confidence: {confidence}. by Slips" + return description + + def _set_campaign_evidence( + self, + campaign: SSHBruteforceCampaign, + banner: str, + banner_source: str, + ): + source_key = self._source_tw_key(campaign.profileid, campaign.twid) + confirmation = self.zeek_confirmations.get(source_key, {}) + zeek_confirmed = bool(confirmation) + confirmed_attempts = self._parse_confirmed_attempts( + confirmation.get("attempts") + ) + confidence = self._calculate_confidence( + campaign.attempts, + banner, + banner_source, + confirmed_attempts=confirmed_attempts, + ) + description = self._build_campaign_description( + campaign, banner, banner_source, confidence, zeek_confirmed + ) + + evidence = Evidence( + evidence_type=EvidenceType.PASSWORD_GUESSING, + attacker=Attacker( + direction=Direction.SRC, + ioc_type=IoCType.IP, + value=campaign.saddr, + ), + victim=Victim( + direction=Direction.DST, + ioc_type=IoCType.IP, + value=campaign.daddr, + ) + if utils.is_valid_ip(campaign.daddr) + else False, + threat_level=ThreatLevel.MEDIUM, + confidence=confidence, + description=description, + profile=ProfileID(ip=campaign.saddr), + timewindow=TimeWindow(number=self._get_twid_number(campaign.twid)), + uid=campaign.uids, + timestamp=campaign.last_timestamp, + proto=Proto.TCP, + dst_port=self._parse_port(campaign.dport), + ) + self.db.set_evidence(evidence) + + def _set_notice_evidence(self, profileid: str, twid: str, flow): + srcip = flow.saddr + description = ( + f"SSH bruteforcing. {flow.msg}. " + f"Confirmed by Zeek notice.log. Confidence: 1.0. by Zeek" + ) + evidence = Evidence( + evidence_type=EvidenceType.PASSWORD_GUESSING, + attacker=Attacker( + direction=Direction.SRC, + ioc_type=IoCType.IP, + value=srcip, + ), + threat_level=ThreatLevel.MEDIUM, + confidence=1.0, + description=description, + profile=ProfileID(ip=srcip), + timewindow=TimeWindow(number=self._get_twid_number(twid)), + uid=[flow.uid], + timestamp=flow.starttime, + ) + self.db.set_evidence(evidence) + self.zeek_confirmations[self._source_tw_key(profileid, twid)][ + "reported" + ] = "true" + + @staticmethod + def _parse_notice_attempts(msg: str) -> int: + match = re.search(r"seen in (\d+) connections", msg or "") + if not match: + return 0 + return int(match.group(1)) + + def _cache_client_software(self, flow): + if flow.software != "SSH::CLIENT": + return + + banner = self._format_client_banner( + flow.software_name, flow.unparsed_version + ) + if not banner: + return + + self.client_software[flow.saddr] = { + "banner": banner, + "software_name": flow.software_name, + "unparsed_version": flow.unparsed_version, + } + + def _handle_software(self, flow): + if not utils.is_valid_ip(flow.saddr): + return + self._cache_client_software(flow) + + def _handle_notice(self, profileid: str, twid: str, flow): + if "Password_Guessing" not in flow.note: + return + + if not utils.is_valid_ip(flow.saddr): + return + + profileid = f"profile_{flow.saddr}" + + source_key = self._source_tw_key(profileid, twid) + confirmation = self.zeek_confirmations.setdefault( + source_key, + { + "msg": flow.msg, + "attempts": str(self._parse_notice_attempts(flow.msg)), + "reported": "false", + }, + ) + confirmation["msg"] = flow.msg + confirmation["attempts"] = str( + max(int(confirmation["attempts"]), self._parse_notice_attempts(flow.msg)) + ) + + if confirmation["reported"] != "true": + self._set_notice_evidence(profileid, twid, flow) + + def _handle_ssh(self, profileid: str, twid: str, flow): + if not utils.is_valid_ip(flow.saddr): + return + + profileid = f"profile_{flow.saddr}" + + attempt_increment = self._parse_attempt_increment(flow) + if attempt_increment <= 0: + return + + if not flow.daddr: + return + + dport = str(flow.dport or "") + campaign_key = self._campaign_key(profileid, twid, flow.daddr, dport) + campaign = self.campaigns.get(campaign_key) + if not campaign: + campaign = SSHBruteforceCampaign( + profileid=profileid, + twid=twid, + saddr=flow.saddr, + daddr=flow.daddr, + dport=dport, + first_timestamp=flow.starttime, + last_timestamp=flow.starttime, + ) + self.campaigns[campaign_key] = campaign + + campaign.attempts += attempt_increment + campaign.last_timestamp = flow.starttime + if flow.uid: + campaign.uids.append(flow.uid) + + bucket = self._get_reporting_bucket(campaign.attempts) + if bucket <= campaign.reported_bucket: + return + + campaign.reported_bucket = bucket + banner_context = self._get_banner_context(flow) + self._set_campaign_evidence( + campaign, + banner_context["banner"], + banner_context["source"], + ) + + def cleanup_cache_dicts(self, profile_tw: List[str]): + profile_tw = "_".join(profile_tw) + self.campaigns = { + key: value + for key, value in self.campaigns.items() + if profile_tw not in key + } + self.zeek_confirmations = { + key: value + for key, value in self.zeek_confirmations.items() + if profile_tw not in key + } + + def main(self): + if msg := self.get_msg("new_software"): + data = json.loads(msg["data"]) + flow = self.classifier.convert_to_flow_obj(data["flow"]) + self._handle_software(flow) + + if msg := self.get_msg("new_notice"): + data = json.loads(msg["data"]) + profileid = data["profileid"] + twid = data["twid"] + flow = self.classifier.convert_to_flow_obj(data["flow"]) + self._handle_notice(profileid, twid, flow) + + if msg := self.get_msg("new_ssh"): + data = json.loads(msg["data"]) + profileid = data["profileid"] + twid = data["twid"] + flow = self.classifier.convert_to_flow_obj(data["flow"]) + self._handle_ssh(profileid, twid, flow) + + if msg := self.get_msg("tw_closed"): + self.cleanup_cache_dicts(msg["data"].split("_")) diff --git a/modules/flowalerts/conn.py b/modules/flowalerts/conn.py index e25f35f5ca..ba021112e5 100644 --- a/modules/flowalerts/conn.py +++ b/modules/flowalerts/conn.py @@ -189,7 +189,8 @@ def check_unknown_port(self, profileid, twid, flow): # scanned from this attacker return False - portproto = f"{flow.dport}/{flow.proto}" + proto = str(flow.proto or "").lower() + portproto = f"{flow.dport}/{proto}" if self.db.get_port_info(portproto): # it's a known port return False @@ -201,7 +202,7 @@ def check_unknown_port(self, profileid, twid, flow): return False if ( - "icmp" not in flow.proto + "icmp" not in proto and not self.is_p2p(flow) and not self.db.is_ftp_port(flow.dport) ): diff --git a/modules/flowalerts/notice.py b/modules/flowalerts/notice.py index cf38dfd69f..a580b8718b 100644 --- a/modules/flowalerts/notice.py +++ b/modules/flowalerts/notice.py @@ -48,5 +48,4 @@ def analyze(self, msg): self.check_vertical_portscan(twid, flow) self.check_horizontal_portscan(flow, profileid, twid) - self.check_password_guessing(twid, flow) return True diff --git a/modules/flowalerts/ssh.py b/modules/flowalerts/ssh.py index 513397c396..abbd3d4c4b 100644 --- a/modules/flowalerts/ssh.py +++ b/modules/flowalerts/ssh.py @@ -13,10 +13,7 @@ class SSH(IFlowalertsAnalyzer): def init(self): - # after this number of failed ssh logins, we alert pw guessing - self.pw_guessing_threshold = 20 self.read_configuration() - self.password_guessing_cache = {} self.classifier = FlowClassifier() def name(self) -> str: @@ -91,39 +88,12 @@ async def check_successful_ssh(self, twid, flow): else: self.detect_successful_ssh_by_slips(twid, conn_log_flow, flow) - def check_ssh_password_guessing(self, profileid, twid, flow): - """ - This detection is only done when there's a failed ssh attempt - alerts ssh pw bruteforce when there's more than - 20 failed attempts by the same ip to the same IP - """ - if flow.auth_success in ("true", "T"): - return False - - cache_key = f"{profileid}-{twid}-{flow.daddr}" - # update the number of times this ip performed a failed ssh login - if cache_key in self.password_guessing_cache: - self.password_guessing_cache[cache_key].append(flow.uid) - else: - self.password_guessing_cache = {cache_key: [flow.uid]} - - conn_count = len(self.password_guessing_cache[cache_key]) - - if conn_count >= self.pw_guessing_threshold: - - uids = self.password_guessing_cache[cache_key] - self.set_evidence.ssh_pw_guessing(flow, twid, uids) - # reset the counter - del self.password_guessing_cache[cache_key] - async def analyze(self, msg): if not utils.is_msg_intended_for(msg, "new_ssh"): return msg = json.loads(msg["data"]) - profileid = msg["profileid"] twid = msg["twid"] flow = self.classifier.convert_to_flow_obj(msg["flow"]) self.flowalerts.create_task(self.check_successful_ssh, twid, flow) - self.check_ssh_password_guessing(profileid, twid, flow) diff --git a/modules/network_discovery/network_discovery.py b/modules/network_discovery/network_discovery.py index 841dc8d187..7931b44a51 100644 --- a/modules/network_discovery/network_discovery.py +++ b/modules/network_discovery/network_discovery.py @@ -43,12 +43,12 @@ def init(self): self.classifier = FlowClassifier() def subscribe_to_channels(self): - self.c1 = self.db.subscribe("tw_modified") + self.c1 = self.db.subscribe("new_flow") self.c2 = self.db.subscribe("new_notice") self.c3 = self.db.subscribe("new_dhcp") self.c4 = self.db.subscribe("tw_closed") self.channels = { - "tw_modified": self.c1, + "new_flow": self.c1, "new_notice": self.c2, "new_dhcp": self.c3, "tw_closed": self.c4, @@ -191,7 +191,7 @@ def pre_main(self): utils.drop_root_privs_permanently() def main(self): - if msg := self.get_msg("tw_modified"): + if msg := self.get_msg("new_flow"): msg = json.loads(msg["data"]) profileid = msg["profileid"] twid = msg["twid"] diff --git a/modules/timeline/timeline.py b/modules/timeline/timeline.py index b09b1412cd..210e44c1df 100644 --- a/modules/timeline/timeline.py +++ b/modules/timeline/timeline.py @@ -354,14 +354,12 @@ def pre_main(self): def main(self): for _ in range(self._new_flow_msgs_batch_size): - msg = self.get_msg("new_flow") - if not msg: - break - msg = json.loads(msg["data"]) - profileid = msg["profileid"] - twid = msg["twid"] - flow = self.classifier.convert_to_flow_obj(msg["flow"]) - self.process_flow(profileid, twid, flow) + if msg := self.get_msg("new_flow"): + msg = json.loads(msg["data"]) + profileid = msg["profileid"] + twid = msg["twid"] + flow = self.classifier.convert_to_flow_obj(msg["flow"]) + self.process_flow(profileid, twid, flow) def _cache_get(self, cache: OrderedDict, key): if key in cache: diff --git a/slips/main.py b/slips/main.py index 6aa219b9e4..4bd2376958 100644 --- a/slips/main.py +++ b/slips/main.py @@ -22,6 +22,7 @@ from managers.redis_manager import RedisManager from managers.ui_manager import UIManager from slips_files.common.parsers.config_parser import ConfigParser +from slips_files.common.performance_paths import get_performance_plots_dir from slips_files.common.printer import Printer from slips_files.common.slips_utils import utils from slips_files.common.style import green, yellow @@ -428,8 +429,11 @@ def get_analyzed_flows_percentage(self) -> str: processed = self.db.get_flow_analyzed_by_the_profiler_so_far() if not processed: return "" + try: + percentage = (processed / self.total_flows) * 100 + except ZeroDivisionError: + return "" - percentage = (processed / self.total_flows) * 100 # in very large pcaps, thousands of flows are nothing compared to # the tot flows, so if the percentage is int, slips would print 0% # for a while, so we take the first number after the floating point @@ -694,6 +698,12 @@ def sig_handler(sig, frame): "of traffic by querying TI sites." ) + if self.conf.generate_performance_plots(): + self.print( + f"Slips will generate performance plots on shutdown in " + f"{green(get_performance_plots_dir(self.args.output))}." + ) + while (not self.proc_man.should_stop_slips()) and ( not self.sigterm_received ): diff --git a/slips_files/common/parsers/config_parser.py b/slips_files/common/parsers/config_parser.py index 2bd7fb5e5d..997543b92a 100644 --- a/slips_files/common/parsers/config_parser.py +++ b/slips_files/common/parsers/config_parser.py @@ -302,6 +302,11 @@ def debug(self): debug = 0 return debug + def generate_performance_plots(self) -> bool: + return self.read_configuration( + "Debug", "generate_performance_plots", False + ) + def export_to(self): return self.read_configuration("exporting_alerts", "export_to", []) @@ -462,6 +467,16 @@ def ssh_succesful_detection_threshold(self): return threshold + def ssh_bruteforcing_threshold(self): + threshold = self.read_configuration( + "bruteforcing", "ssh_attempt_threshold", 9 + ) + try: + threshold = int(threshold) + except ValueError: + threshold = 9 + return max(1, threshold) + def data_exfiltration_threshold(self): """ returns threshold in MBs diff --git a/slips_files/common/performance_paths.py b/slips_files/common/performance_paths.py new file mode 100644 index 0000000000..0da8c66bd9 --- /dev/null +++ b/slips_files/common/performance_paths.py @@ -0,0 +1,27 @@ +# SPDX-FileCopyrightText: 2021 Sebastian Garcia +# SPDX-License-Identifier: GPL-2.0-only +import os + + +PERFORMANCE_PLOTS_DIRNAME = "performance_plots" +PERFORMANCE_CSV_DIRNAME = "csv" + + +def get_performance_plots_dir(output_dir: str) -> str: + return os.path.join(output_dir or "", PERFORMANCE_PLOTS_DIRNAME) + + +def get_performance_csv_dir(output_dir: str) -> str: + """ + csv files used for generating the plots go into + output/performance_plots/csv/ + This func returns that path + """ + return os.path.join( + get_performance_plots_dir(output_dir), PERFORMANCE_CSV_DIRNAME + ) + + +def get_performance_csv_path(output_dir: str, filename: str) -> str: + """returns the full path to the given filename inside the csv dir""" + return os.path.join(get_performance_csv_dir(output_dir), filename) diff --git a/slips_files/common/plotter.py b/slips_files/common/plotter.py new file mode 100644 index 0000000000..74910e0ebe --- /dev/null +++ b/slips_files/common/plotter.py @@ -0,0 +1,469 @@ +# SPDX-FileCopyrightText: 2021 Sebastian Garcia +# SPDX-License-Identifier: GPL-2.0-only +import csv +import glob +import math +import os +import statistics +import subprocess +import sys + +from slips_files.common.performance_paths import ( + get_performance_csv_dir, + get_performance_csv_path, + get_performance_plots_dir, +) + + +class Plotter: + def __init__(self, output_dir, print_func): + self.output_dir = output_dir or "" + self.print = print_func + self.plots_dir = get_performance_plots_dir(self.output_dir) + self.csv_dir = get_performance_csv_dir(self.output_dir) + + def plot_latency_csv(self): + latency_path = get_performance_csv_path(self.output_dir, "latency.csv") + if not self._is_valid_input(latency_path): + return + + ts_values = [] + latency_values = [] + try: + with open(latency_path, newline="") as csv_file: + reader = csv.DictReader(csv_file) + for row in reader: + ts = row.get("ts") + latency = row.get("latency") + if ts is None or latency is None: + continue + try: + ts_values.append(float(ts)) + latency_values.append(float(latency)) + except ValueError: + continue + except Exception as exc: + self._log(f"[Plotter] Failed to read latency.csv: {exc}") + return + + if not ts_values: + return + + output_path = os.path.join( + self.plots_dir, "latency_of_each_evidence_from_alerts_json.png" + ) + self._save_plot( + output_path, + ts_values, + {"latency": latency_values}, + xlabel="ts", + ylabel="latency", + title="Latency", + ) + + def plot_profiler_latency_csvs(self): + if not self.output_dir: + return + + csv_paths = sorted( + glob.glob( + os.path.join(self.csv_dir, "profiler_worker_*_latency.csv") + ) + ) + if not csv_paths: + return + + os.makedirs(self.plots_dir, exist_ok=True) + output_path = os.path.join( + self.plots_dir, "all_profiler_workers_latency.png" + ) + + try: + import matplotlib + + matplotlib.use("Agg") + from matplotlib import pyplot as plt + except Exception as exc: + self._log(f"[Plotter] Skipping plot {output_path}: {exc}") + return + + try: + plt.figure(figsize=(10, 4)) + plotted_any_series = False + + for csv_path in csv_paths: + ts_values = [] + latency_values = [] + with open(csv_path, newline="", encoding="utf-8") as csv_file: + reader = csv.DictReader(csv_file) + for row in reader: + try: + ts_values.append(float(row["timestamp_now"])) + latency_values.append( + float(row["latency_in_seconds"]) + ) + except (KeyError, TypeError, ValueError): + continue + + if not ts_values: + continue + + label = os.path.basename(csv_path).replace("_latency.csv", "") + plt.plot(ts_values, latency_values, linewidth=1.0, label=label) + plotted_any_series = True + + if not plotted_any_series: + plt.close() + return + + plt.xlabel("timestamp_now") + plt.ylabel("latency_in_seconds") + plt.title("Profiler latency") + plt.legend(fontsize="small", ncol=2) + plt.tight_layout() + plt.savefig(output_path, format="png") + plt.close() + self._log(f"[Plotter] Saved plot to {output_path}") + except Exception as exc: + self._log(f"[Plotter] Failed to save plot {output_path}: {exc}") + + def write_latency_metrics(self, metrics_path=None): + latency_path = get_performance_csv_path(self.output_dir, "latency.csv") + if not self.output_dir or not os.path.exists(latency_path): + return + + latency_values = [] + try: + with open(latency_path, newline="") as csv_file: + reader = csv.DictReader(csv_file) + if not reader.fieldnames or "latency" not in reader.fieldnames: + return + for row in reader: + raw_latency = row.get("latency") + try: + latency_values.append(float(raw_latency)) + except (TypeError, ValueError): + pass + except Exception as exc: + self._log(f"[Plotter] Failed to read latency.csv: {exc}") + return + + latency_p50 = self._percentile(latency_values, 50) + latency_p95 = self._percentile(latency_values, 95) + latency_p99 = self._percentile(latency_values, 99) + latency_avg = self._average(latency_values) + + if metrics_path is None: + metrics_path = os.path.join(self.output_dir, "metrics.txt") + lines = [ + "latency.cs:v metrics:", + f"p50 for latency: {self._format_metric(latency_p50)}", + f"p95 for latency: {self._format_metric(latency_p95)}", + f"p99 for latency: {self._format_metric(latency_p99)}", + f"avg for latency: {self._format_metric(latency_avg)}", + "\n\n", + ] + try: + with open(metrics_path, "a", encoding="utf-8") as handle: + handle.write("\n".join(lines) + "\n") + except Exception as exc: + self._log(f"[Plotter] Failed to write metrics.txt: {exc}") + + def plot_throughput_csv(self): + throughput_path = get_performance_csv_path( + self.output_dir, "flows_per_minute.csv" + ) + if not self._is_valid_input(throughput_path): + return + + ts_values = [] + series = {} + profiler_columns = [] + try: + with open(throughput_path, newline="") as csv_file: + reader = csv.DictReader(csv_file) + if not reader.fieldnames or "ts" not in reader.fieldnames: + return + + # recognize profiler columns + for column in reader.fieldnames: + if column == "ts": + continue + series[column] = [] + if column.startswith("profiler_flows_per_min_worker"): + profiler_columns.append(column) + + for row in reader: + ts = row.get("ts") + if ts is None: + continue + try: + ts_values.append(float(ts)) + except ValueError: + continue + + for column in series: + raw_value = row.get(column) + try: + series[column].append(float(raw_value)) + except (TypeError, ValueError): + series[column].append(float("nan")) + except Exception as exc: + self._log(f"[Plotter] Failed to read flows_per_minute.csv: {exc}") + return + + if not ts_values: + return + + labeled_series = {} + for column, values in series.items(): + label = column + if column == "input_flows_per_min": + label = "input" + elif column.startswith("profiler_flows_per_min_worker"): + suffix = column.replace("profiler_flows_per_min_worker", "") + label = f"profiler{suffix}" + labeled_series[label] = values + + throughput_output_path = os.path.join( + self.plots_dir, "input_proc_flows_per_min.png" + ) + self._save_plot( + throughput_output_path, + ts_values, + labeled_series, + xlabel="ts", + ylabel="flows_per_min", + title="Flows per minute", + ) + + if profiler_columns: + profiler_sum = [] + for idx in range(len(ts_values)): + total = 0.0 + for column in profiler_columns: + try: + value = series[column][idx] + except IndexError: + value = float("nan") + if value == value: + total += value + profiler_sum.append(total) + + combined_output_path = os.path.join( + self.plots_dir, + "flows_per_minute_seen_by_all_profilers_combined.png", + ) + self._save_plot( + combined_output_path, + ts_values, + {"combined": profiler_sum}, + xlabel="ts", + ylabel="flows_per_min", + title="flows_per_minute_for_all_profilers.csv combined", + ) + + def write_throughput_metrics(self): + throughput_path = get_performance_csv_path( + self.output_dir, "flows_per_minute.csv" + ) + if not self.output_dir or not os.path.exists(throughput_path): + return + + input_values = [] + profiler_sums = [] + profiler_columns = [] + try: + with open(throughput_path, newline="") as csv_file: + reader = csv.DictReader(csv_file) + if not reader.fieldnames or "ts" not in reader.fieldnames: + return + + for column in reader.fieldnames: + if column.startswith("profiler_flows_per_min"): + profiler_columns.append(column) + + for row in reader: + raw_input = row.get("input_flows_per_min") + try: + input_values.append(float(raw_input)) + except (TypeError, ValueError): + pass + + total = 0.0 + for column in profiler_columns: + raw_value = row.get(column) + try: + value = float(raw_value) + except (TypeError, ValueError): + continue + if not math.isnan(value): + total += value + profiler_sums.append(total) + except Exception as exc: + self._log(f"[Plotter] Failed to read flows_per_minute.csv: {exc}") + return + + input_p50 = self._percentile(input_values, 50) + input_p95 = self._percentile(input_values, 95) + input_p99 = self._percentile(input_values, 99) + input_avg = self._average(input_values) + profiler_p50 = self._percentile(profiler_sums, 50) + profiler_p95 = self._percentile(profiler_sums, 95) + profiler_p99 = self._percentile(profiler_sums, 99) + profiler_avg = self._average(profiler_sums) + + metrics_path = os.path.join(self.output_dir, "metrics.txt") + lines = [ + "flows_per_minute.csv metrics:", + f"p50 for input: {self._format_metric(input_p50)}", + f"p95 for input: {self._format_metric(input_p95)}", + f"p99 for input: {self._format_metric(input_p99)}", + f"avg for input: {self._format_metric(input_avg)}", + ("p50 for all profilers: " f"{self._format_metric(profiler_p50)}"), + ("p95 for all profilers: " f"{self._format_metric(profiler_p95)}"), + ("p99 for all profilers: " f"{self._format_metric(profiler_p99)}"), + ("avg for all profilers: " f"{self._format_metric(profiler_avg)}"), + "\n\n", + ] + try: + with open(metrics_path, "w", encoding="utf-8") as handle: + handle.write("\n".join(lines) + "\n") + except Exception as exc: + self._log(f"[Plotter] Failed to write metrics.txt: {exc}") + return + + self.write_latency_metrics(metrics_path=metrics_path) + + def plot_flows_from_conn_log(self): + conn_log = os.path.join(self.output_dir, "zeek_files", "conn.log") + if not os.path.exists(conn_log): + return + + os.makedirs(self.plots_dir, exist_ok=True) + output_plot = os.path.join( + self.plots_dir, "flows_per_second_seen_in_conn_log.png" + ) + # Assuming stress_testing_scripts is in the project root. + # This file is in slips_files/common/plotter.py + # So project root is 2 levels up. + current_dir = os.path.dirname(os.path.abspath(__file__)) + project_root = os.path.abspath(os.path.join(current_dir, "../..")) + script_path = os.path.join( + project_root, "stress_testing_scripts", "plot_flows_over_time.py" + ) + + if not os.path.exists(script_path): + self._log( + f"[Plotter] Could not find plot_flows_over_time.py at " + f"{script_path}" + ) + return + + cmd = [ + sys.executable, + script_path, + "--conn-log", + conn_log, + "--output", + output_plot, + ] + + try: + subprocess.run( + cmd, check=True, stdout=subprocess.PIPE, stderr=subprocess.PIPE + ) + self._log(f"[Plotter] Saved flows over time plot to {output_plot}") + except subprocess.CalledProcessError as e: + self._log( + f"[Plotter] Failed to run plot_flows_over_time.py: {e.stderr}" + ) + except Exception as exc: + self._log( + f"[Plotter] Error running plot_flows_over_time.py: {exc}" + ) + + def _is_valid_input(self, csv_path): + if not self.output_dir: + return False + if not os.path.exists(csv_path): + return False + os.makedirs(self.plots_dir, exist_ok=True) + return True + + def _save_plot( + self, output_path, ts_values, series, xlabel, ylabel, title + ): + try: + import matplotlib + + matplotlib.use("Agg") + from matplotlib import pyplot as plt + except Exception as exc: + self._log(f"[Plotter] Skipping plot {output_path}: {exc}") + return + + try: + plt.figure(figsize=(10, 4)) + for label, values in series.items(): + plt.plot(ts_values, values, linewidth=1.0, label=label) + plt.xlabel(xlabel) + plt.ylabel(ylabel) + plt.title(title) + if len(series) > 1: + plt.legend(fontsize="small", ncol=2) + plt.tight_layout() + plt.savefig(output_path, format="png") + plt.close() + self._log(f"[Plotter] Saved plot to {output_path}") + except Exception as exc: + self._log(f"[Plotter] Failed to save plot {output_path}: {exc}") + + def _log(self, message): + if self.print: + self.print(message, log_to_logfiles_only=True) + + def _percentile(self, values, percentile): + clean = [] + for value in values: + if value is None: + continue + try: + if math.isnan(value): + continue + except TypeError: + continue + clean.append(value) + if not clean: + return float("nan") + clean.sort() + if len(clean) == 1: + return clean[0] + rank = (len(clean) - 1) * (percentile / 100.0) + lower = math.floor(rank) + upper = math.ceil(rank) + if lower == upper: + return clean[int(rank)] + lower_value = clean[lower] + upper_value = clean[upper] + return lower_value + (upper_value - lower_value) * (rank - lower) + + def _average(self, values): + clean = [] + for value in values: + if value is None: + continue + try: + if math.isnan(value): + continue + except TypeError: + continue + clean.append(value) + if not clean: + return float("nan") + return statistics.fmean(clean) + + def _format_metric(self, value): + if math.isnan(value): + return "nan" + return f"{value}" diff --git a/slips_files/common/slips_utils.py b/slips_files/common/slips_utils.py index 377f651df9..000d4bd4bc 100644 --- a/slips_files/common/slips_utils.py +++ b/slips_files/common/slips_utils.py @@ -307,6 +307,7 @@ def are_detection_modules_interested_in_this_ip(self, ip) -> bool: """ Check if any of the scan detection modules (horizontal portscan, vertical portscan, icmp scan) are interested in this ip + these modules are only interested in private or public ipv4 """ try: ip_obj = ipaddress.ip_address(ip) diff --git a/slips_files/core/aid_manager.py b/slips_files/core/aid_manager.py index 65e87d396c..5842c17d46 100644 --- a/slips_files/core/aid_manager.py +++ b/slips_files/core/aid_manager.py @@ -1,6 +1,5 @@ from multiprocessing import Process, Queue from queue import Empty -from threading import Event from slips_files.common.slips_utils import utils from slips_files.core.database.database_manager import DBManager @@ -18,12 +17,9 @@ def __init__( self, db: DBManager, _aid_queue: Queue, - stop_profiler_workers_event: Event, ): self.db = db self._aid_queue: Queue = _aid_queue - # returns true when this process should shutdown - self.stop_profiler_workers_event = stop_profiler_workers_event self._process = Process( target=self._worker_loop, @@ -35,11 +31,9 @@ def __init__( def _worker_loop(self, aid_queue, db: DBManager): """ - TRuns in its own process - - Initialize DBManager once. - - Loop forever processing tasks. + Runs in its own process """ - while not self.stop_profiler_workers_event.is_set(): + while True: try: task = aid_queue.get(timeout=1) if task == "stop": @@ -52,7 +46,7 @@ def _worker_loop(self, aid_queue, db: DBManager): # CPU-heavy hashing flow.aid = utils.get_aid(flow) - self.db.add_flow(flow, profileid, twid, label=label) + db.add_flow(flow, profileid, twid, label=label) except KeyboardInterrupt: continue except Empty: diff --git a/slips_files/core/database/database_manager.py b/slips_files/core/database/database_manager.py index 6fb1f745b6..bbf6602db3 100644 --- a/slips_files/core/database/database_manager.py +++ b/slips_files/core/database/database_manager.py @@ -1,13 +1,17 @@ # SPDX-FileCopyrightText: 2021 Sebastian Garcia # SPDX-License-Identifier: GPL-2.0-only +import csv import json import os import shutil import sqlite3 +import time from pathlib import Path from typing import ( - List, Dict, + Iterable, + List, + Optional, ) @@ -16,6 +20,7 @@ from slips_files.core.database.redis_db.database import RedisDB from slips_files.core.database.sqlite_db.database import SQLiteDB from slips_files.common.parsers.config_parser import ConfigParser +from slips_files.common.performance_paths import get_performance_csv_path from slips_files.core.structures.evidence import Evidence from slips_files.core.structures.alerts import Alert from slips_files.core.output import Output @@ -262,6 +267,9 @@ def set_local_network(self, *args, **kwargs): def get_local_network(self, *args, **kwargs): return self.rdb.get_local_network(*args, **kwargs) + def get_total_recognized_localnets(self, *args, **kwargs): + return self.rdb.get_total_recognized_localnets(*args, **kwargs) + def get_label_count(self, *args, **kwargs): return self.rdb.get_label_count(*args, **kwargs) @@ -298,6 +306,205 @@ def store_module_flows_per_second(self, *args, **kwargs): def get_module_flows_per_second(self, *args, **kwargs): return self.rdb.get_module_flows_per_second(*args, **kwargs) + def record_flow_per_minute(self, module: str, now: Optional[float] = None): + if not self.conf.generate_performance_plots(): + return + + now = time.time() if now is None else now + minute_ts = int(now // 60) * 60 + self.rdb.increment_flows_per_minute(module, minute_ts) + self.rdb.record_flows_per_minute_module(module) + if ( + not hasattr(self, "_last_flows_per_minute_bucket") + or self._last_flows_per_minute_bucket != minute_ts + ): + self._last_flows_per_minute_bucket = minute_ts + self._maybe_log_flows_per_minute(minute_ts) + + def _maybe_log_flows_per_minute(self, minute_ts: int): + if not self.conf.generate_performance_plots(): + return + + if not self.rdb.try_acquire_flows_per_minute_log_lock(): + return + + try: + last_logged = self.rdb.get_last_logged_flows_per_minute() + if last_logged is None: + # Start tracking from the minute before the first flow. + self.rdb.set_last_logged_flows_per_minute(minute_ts - 60) + return + + last_complete_minute = minute_ts - 60 + if last_complete_minute <= last_logged: + return + + modules = self.rdb.get_flows_per_minute_modules() + profiler_modules = sorted( + module + for module in modules + if self._is_profiler_module(module) + ) + for ts in range(last_logged + 60, last_complete_minute + 1, 60): + input_count = self.rdb.get_flows_per_minute("input", ts) + profiler_counts = { + module: self.rdb.get_flows_per_minute(module, ts) + for module in profiler_modules + } + self._append_flows_per_minute_row( + ts, input_count, profiler_counts + ) + self.rdb.set_last_logged_flows_per_minute(ts) + finally: + self.rdb.release_flows_per_minute_log_lock() + + def _append_flows_per_minute_row( + self, ts: int, input_count: int, profiler_counts: Dict[str, int] + ): + output_dir = self.get_output_dir() or self.output_dir + csv_path = get_performance_csv_path(output_dir, "flows_per_minute.csv") + os.makedirs(os.path.dirname(csv_path), exist_ok=True) + profiler_columns = self._get_profiler_columns(profiler_counts.keys()) + desired_header = ["ts", "input_flows_per_min"] + profiler_columns + header = self._ensure_flows_per_minute_header(csv_path, desired_header) + + with open(csv_path, "a", newline="") as handle: + writer = csv.writer(handle) + if os.path.getsize(csv_path) == 0: + writer.writerow(header) + row = self._build_flows_per_minute_row( + ts, input_count, profiler_counts, header + ) + writer.writerow(row) + + def _is_profiler_module(self, module: str) -> bool: + module_lower = module.lower() + return module_lower.startswith("profiler") + + def _get_profiler_columns(self, modules: Iterable[str]) -> List[str]: + columns = [] + for module in modules: + column = self._profiler_column_for_module(module) + if column: + columns.append(column) + return self._sort_profiler_columns(columns) + + def _profiler_column_for_module(self, module: str) -> Optional[str]: + module_lower = module.lower() + if module_lower == "profiler": + return "profiler_flows_per_min" + prefix_map = ( + "profilerworker_process_", + "profilerworker_", + "profiler_worker_", + "profiler_", + ) + for prefix in prefix_map: + if module_lower.startswith(prefix): + suffix = module_lower.split(prefix, 1)[1] + if not suffix: + return "profiler_flows_per_min" + return f"profiler_flows_per_min_worker{suffix}" + return None + + def _sort_profiler_columns(self, columns: List[str]) -> List[str]: + unique_columns = list(dict.fromkeys(columns)) + worker_prefix = "profiler_flows_per_min_worker" + + def sort_key(name: str): + if name == "profiler_flows_per_min": + return (0, -1, "") + if name.startswith(worker_prefix): + suffix = name[len(worker_prefix) :] + if suffix.isdigit(): + return (0, int(suffix), "") + return (1, 0, suffix) + return (2, 0, name) + + return sorted(unique_columns, key=sort_key) + + def _ensure_flows_per_minute_header( + self, csv_path: str, desired_header: List[str] + ) -> List[str]: + if not os.path.exists(csv_path) or os.path.getsize(csv_path) == 0: + return desired_header + + with open(csv_path, newline="") as handle: + reader = csv.reader(handle) + existing_header = next(reader, []) + + if not existing_header: + return desired_header + + if existing_header == desired_header: + return existing_header + + merged_header = self._merge_flows_per_minute_headers( + existing_header, desired_header + ) + if merged_header != existing_header: + self._rewrite_flows_per_minute_csv( + csv_path, existing_header, merged_header + ) + return merged_header + + def _merge_flows_per_minute_headers( + self, existing_header: List[str], desired_header: List[str] + ) -> List[str]: + base_columns = ["ts", "input_flows_per_min"] + profiler_columns = self._sort_profiler_columns( + [ + column + for column in existing_header + desired_header + if column.startswith("profiler_flows_per_min") + ] + ) + other_columns = [ + column + for column in existing_header + desired_header + if column not in base_columns and column not in profiler_columns + ] + other_columns = list(dict.fromkeys(other_columns)) + return base_columns + profiler_columns + other_columns + + def _rewrite_flows_per_minute_csv( + self, csv_path: str, old_header: List[str], new_header: List[str] + ): + tmp_path = f"{csv_path}.tmp" + with open(csv_path, newline="") as handle, open( + tmp_path, "w", newline="" + ) as out_handle: + reader = csv.reader(handle) + writer = csv.writer(out_handle) + next(reader, None) + writer.writerow(new_header) + for row in reader: + row_map = { + old_header[idx]: row[idx] + for idx in range(min(len(old_header), len(row))) + } + writer.writerow( + [row_map.get(column, "0") for column in new_header] + ) + os.replace(tmp_path, csv_path) + + def _build_flows_per_minute_row( + self, + ts: int, + input_count: int, + profiler_counts: Dict[str, int], + header: List[str], + ) -> List[int]: + row_map: Dict[str, int] = { + "ts": ts, + "input_flows_per_min": input_count, + } + for module, count in profiler_counts.items(): + column = self._profiler_column_for_module(module) + if column: + row_map[column] = count + return [row_map.get(column, 0) for column in header] + def get_accumulated_threat_level(self, *args, **kwargs): return self.rdb.get_accumulated_threat_level(*args, **kwargs) diff --git a/slips_files/core/database/redis_db/alert_handler.py b/slips_files/core/database/redis_db/alert_handler.py index dcd00eccb3..d399867493 100644 --- a/slips_files/core/database/redis_db/alert_handler.py +++ b/slips_files/core/database/redis_db/alert_handler.py @@ -277,20 +277,19 @@ def set_evidence(self, evidence: Evidence): evidence_exists: Optional[dict] = self.r.hget( evidence_hash, evidence.id ) + if evidence_exists: + return False + if self.is_whitelisted_evidence(evidence.id): + return False + self.r.hset(evidence_hash, evidence.id, evidence_to_send) + self.r.incr(self.constants.NUMBER_OF_EVIDENCE) # note that publishing HAS TO be done after adding the evidence # to the db # whitelisted evidence are deleted from the db, so we need to check # that we're not re-adding a deleted evidence - if (not evidence_exists) and ( - not self.is_whitelisted_evidence(evidence.id) - ): - self.r.hset(evidence_hash, evidence.id, evidence_to_send) - self.r.incr(self.constants.NUMBER_OF_EVIDENCE) - self.publish(self.channels.EVIDENCE_ADDED, evidence_to_send) - return True - - return False + self.publish(self.channels.EVIDENCE_ADDED, evidence_to_send) + return True def set_alert(self, alert: Alert): self.set_evidence_causing_alert(alert) diff --git a/slips_files/core/database/redis_db/constants.py b/slips_files/core/database/redis_db/constants.py index 2ca9cd6fd4..79af2894ef 100644 --- a/slips_files/core/database/redis_db/constants.py +++ b/slips_files/core/database/redis_db/constants.py @@ -33,7 +33,8 @@ class Constants: CACHED_ASN = "cached_asn" PIDS = "PIDs" MAC = "MAC" - MODIFIED_TIMEWINDOWS = "ModifiedTW" + MODIFIED_TIMEWINDOWS = "modified_timewindows" + TW_FLOWS_COUNTER = "timewindow_flows_counter" ACCUMULATED_THREAT_LEVELS = "accumulated_threat_levels" TRANCO_WHITELISTED_DOMAINS = "tranco_whitelisted_domains" WHITELIST = "whitelist" @@ -108,6 +109,10 @@ class Constants: P2P_PEER_INFO_HASH = "peer_info" FIDES_CACHE_KEY = "fides_cache" FIDES_CACHE_CREATED_SECONDS = "created_seconds" + FLOWS_PER_MINUTE = "flows_per_minute" + FLOWS_PER_MINUTE_MODULES = "flows_per_minute_modules" + FLOWS_PER_MINUTE_LAST_LOGGED = "flows_per_minute_last_logged" + FLOWS_PER_MINUTE_LOG_LOCK = "flows_per_minute_log_lock" class Channels: diff --git a/slips_files/core/database/redis_db/database.py b/slips_files/core/database/redis_db/database.py index f9692ea3a8..fc00011183 100644 --- a/slips_files/core/database/redis_db/database.py +++ b/slips_files/core/database/redis_db/database.py @@ -62,7 +62,6 @@ class RedisDB( # Stores instances per port instances = {} supported_channels = { - "tw_modified", "evidence_added", "new_ip", "new_flow", @@ -370,7 +369,7 @@ def _connect(port: int, db: int) -> redis.StrictRedis: # normally; if it fails, an exception will be thrown return redis.StrictRedis( - host="localhost", + host=LOCALHOST, port=port, db=db, charset="utf-8", @@ -657,6 +656,13 @@ def set_local_network(self, cidr, interface): def get_local_network(self, interface): return self.r.hget(self.constants.LOCAL_NETWORK, interface) + def get_total_recognized_localnets(self): + """ + when slips is running using 2 interfaces, Slips recognizes 2 diff + localnets, so this function is expected to return 2 + """ + return self.r.hlen(self.constants.LOCAL_NETWORK) + def get_used_port(self) -> int: return int(self.r.config_get(self.constants.REDIS_USED_PORT)["port"]) @@ -1481,6 +1487,39 @@ def store_module_flows_per_second(self, module, fps): def get_module_flows_per_second(self, module): return self.r.hget(self.constants.MODULES_FLOWS_PER_SECOND, module) + def increment_flows_per_minute(self, module: str, minute_ts: int) -> int: + key = f"{self.constants.FLOWS_PER_MINUTE}:{module}" + return self.r.hincrby(key, minute_ts, 1) + + def get_flows_per_minute(self, module: str, minute_ts: int) -> int: + key = f"{self.constants.FLOWS_PER_MINUTE}:{module}" + value = self.r.hget(key, minute_ts) + return int(value) if value else 0 + + def record_flows_per_minute_module(self, module: str): + self.r.sadd(self.constants.FLOWS_PER_MINUTE_MODULES, module) + + def get_flows_per_minute_modules(self) -> List[str]: + return list(self.r.smembers(self.constants.FLOWS_PER_MINUTE_MODULES)) + + def get_last_logged_flows_per_minute(self) -> Optional[int]: + value = self.r.get(self.constants.FLOWS_PER_MINUTE_LAST_LOGGED) + return int(value) if value is not None else None + + def set_last_logged_flows_per_minute(self, minute_ts: int): + self.r.set(self.constants.FLOWS_PER_MINUTE_LAST_LOGGED, minute_ts) + + def try_acquire_flows_per_minute_log_lock(self, ttl_seconds: int = 10): + return self.r.set( + self.constants.FLOWS_PER_MINUTE_LOG_LOCK, + "1", + nx=True, + ex=ttl_seconds, + ) + + def release_flows_per_minute_log_lock(self): + self.r.delete(self.constants.FLOWS_PER_MINUTE_LOG_LOCK) + def get_name_of_module_at(self, given_pid): """returns the name of the module that has the given pid""" for name, pid in self.get_pids().items(): diff --git a/slips_files/core/database/redis_db/profile_handler.py b/slips_files/core/database/redis_db/profile_handler.py index 8a0004fc12..e6ac375b8a 100644 --- a/slips_files/core/database/redis_db/profile_handler.py +++ b/slips_files/core/database/redis_db/profile_handler.py @@ -17,7 +17,6 @@ ) import redis import validators -from redis.client import Pipeline from slips_files.core.structures.flow_attributes import Role @@ -406,6 +405,9 @@ def add_software_to_profile(self, profileid, flow): """ Used to associate this profile with it's used software and version """ + if not flow.software: + return + sw_dict = { flow.software: { "version-major": flow.version_major, @@ -1135,7 +1137,6 @@ def check_tw_to_close(self, close_all=False): # Mark the TWs as closed so modules can work on its data pipe = self.r.pipeline() for profile_tw_to_close in profiles_tws_to_close: - pipe.zrem(self.constants.MODIFIED_TIMEWINDOWS, profile_tw_to_close) pipe = self.publish( "tw_closed", profile_tw_to_close, pipeline=pipe @@ -1157,46 +1158,35 @@ def get_current_timewindow(self) -> Optional[str]: def set_current_timewindow(self, timewindow: str) -> Optional[str]: self.r.set(self.constants.CURRENT_TIMEWINDOW, timewindow) - def mark_profile_tw_as_modified( - self, profileid, twid, timestamp, pipe: Pipeline = None - ): + def mark_profile_tw_as_modified(self, modified_tw_details: dict): """ - Mark a TW in a profile as modified - This means: - 1- To add it to the list of ModifiedTW - 2- Add the timestamp received to the time_of_last_modification - in the TW itself - - Modules wait for a TW modification to do some detections. - check the "tw_modified" channel usages to know why this func is - useful - - """ - if not timestamp: - # NEVER use time.time() as a default value for timestamp, - # using it when analyzing Pcaps/files leads to accumulation of tw - # data in RAM > redis getting OOM > slips crashing. - raise ValueError( - "timestamp is required to mark a TW as " - "modified. Received timestamp: None. This " - "leads to Slips running out of memory and crashing." - " Please make sure to provide a timestamp when " - "calling this function." - ) + PS: this function should be as optimized as possible, it's the main + source of latency and it gets called per flow + :param modified_tw_details: a dict with {profileid_tw: ts, ...} to + add to the MODIFIED_TIMEWINDOWS key. + """ + # why are we batch processing? because this function is called in + # an extremely hot path (per flow) and a zadd is O(log N) and we + # need this func to be way faster than that. + # right now, all usages of this key doesn't require it to be 100% + # real-time. so that's why we can batch update it. in the future if + # a usage requires it to be real-time, developers need to come up + # with something that wouldn't introduce latency and keep it + # real-time. - data = {f"{profileid}{self.separator}{twid}": float(timestamp)} - client = pipe if pipe else self.r - client.zadd(self.constants.MODIFIED_TIMEWINDOWS, data) - self.publish( - "tw_modified", - json.dumps( - { - "profileid": profileid, - "twid": twid, - } - ), + pipe = self.r.pipeline() + # without gt, older timestamps can overwrite newer ones + pipe.zadd( + self.constants.MODIFIED_TIMEWINDOWS, + modified_tw_details, + gt=True, ) - return pipe + pipe.zadd( + self.constants.MODIFIED_TIMEWINDOWS, + modified_tw_details, + nx=True, + ) + pipe.execute() def publish_new_letter( self, new_symbol: str, profileid: str, twid: str, tupleid: str, flow diff --git a/slips_files/core/evidence_handler.py b/slips_files/core/evidence_handler.py index ba0408c43c..44003610ab 100644 --- a/slips_files/core/evidence_handler.py +++ b/slips_files/core/evidence_handler.py @@ -20,42 +20,23 @@ # Contact: eldraco@gmail.com, sebastian.garcia@agents.fel.cvut.cz, # stratosphere@aic.fel.cvut.cz -import json -import multiprocessing import threading -from typing import ( - List, - Dict, - Optional, -) -from datetime import datetime -import sys -import os +import multiprocessing +from typing import List import time -from slips_files.common.idmefv2 import IDMEFv2 +from multiprocessing import Process from slips_files.common.style import ( green, ) from slips_files.common.parsers.config_parser import ConfigParser from slips_files.common.slips_utils import utils from slips_files.core.evidence_logger import EvidenceLogger -from slips_files.core.helpers.whitelist.whitelist import Whitelist -from slips_files.core.helpers.notify import Notify from slips_files.common.abstracts.icore import ICore -from slips_files.core.structures.evidence import ( - dict_to_evidence, - Evidence, - TimeWindow, -) -from slips_files.core.structures.alerts import ( - Alert, -) -from slips_files.core.text_formatters.evidence_formatter import ( - EvidenceFormatter, -) +from slips_files.core.evidence_handler_worker import EvidenceHandlerWorker -IS_IN_A_DOCKER_CONTAINER = os.environ.get("IS_IN_A_DOCKER_CONTAINER", False) + +DEFAULT_EVIDENCE_HANDLER_WORKERS = 3 # Evidence Process @@ -63,33 +44,18 @@ class EvidenceHandler(ICore): name = "EvidenceHandler" def init(self): - self.whitelist = Whitelist(self.logger, self.db, self.bloom_filters) - self.idmefv2 = IDMEFv2(self.logger, self.db) - self.separator = self.db.get_separator() self.read_configuration() - self.detection_threshold_in_this_width = ( - self.detection_threshold * self.width / 60 - ) # to keep track of the number of generated evidence self.db.init_evidence_number() - if self.popup_alerts: - self.notify = Notify() - if self.notify.bin_found: - # The way we send notifications differ depending - # on the user and the OS - self.notify.setup_notifications() - else: - self.popup_alerts = False - - self.is_running_non_stop = self.db.is_running_non_stop() - self.blocking_modules_supported = self.is_blocking_modules_supported() - - # this list will have our local and public ips when using -i - self.our_ips: List[str] = utils.get_own_ips(ret="List") - self.formatter = EvidenceFormatter(self.db, self.args) # thats just a tmp value, this variable will be set and used when # the module is stopping. self.last_msg_received_time = time.time() + # we don't want the workers to subscribe to channels and + # read from there, in that case all workers will process the same + # msg. instead we use a queue, so that each worker processes a + # unique msg. + self.evidence_worker_queue = multiprocessing.Queue(maxsize=30000000) + self.evidence_worker_child_processes: List[Process] = [] # A thread that handing I/O to disk (writing evidence to log files) self.logger_stop_signal = threading.Event() @@ -126,367 +92,51 @@ def read_configuration(self): 2, 0, ) - self.GID = conf.get_GID() - self.UID = conf.get_UID() - - self.popup_alerts = conf.popup_alerts() - # In docker, disable alerts no matter what slips.yaml says - if IS_IN_A_DOCKER_CONTAINER: - self.popup_alerts = False - - def handle_unable_to_log(self, failed_log, error=None): - self.print(f"Error logging evidence/alert: {error}. {failed_log}.") - - def add_alert_to_json_log_file(self, alert: Alert): - """ - Add a new alert/event line to our alerts.json file in json format. - """ - idmef_alert: dict = self.idmefv2.convert_to_idmef_alert(alert) - if not idmef_alert: - self.handle_unable_to_log(alert, "Can't convert to IDMEF alert") - return - - to_log = { - "to_log": idmef_alert, - "where": "alerts.json", - } - self.evidence_logger_q.put(to_log) - - def add_evidence_to_json_log_file( - self, - evidence, - accumulated_threat_level: float = 0, - ): - """ - Add a new evidence line to our alerts.json file in json format. - """ - idmef_evidence: dict = self.idmefv2.convert_to_idmef_event(evidence) - if not idmef_evidence: - self.handle_unable_to_log( - evidence, "Can't convert to IDMEF evidence" - ) - return - - try: - idmef_evidence.update( - { - "Note": json.dumps( - { - # this is all the uids of the flows that cause - # this evidence - "uids": evidence.uid, - "accumulated_threat_level": accumulated_threat_level, - "threat_level": str(evidence.threat_level), - "timewindow": evidence.timewindow.number, - } - ) - } - ) - - to_log = { - "to_log": idmef_evidence, - "where": "alerts.json", - } - - self.evidence_logger_q.put(to_log) - - except KeyboardInterrupt: - return True - except Exception as e: - self.handle_unable_to_log(evidence, e) - - def add_to_log_file(self, data: str): - """ - Add a new evidence line to the alerts.log and other log files if - logging is enabled. - """ - to_log = {"to_log": data, "where": "alerts.log"} - self.evidence_logger_q.put(to_log) - - def log_alert(self, alert: Alert, blocked=False): - """ - constructs the alert descript ion from the given alert and logs it - to alerts.log and alerts.json - :param blocked: bool. if the ip was blocked by the blocking module, - we should say so in alerts.log, if not, we should say that - we generated an alert - """ - now = utils.get_human_readable_datetime() - - alert_description = ( - f"{alert.last_flow_datetime}: " f"Src IP {alert.profile.ip:26}. " - ) - if blocked: - # Add to log files that this srcip is being blocked - alert_description += "Is blocked " - else: - alert_description += "Generated an alert " - - alert_description += ( - f"given enough evidence on timewindow " - f"{alert.timewindow.number}. (real time {now})" - ) - # log to alerts.log - self.add_to_log_file(alert_description) - # log to alerts.json - self.add_alert_to_json_log_file(alert) def shutdown_gracefully(self): + self.stop_evidence_workers() self.logger_stop_signal.set() try: self.logger_thread.join(timeout=5) except Exception: pass - def get_evidence_that_were_part_of_a_past_alert( - self, profileid: str, twid: str - ) -> List[str]: - """ - returns a list of evidence bool: - # given all the tw evidence, we should only - # consider evidence that makes this given - # profile malicious, aka evidence of this profile(srcip) attacking - # others. - return evidence.attacker.direction != "SRC" - - def get_evidence_for_tw( - self, profileid: str, twid: str - ) -> Optional[Dict[str, Evidence]]: - """ - filters and returns all the evidence for this profile in this TW - returns the dict with filtered evidence - """ - tw_evidence: Dict[str, dict] = self.db.get_twid_evidence( - profileid, twid - ) - if not tw_evidence: - return - - past_evidence_ids: List[str] = ( - self.get_evidence_that_were_part_of_a_past_alert(profileid, twid) - ) - - filtered_evidence = {} - - for id, evidence in tw_evidence.items(): - id: str - evidence: str - evidence: dict = json.loads(evidence) - evidence: Evidence = dict_to_evidence(evidence) - - if self.is_filtered_evidence(evidence, past_evidence_ids): - continue - - if self.db.is_whitelisted_evidence(id): - continue - - # delete not processed evidence - # sometimes the db has evidence that didn't come yet to evidence.py - # and they are alerted without checking the whitelist! - # to fix this, we keep track of processed evidence - # that came to new_evidence channel and were processed by it. - # so they are ready to be a part of an alert - profileid: str = str(evidence.profile) - if not self.db.is_evidence_processed(id, profileid, twid): - continue - - filtered_evidence[evidence.id] = evidence - - return filtered_evidence - - def is_filtered_evidence( - self, evidence: Evidence, past_evidence_ids: List[str] - ): - """ - filters the following - * evidence that were part of a past alert in this same profileid - twid (past_evidence_ids) - * evidence that weren't done by the given profileid - """ - - # delete already alerted evidence - # if there was an alert in this tw before, remove the evidence that - # were part of the past alert from the current evidence. - - # when blocking is not enabled, we can alert on a - # single profile many times - # when we get all the tw evidence from the db, we get the once we - # alerted, and the new once we need to alert - # this method removes the already alerted evidence to avoid duplicates - if evidence.id in past_evidence_ids: - return True - - if self.is_evidence_done_by_others(evidence): - return True - - return False - - def get_threat_level( - self, - evidence: Evidence, - ) -> float: - """ - return the threat level of the given evidence * confidence - """ - confidence: float = evidence.confidence - threat_level: float = evidence.threat_level.value - - # Compute the moving average of evidence - evidence_threat_level: float = threat_level * confidence - self.print( - f"\t\tWeighted Threat Level: " f"{evidence_threat_level}", 3, 0 - ) - return evidence_threat_level - - def send_to_exporting_module(self, tw_evidence: Dict[str, Evidence]): - """ - sends all given evidence to export_evidence channel - :param tw_evidence: all evidence that happened in a certain - timewindow - format is {evidence_id (str) : Evidence obj} - """ - for evidence in tw_evidence.values(): - evidence: Evidence - evidence_dict: dict = utils.to_dict(evidence) - self.print( - f"[EvidenceHandler] Exporting evidence {evidence_dict.get('id')} " - f"type={evidence_dict.get('evidence_type')} via export_evidence.", - 2, - 0, - ) - self.db.publish("export_evidence", json.dumps(evidence_dict)) - - def publish_single_evidence(self, evidence: Evidence): - evidence_dict: dict = utils.to_dict(evidence) - self.print( - f"[EvidenceHandler] Export streaming {evidence_dict.get('id')} " - f"type={evidence_dict.get('evidence_type')} via export_evidence.", - 2, - 0, - ) - self.db.publish("export_evidence", json.dumps(evidence_dict)) - - def is_blocking_modules_supported(self) -> bool: - """ - returns true if slips is running in an interface or growing - zeek dir with -p - or if slips is using custom flows (meaning slips is reading the - flows by a custom module not by input.py). - """ - custom_flows = "-im" in sys.argv or "--input-module" in sys.argv - blocking_module_enabled = "-p" in sys.argv - return ( - self.is_running_non_stop or custom_flows - ) and blocking_module_enabled - - def handle_new_alert( - self, - alert: Alert, - evidence_causing_the_alert, - ): - """ - saves alert details in the db and informs exporting modules about it - - if a profile already generated an alert in this tw, we send a - blocking request (to extend its blocking period), and log the alert - in the db only, without printing it to cli. - :param evidence_causing_the_alert: Dict[str, Evidence] - """ - self.db.set_alert(alert, evidence_causing_the_alert) - is_blocked: bool = self.decide_blocking( - alert.profile.ip, alert.timewindow - ) - # like in the firewall - profile_already_blocked: bool = self.db.is_blocked_profile_and_tw( - str(alert.profile), str(alert.timewindow) - ) - if profile_already_blocked: - # that's it, dont keep logging new alerts if 1 alerts is logged - # in this tw. - return - - self.send_to_exporting_module(evidence_causing_the_alert) - alert_to_print: str = self.formatter.format_evidence_for_printing( - alert, evidence_causing_the_alert - ) - - self.print(f"{alert_to_print}", 1, 0) - - if self.popup_alerts: - self.show_popup(alert) - - if is_blocked: - self.db.mark_profile_and_timewindow_as_blocked( - str(alert.profile), str(alert.timewindow) - ) - - self.log_alert(alert, blocked=is_blocked) - - def decide_blocking( - self, - ip_to_block: str, - timewindow: TimeWindow, - ) -> bool: - """ - Decide whether to block or not and send to the blocking module - returns True if the given IP was blocked by Slips blocking module - """ - # send ip to the blocking module - if not self.blocking_modules_supported: - return False - # now since this source ip(profileid) caused an alert, - # it means it caused so many evidence(attacked others a lot) - # that we decided to alert and block it - - # First, Make sure we don't block our own IP - if ip_to_block in self.our_ips: - return False - - # TODO: edit the options here. by default it'll block - # all traffic to or from this ip - # PS: if by default we don't block everything from/to this ip anymore, - # remember to update the CYST module - blocking_data = { - "ip": ip_to_block, - "block": True, - "tw": timewindow.number, - # in which localnet is this IP? to which interface does it belong? - "interface": utils.get_interface_of_ip( - ip_to_block, self.db, self.args - ), - } - blocking_data = json.dumps(blocking_data) - self.db.publish("new_blocking", blocking_data) - return True - - def update_accumulated_threat_level(self, evidence: Evidence) -> float: - """ - update the accumulated threat level of the profileid and twid of - the given evidence and return the updated value - """ - evidence_threat_level: float = self.get_threat_level(evidence) - return self.db.update_accumulated_threat_level( - str(evidence.profile), - str(evidence.timewindow), - evidence_threat_level, + used_queues = [ + self.evidence_worker_queue, + self.evidence_logger_q, + ] + + for q in used_queues: + q.cancel_join_thread() + q.close() + + def stop_evidence_workers(self): + for _ in self.evidence_worker_child_processes: + self.evidence_worker_queue.put("stop") + + for process in self.evidence_worker_child_processes: + try: + process.join() + except (OSError, ChildProcessError): + pass + + def start_evidence_worker(self, worker_id: int = None): + worker_name = f"EvidenceHandlerWorker_Process_{worker_id}" + worker = EvidenceHandlerWorker( + logger=self.logger, + output_dir=self.output_dir, + redis_port=self.redis_port, + termination_event=self.termination_event, + conf=self.conf, + ppid=self.ppid, + slips_args=self.args, + bloom_filters_manager=self.bloom_filters, + name=worker_name, + evidence_queue=self.evidence_worker_queue, + evidence_logger_q=self.evidence_logger_q, ) - - def show_popup(self, alert: Alert): - alert_description: str = self.formatter.get_printable_alert(alert) - self.notify.show_popup(alert_description) + worker.start() + self.evidence_worker_child_processes.append(worker) def should_stop(self) -> bool: """ @@ -512,161 +162,23 @@ def should_stop(self) -> bool: def pre_main(self): self.print(f"Using threshold: {green(self.detection_threshold)}") + for worker_id in range(DEFAULT_EVIDENCE_HANDLER_WORKERS): + self.start_evidence_worker(worker_id) def main(self): while not self.should_stop(): if msg := self.get_msg("evidence_added"): - msg["data"]: str - evidence: dict = json.loads(msg["data"]) - try: - evidence: Evidence = dict_to_evidence(evidence) - except Exception as e: - self.print( - f"Problem converting {evidence} to dict: " f"{e}", 0, 1 - ) - continue - profileid: str = str(evidence.profile) - twid: str = str(evidence.timewindow) - timestamp: str = evidence.timestamp - - # the database naturally has evidence before they reach - # this module. and sometime when this module queries - # evidence for a specific timewindow, the db returns all - # evidence including the ones the werent processed here yet. - # this marking of ev. as processed is to avoid that. - # so that get_evidence_for_tw() call below won't return - # unprocessed evidence. - self.db.mark_evidence_as_processed( - evidence.id, profileid, twid - ) - - if self.whitelist.is_whitelisted_evidence(evidence): - self.db.cache_whitelisted_evidence_id(evidence.id) - # Modules add evidence to the db before - # reaching this point, now remove evidence from db so - # it could be completely ignored - self.db.delete_evidence(profileid, twid, evidence.id) - self.print( - f"{self.whitelist.get_bloom_filters_stats()}", 2, 0 - ) - continue - - # convert time to local timezone - if self.is_running_non_stop: - timestamp: datetime = utils.convert_to_local_timezone( - timestamp - ) - flow_datetime = utils.convert_ts_format(timestamp, "iso") - - evidence: Evidence = ( - self.formatter.add_threat_level_to_evidence_description( - evidence - ) + self.evidence_worker_queue.put( + { + "channel": "evidence_added", + "message": msg, + } ) - evidence_to_log: str = self.formatter.get_evidence_to_log( - evidence, - flow_datetime, - ) - # Add the evidence to alerts.log - self.add_to_log_file(evidence_to_log) - - past_evidence_ids: List[str] = ( - self.get_evidence_that_were_part_of_a_past_alert( - profileid, twid - ) - ) - # filtered evidence dont add to the acc threat level - if not self.is_filtered_evidence(evidence, past_evidence_ids): - accumulated_threat_level: float = ( - self.update_accumulated_threat_level(evidence) - ) - else: - accumulated_threat_level: float = ( - self.db.get_accumulated_threat_level(profileid, twid) - ) - - # add to alerts.json - self.add_evidence_to_json_log_file( - evidence, - accumulated_threat_level, - ) - - # stream every evidence toward exporting modules immediately - self.publish_single_evidence(evidence) - - evidence_dict: dict = utils.to_dict(evidence) - self.db.publish("report_to_peers", json.dumps(evidence_dict)) - - # This is the part to detect if the accumulated - # evidence was enough for generating a detection - # The detection should be done in attacks per minute. - # The parameter in the configuration - # is attacks per minute - # So find out how many attacks corresponds - # to the width we are using - if ( - accumulated_threat_level - >= self.detection_threshold_in_this_width - ): - tw_evidence: Dict[str, Evidence] - tw_evidence = self.get_evidence_for_tw(profileid, twid) - if tw_evidence: - tw_start, tw_end = self.db.get_tw_limits( - profileid, twid - ) - evidence.timewindow.start_time = tw_start - evidence.timewindow.end_time = tw_end - - alert: Alert = Alert( - profile=evidence.profile, - timewindow=evidence.timewindow, - last_evidence=evidence, - accumulated_threat_level=accumulated_threat_level, - correl_id=list(tw_evidence.keys()), - ) - self.handle_new_alert(alert, tw_evidence) - if msg := self.get_msg("new_blame"): - data = msg["data"] - try: - data = json.loads(data) - except json.decoder.JSONDecodeError: - self.print( - "Error in the report received from p2ptrust module" - ) - return - # The available values for the following variables are - # defined in go_director - - # available key types: "ip" - # key_type = data['key_type'] - - # if the key type is ip, the ip is validated - key = data["key"] - - # available evaluation types: 'score_confidence' - # evaluation_type = data['evaluation_type'] - - # this is the score_confidence received from the peer - evaluation = data["evaluation"] - # {"key_type": "ip", "key": "1.2.3.40", - # "evaluation_type": "score_confidence", - # "evaluation": { "score": 0.9, "confidence": 0.6 }} - ip_info = {"p2p4slips": evaluation} - ip_info["p2p4slips"].update({"ts": time.time()}) - self.db.store_blame_report(key, evaluation) - - blocking_data = { - "ip": key, - "block": True, - "to": True, - "from": True, - # in which localnet is this IP? - # to which interface does it belong? - "interface": utils.get_interface_of_ip( - key, self.db, self.args - ), - } - blocking_data = json.dumps(blocking_data) - self.db.publish("new_blocking", blocking_data) + self.evidence_worker_queue.put( + { + "channel": "new_blame", + "message": msg, + } + ) diff --git a/slips_files/core/evidence_handler_worker.py b/slips_files/core/evidence_handler_worker.py new file mode 100644 index 0000000000..5ffa395b40 --- /dev/null +++ b/slips_files/core/evidence_handler_worker.py @@ -0,0 +1,512 @@ +# SPDX-FileCopyrightText: 2021 Sebastian Garcia +# SPDX-License-Identifier: GPL-2.0-only +# Stratosphere Linux IPS. A machine-learning Intrusion Detection System +# Copyright (C) 2021 Sebastian Garcia + +import json +import os +import queue +import sys +from multiprocessing import Queue +from typing import Dict, List, Optional + +from slips_files.common.abstracts.imodule import IModule +from slips_files.common.idmefv2 import IDMEFv2 +from slips_files.common.parsers.config_parser import ConfigParser +from slips_files.common.slips_utils import utils +from slips_files.common.style import green +from slips_files.core.helpers.notify import Notify +from slips_files.core.helpers.whitelist.whitelist import Whitelist +from slips_files.core.structures.alerts import Alert +from slips_files.core.structures.evidence import ( + Evidence, + ThreatLevel, + TimeWindow, + dict_to_evidence, +) +from slips_files.core.text_formatters.evidence_formatter import ( + EvidenceFormatter, +) + +IS_IN_A_DOCKER_CONTAINER = os.environ.get("IS_IN_A_DOCKER_CONTAINER", False) + + +class EvidenceHandlerWorker(IModule): + name = "EvidenceHandlerWorker" + + def init( + self, + name: str, + evidence_queue: Queue, + evidence_logger_q: Queue, + ): + self.name = name + self.evidence_queue = evidence_queue + self.evidence_logger_q = evidence_logger_q + self.whitelist = Whitelist(self.logger, self.db, self.bloom_filters) + self.idmefv2 = IDMEFv2(self.logger, self.db) + self.read_configuration() + self.detection_threshold_in_this_width = ( + self.detection_threshold * self.width / 60 + ) + if self.popup_alerts: + self.notify = Notify() + if self.notify.bin_found: + self.notify.setup_notifications() + else: + self.popup_alerts = False + + self.is_running_non_stop = self.db.is_running_non_stop() + self.blocking_modules_supported = self.is_blocking_modules_supported() + self.our_ips: List[str] = utils.get_own_ips(ret="List") + self.formatter = EvidenceFormatter(self.db, self.args) + self.slips_start_time: str = self.db.get_slips_start_time() + self.first_flow_pcap_time = None + + def subscribe_to_channels(self): + self.channels = {} + + def read_configuration(self): + conf = ConfigParser() + self.width: float = conf.get_tw_width_in_seconds() + self.detection_threshold = conf.evidence_detection_threshold() + self.print( + f"Detection Threshold: {self.detection_threshold} " + f"attacks per minute " + f"({self.detection_threshold * int(self.width) / 60} " + f"in the current time window width)", + 2, + 0, + ) + self.popup_alerts = conf.popup_alerts() + self.use_p2p: bool = conf.use_local_p2p() or conf.use_global_p2p() + self.exporting_modules_enabled: bool = ( + conf.export_to() or conf.send_to_warden() + ) + self.generate_performance_plots = ( + conf.generate_performance_plots() is True + ) + if IS_IN_A_DOCKER_CONTAINER: + self.popup_alerts = False + + def handle_unable_to_log(self, failed_log, error=None): + self.print(f"Error logging evidence/alert: {error}. {failed_log}.") + + def add_alert_to_json_log_file(self, alert: Alert): + idmef_alert: dict = self.idmefv2.convert_to_idmef_alert(alert) + if not idmef_alert: + self.handle_unable_to_log(alert, "Can't convert to IDMEF alert") + return + + self.evidence_logger_q.put( + { + "to_log": idmef_alert, + "where": "alerts.json", + } + ) + + def add_evidence_to_json_log_file( + self, + evidence: Evidence, + accumulated_threat_level: float = 0, + ): + idmef_evidence: dict = self.idmefv2.convert_to_idmef_event(evidence) + if not idmef_evidence: + self.handle_unable_to_log( + evidence, "Can't convert to IDMEF evidence" + ) + return + + try: + idmef_evidence.update( + { + "Note": json.dumps( + { + "uids": evidence.uid, + "accumulated_threat_level": accumulated_threat_level, + "threat_level": str(evidence.threat_level), + "timewindow": evidence.timewindow.number, + } + ) + } + ) + self.add_latency_to_csv(idmef_evidence) + self.evidence_logger_q.put( + { + "to_log": idmef_evidence, + "where": "alerts.json", + } + ) + except KeyboardInterrupt: + return True + except Exception as error: + self.handle_unable_to_log(evidence, error) + + def add_latency_to_csv(self, idmef_evidence: dict): + if not self.generate_performance_plots: + return + + start_time = idmef_evidence.get("StartTime") + create_time = idmef_evidence.get("CreateTime") + evidence_id = idmef_evidence.get("ID") + if not (start_time and create_time and evidence_id): + return + + if self.first_flow_pcap_time is None: + self.first_flow_pcap_time = float(self.db.get_first_flow_time()) + + try: + start_unix = utils.convert_ts_format(start_time, "unixtimestamp") + create_unix = utils.convert_ts_format(create_time, "unixtimestamp") + + if self.is_running_non_stop: + latency = float(create_unix) - float(start_unix) + else: + wall_elapsed = float(create_unix) - float( + self.slips_start_time + ) + pcap_elapsed = float(start_unix) - float( + self.first_flow_pcap_time + ) + latency = wall_elapsed - pcap_elapsed + if latency < 0: + latency = 0 + + latency = round(latency) + except Exception: + return + + self.evidence_logger_q.put( + { + "to_log": { + "ts": create_unix, + "evidence_id": evidence_id, + "latency": latency, + }, + "where": "latency.csv", + } + ) + + def add_to_log_file(self, data: str): + self.evidence_logger_q.put({"to_log": data, "where": "alerts.log"}) + + def log_alert(self, alert: Alert, blocked=False): + now = utils.get_human_readable_datetime() + + alert_description = ( + f"{alert.last_flow_datetime}: " f"Src IP {alert.profile.ip:26}. " + ) + if blocked: + alert_description += "Is blocked " + else: + alert_description += "Generated an alert " + + alert_description += ( + f"given enough evidence on timewindow " + f"{alert.timewindow.number}. (real time {now})" + ) + self.add_to_log_file(alert_description) + self.add_alert_to_json_log_file(alert) + + def get_evidence_that_were_part_of_a_past_alert( + self, profileid: str, twid: str + ) -> List[str]: + past_alerts: dict = self.db.get_profileid_twid_alerts(profileid, twid) + + past_evidence_ids = [] + if past_alerts: + for evidence_id_list in list(past_alerts.values()): + evidence_id_list: List[str] = json.loads(evidence_id_list) + past_evidence_ids += evidence_id_list + + return past_evidence_ids + + def is_evidence_done_by_others(self, evidence: Evidence) -> bool: + return evidence.attacker.direction != "SRC" + + def get_evidence_for_tw( + self, profileid: str, twid: str + ) -> Optional[Dict[str, Evidence]]: + tw_evidence: Dict[str, dict] = self.db.get_twid_evidence( + profileid, twid + ) + if not tw_evidence: + return None + + past_evidence_ids = self.get_evidence_that_were_part_of_a_past_alert( + profileid, twid + ) + filtered_evidence = {} + + for evidence_id, raw_evidence in tw_evidence.items(): + evidence = dict_to_evidence(json.loads(raw_evidence)) + + if self.is_filtered_evidence(evidence, past_evidence_ids): + continue + + if self.db.is_whitelisted_evidence(evidence_id): + continue + + profileid = str(evidence.profile) + if not self.db.is_evidence_processed(evidence_id, profileid, twid): + continue + + filtered_evidence[evidence.id] = evidence + + return filtered_evidence + + def is_filtered_evidence( + self, evidence: Evidence, past_evidence_ids: List[str] + ): + if evidence.id in past_evidence_ids: + return True + + if self.is_evidence_done_by_others(evidence): + return True + + return False + + def get_threat_level(self, evidence: Evidence) -> float: + evidence_threat_level = ( + evidence.threat_level.value * evidence.confidence + ) + self.print(f"\t\tWeighted Threat Level: {evidence_threat_level}", 3, 0) + return evidence_threat_level + + def send_to_exporting_module(self, tw_evidence: Dict[str, Evidence]): + if not self.exporting_modules_enabled: + return + + for evidence in tw_evidence.values(): + evidence_dict: dict = utils.to_dict(evidence) + self.print( + f"[EvidenceHandler] Exporting evidence {evidence_dict.get('id')} " + f"type={evidence_dict.get('evidence_type')} via export_evidence.", + 2, + 0, + ) + self.db.publish("export_evidence", json.dumps(evidence_dict)) + + def give_evidence_to_exporting_modules(self, evidence: Evidence): + if not self.exporting_modules_enabled: + return + + evidence_dict: dict = utils.to_dict(evidence) + self.print( + f"[EvidenceHandler] Export streaming {evidence_dict.get('id')} " + f"type={evidence_dict.get('evidence_type')} via export_evidence.", + 2, + 0, + ) + self.db.publish("export_evidence", json.dumps(evidence_dict)) + + def is_blocking_modules_supported(self) -> bool: + custom_flows = "-im" in sys.argv or "--input-module" in sys.argv + blocking_module_enabled = "-p" in sys.argv + return ( + self.is_running_non_stop or custom_flows + ) and blocking_module_enabled + + def handle_new_alert( + self, + alert: Alert, + evidence_causing_the_alert, + ): + self.db.set_alert(alert, evidence_causing_the_alert) + is_blocked: bool = self.decide_blocking( + alert.profile.ip, alert.timewindow + ) + profile_already_blocked: bool = self.db.is_blocked_profile_and_tw( + str(alert.profile), str(alert.timewindow) + ) + if profile_already_blocked: + return + + self.send_to_exporting_module(evidence_causing_the_alert) + alert_to_print: str = self.formatter.format_evidence_for_printing( + alert, evidence_causing_the_alert + ) + self.print(f"{alert_to_print}", 1, 0) + + if self.popup_alerts: + self.show_popup(alert) + + if is_blocked: + self.db.mark_profile_and_timewindow_as_blocked( + str(alert.profile), str(alert.timewindow) + ) + + self.log_alert(alert, blocked=is_blocked) + + def decide_blocking( + self, + ip_to_block: str, + timewindow: TimeWindow, + ) -> bool: + if not self.blocking_modules_supported: + return False + + if ip_to_block in self.our_ips: + return False + + blocking_data = { + "ip": ip_to_block, + "block": True, + "tw": timewindow.number, + "interface": utils.get_interface_of_ip( + ip_to_block, self.db, self.args + ), + } + self.db.publish("new_blocking", json.dumps(blocking_data)) + return True + + def update_accumulated_threat_level(self, evidence: Evidence) -> float: + evidence_threat_level = self.get_threat_level(evidence) + return self.db.update_accumulated_threat_level( + str(evidence.profile), + str(evidence.timewindow), + evidence_threat_level, + ) + + def show_popup(self, alert: Alert): + alert_description = self.formatter.get_printable_alert(alert) + self.notify.show_popup(alert_description) + + def get_accumulated_threat_level( + self, profileid, twid, evidence: Evidence + ) -> float: + if evidence.threat_level == ThreatLevel.INFO: + return self.db.get_accumulated_threat_level(profileid, twid) + + past_evidence_ids = self.get_evidence_that_were_part_of_a_past_alert( + profileid, twid + ) + if not self.is_filtered_evidence(evidence, past_evidence_ids): + return self.update_accumulated_threat_level(evidence) + + return self.db.get_accumulated_threat_level(profileid, twid) + + def get_msg_from_queue(self, q: Queue): + try: + return q.get(timeout=1) + except queue.Empty: + return None + except Exception: + return None + + def is_stop_msg(self, msg) -> bool: + return msg == "stop" + + def pre_main(self): + worker_number = self.name.split("_")[-1] + worker_name = f"Evidence Handler Worker {worker_number}" + self.print(f"Started {green(worker_name)} [PID {green(os.getpid())}]") + + def should_stop(self) -> bool: + return False + + def handle_evidence_added_message(self, msg: dict): + evidence = json.loads(msg["data"]) + try: + evidence = dict_to_evidence(evidence) + except Exception as error: + self.print(f"Problem converting {evidence} to dict: {error}", 0, 1) + return + + profileid = str(evidence.profile) + twid = str(evidence.timewindow) + timestamp = evidence.timestamp + + self.db.mark_evidence_as_processed(evidence.id, profileid, twid) + + if self.whitelist.is_whitelisted_evidence(evidence): + self.db.cache_whitelisted_evidence_id(evidence.id) + self.db.delete_evidence(profileid, twid, evidence.id) + self.print(f"{self.whitelist.get_bloom_filters_stats()}", 2, 0) + return + + if self.is_running_non_stop: + timestamp = utils.convert_to_local_timezone(timestamp) + flow_datetime = utils.convert_ts_format(timestamp, "iso") + + evidence = self.formatter.add_threat_level_to_evidence_description( + evidence + ) + evidence_to_log = self.formatter.get_evidence_to_log( + evidence, + flow_datetime, + ) + self.add_to_log_file(evidence_to_log) + + accumulated_threat_level = self.get_accumulated_threat_level( + profileid, twid, evidence + ) + self.add_evidence_to_json_log_file( + evidence, + accumulated_threat_level, + ) + self.give_evidence_to_exporting_modules(evidence) + + if self.use_p2p: + self.db.publish( + "report_to_peers", json.dumps(utils.to_dict(evidence)) + ) + + if accumulated_threat_level < self.detection_threshold_in_this_width: + return + + tw_evidence = self.get_evidence_for_tw(profileid, twid) + if not tw_evidence: + return + + tw_start, tw_end = self.db.get_tw_limits(profileid, twid) + evidence.timewindow.start_time = tw_start + evidence.timewindow.end_time = tw_end + + alert = Alert( + profile=evidence.profile, + timewindow=evidence.timewindow, + last_evidence=evidence, + accumulated_threat_level=accumulated_threat_level, + correl_id=list(tw_evidence.keys()), + ) + self.handle_new_alert(alert, tw_evidence) + + def handle_new_blame_message(self, msg: dict): + data = msg["data"] + try: + data = json.loads(data) + except json.decoder.JSONDecodeError: + self.print("Error in the report received from p2ptrust module") + return + + key = data["key"] + evaluation = data["evaluation"] + self.db.store_blame_report(key, evaluation) + + blocking_data = { + "ip": key, + "block": True, + "to": True, + "from": True, + "interface": utils.get_interface_of_ip(key, self.db, self.args), + } + self.db.publish("new_blocking", json.dumps(blocking_data)) + + def main(self): + """runs in a loop defined in IModule""" + task = self.get_msg_from_queue(self.evidence_queue) + if not task: + return + + if self.is_stop_msg(task): + self.print("Received stop signal. Stopping.") + return 1 + + channel = task["channel"] + msg = task["message"] + + if channel == "evidence_added": + self.handle_evidence_added_message(msg) + elif channel == "new_blame": + self.handle_new_blame_message(msg) diff --git a/slips_files/core/evidence_logger.py b/slips_files/core/evidence_logger.py index 7b548f7348..e1308aa781 100644 --- a/slips_files/core/evidence_logger.py +++ b/slips_files/core/evidence_logger.py @@ -1,10 +1,13 @@ +import csv import json import os import queue import threading import traceback +import multiprocessing from slips_files.common.parsers.config_parser import ConfigParser +from slips_files.common.performance_paths import get_performance_csv_path from slips_files.common.slips_utils import utils @@ -12,7 +15,7 @@ class EvidenceLogger: def __init__( self, logger_stop_signal: threading.Event, - evidence_logger_q: queue.Queue, + evidence_logger_q: multiprocessing.Queue, output_dir: str, ): self.logger_stop_signal = logger_stop_signal @@ -26,17 +29,43 @@ def __init__( # clear output/alerts.json self.jsonfile = self.clean_file(self.output_dir, "alerts.json") utils.change_logfiles_ownership(self.jsonfile.name, self.UID, self.GID) + self.latency_file = None + self.latency_writer = None + if self.generate_performance_plots: + self._init_latency_file() def read_configuration(self): conf = ConfigParser() self.GID = conf.get_GID() self.UID = conf.get_UID() + self.generate_performance_plots = ( + conf.generate_performance_plots() is True + ) + + def _init_latency_file(self): + self.latency_file = self.clean_file( + self.output_dir, + get_performance_csv_path(self.output_dir, "latency.csv"), + ) + utils.change_logfiles_ownership( + self.latency_file.name, self.UID, self.GID + ) + self.latency_writer = csv.writer(self.latency_file) + self.latency_writer.writerow(["ts", "evidence_id", "latency"]) + self.latency_file.flush() def clean_file(self, output_dir, file_to_clean): """ Clear the file if exists and return an open handle to it """ - logfile_path = os.path.join(output_dir, file_to_clean) + if os.path.isabs(file_to_clean): + logfile_path = file_to_clean + else: + logfile_path = os.path.join(output_dir, file_to_clean) + + logfile_dir = os.path.dirname(logfile_path) + if logfile_dir: + os.makedirs(logfile_dir, exist_ok=True) if os.path.exists(logfile_path): open(logfile_path, "w").close() return open(logfile_path, "a") @@ -68,6 +97,21 @@ def print_to_alerts_json(self, idmef_evidence: dict): except Exception: return + def print_to_latency_csv(self, row: dict): + if self.latency_writer is None or self.latency_file is None: + return + + try: + self.latency_writer.writerow( + [row["ts"], row["evidence_id"], row["latency"]] + ) + self.latency_file.flush() # flush Python buffer + os.fsync(self.latency_file.fileno()) # flush OS buffer + except KeyboardInterrupt: + return True + except Exception: + return + def run_logger_thread(self): """ runs forever in a loop reveiving msgs from evidence_handler and @@ -76,12 +120,16 @@ def run_logger_thread(self): happening, so slips can process evidence faster there while we log as fast as possible here """ - while not self.logger_stop_signal.is_set(): + while True: try: msg = self.evidence_logger_q.get(timeout=1) except queue.Empty: + if self.logger_stop_signal.is_set(): + break continue except Exception: + if self.logger_stop_signal.is_set(): + break continue destination = msg["where"] @@ -91,9 +139,13 @@ def run_logger_thread(self): elif destination == "alerts.json": self.print_to_alerts_json(msg["to_log"]) + elif destination == "latency.csv": + self.print_to_latency_csv(msg["to_log"]) self.shutdown_gracefully() def shutdown_gracefully(self): self.logfile.close() self.jsonfile.close() + if self.latency_file is not None: + self.latency_file.close() diff --git a/slips_files/core/flows/zeek.py b/slips_files/core/flows/zeek.py index 185ee7657e..b6102967e2 100644 --- a/slips_files/core/flows/zeek.py +++ b/slips_files/core/flows/zeek.py @@ -201,6 +201,8 @@ class SSH(BaseFlow): host_key_alg: str host_key: str + sport: str = "" + dport: str = "" ground_truth_label: str = "" detailed_ground_truth_label: str = "" @@ -419,6 +421,7 @@ class Software(BaseFlow): unparsed_version: str version_major: str version_minor: str + software_name: str = "" # software log lines dont have daddr daddr: str = "" ground_truth_label: str = "" @@ -428,6 +431,8 @@ class Software(BaseFlow): type_: str = field(default="software") def __post_init__(self) -> None: + if not self.software and self.software_name: + self.software = self.software_name # store info about everything except http:broswer # we're already reading browser UA from http.log self.http_browser = self.software == "HTTP::BROWSER" diff --git a/slips_files/core/helpers/localnet_cache.py b/slips_files/core/helpers/localnet_cache.py deleted file mode 100644 index a51819e505..0000000000 --- a/slips_files/core/helpers/localnet_cache.py +++ /dev/null @@ -1,48 +0,0 @@ -import json -import multiprocessing -from typing import Dict, List, Tuple - - -class LocalnetCacheShared: - """Small shared dict cache stored as JSON in shared memory.""" - - def __init__(self, size: int = 8192) -> None: - self.size = size - self.buffer = multiprocessing.Array("c", size, lock=False) - self.lock = multiprocessing.Lock() - # ensure buffer is nul-terminated - self.buffer[:] = b"\x00" * size - - def _read_bytes(self) -> bytes: - raw = bytes(self.buffer[:]) - try: - end = raw.index(0) - except ValueError: - end = len(raw) - return raw[:end] - - def get(self) -> Dict[str, str]: - with self.lock: - raw = self._read_bytes() - if not raw: - return {} - try: - return json.loads(raw.decode("utf-8")) - except json.JSONDecodeError: - return {} - - def contains(self, key: str) -> bool: - return key in self.get() - - def items(self) -> List[Tuple[str, str]]: - return list(self.get().items()) - - def set(self, new_cache: Dict[str, str]) -> bool: - payload = json.dumps(new_cache, separators=(",", ":")).encode("utf-8") - if len(payload) >= self.size: - # refuse to write partial data - return False - with self.lock: - self.buffer[: len(payload)] = payload - self.buffer[len(payload) :] = b"\x00" * (self.size - len(payload)) - return True diff --git a/slips_files/core/helpers/localnet_handler.py b/slips_files/core/helpers/localnet_handler.py new file mode 100644 index 0000000000..fd0a654c07 --- /dev/null +++ b/slips_files/core/helpers/localnet_handler.py @@ -0,0 +1,166 @@ +import ipaddress +from ipaddress import IPv4Address, IPv4Network, IPv6Address, IPv6Network +from typing import Dict, List, Union +import validators + +import netifaces + +from slips_files.common.slips_utils import utils + + +class LocalnetHandler: + def __init__(self, profiler) -> None: + self.profiler = profiler + self._private_client_ips = self.get_private_client_ips( + self.profiler.client_ips + ) + self._configured_default_localnet = ( + self._get_configured_default_localnet() + ) + self.is_running_non_stop = self.profiler.db.is_running_non_stop() + self.done_recognizing_all_localnets = False + self.localnet_cache = {} + self.number_of_expected_localnets: int = ( + self._get_expected_localnets_number() + ) + + def get_private_client_ips( + self, client_ips=None + ) -> List[Union[IPv4Network, IPv6Network, IPv4Address, IPv6Address]]: + """ + returns the private ips found in the client_ips param + in the config file + """ + if client_ips is None: + client_ips = self.profiler.client_ips + + try: + ips = list(client_ips) + except TypeError: + return [] + + private_clients = [] + for ip in ips: + if utils.is_private_ip(ip): + private_clients.append(ip) + return private_clients + + def _get_configured_default_localnet(self) -> Dict[str, str]: + """if private client_ips are set in the config, derive the used + local net from it""" + for range_ in self._private_client_ips: + if isinstance(range_, (IPv4Network, IPv6Network)): + return {"default": str(range_)} + return {} + + def _get_localnet_of_given_interfaces_using_netifaces( + self, + ) -> Dict[str, str]: + """ + returns the local network of the given interface/s (-i or -ap) + """ + local_nets = {} + for interface in utils.get_all_interfaces(self.profiler.args): + addrs = netifaces.ifaddresses(interface).get(netifaces.AF_INET) + if not addrs: + return local_nets + + for addr in addrs: + ip = addr.get("addr") + netmask = addr.get("netmask") + if ip and netmask: + network = ipaddress.IPv4Network( + f"{ip}/{netmask}", strict=False + ) + local_nets[interface] = str(network) + return local_nets + + def _get_local_net_of_flow(self, flow) -> Dict[str, str]: + """ + gets the local network from client_ip + param in the config file, + or by using the localnetwork of the first private + srcip seen in the traffic + """ + if self._configured_default_localnet: + return self._configured_default_localnet.copy() + + ip: str = flow.saddr + if cidr := utils.get_cidr_of_private_ip(ip): + return {"default": cidr} + + return {} + + def _get_expected_localnets_number(self): + """ + if using -ap, we expect 2localnets,one for eeach interface, + if using -i, we expect 1 + """ + return 2 if self.profiler.args.access_point else 1 + + def handle_setting_local_net(self, flow): + """ + stores the local network if possible + sets the self.localnet_cache dict + """ + if not self._should_set_localnet(flow): + return + + if self.is_running_non_stop: + local_nets: Dict[str, str] = ( + self._get_localnet_of_given_interfaces_using_netifaces() + ) + else: + # slips is analyzing a file + local_nets: Dict[str, str] = self._get_local_net_of_flow(flow) + + self.localnet_cache = local_nets + + for interface, local_net in self.localnet_cache.items(): + self.profiler.db.set_local_network(local_net, interface) + + def _should_set_localnet(self, flow) -> bool: + """ + returns true only if the saddr of the current flow is ipv4, private + and we don't have the local_net set already + """ + if self.done_recognizing_all_localnets: + return False + + if ( + self.profiler.db.get_total_recognized_localnets() + == self.number_of_expected_localnets + ): + self.done_recognizing_all_localnets = True + return False + + if self.is_running_non_stop: + if flow.interface in self.localnet_cache: + # localnet of this interface is already recognized + return False + + elif "default" in self.localnet_cache: + # slips is analyzing a pcap/zeek dir, and we already guessed the + # localnet of it + return False + + if flow.saddr == "0.0.0.0": + return False + + if self._private_client_ips: + return True + + if not validators.ipv4(flow.saddr): + return False + + saddr_obj = ipaddress.ip_address(flow.saddr) + + if ( + saddr_obj.is_multicast + or saddr_obj.is_link_local + or saddr_obj.is_loopback + or saddr_obj.is_reserved + or not saddr_obj.is_private + ): + return False + return True diff --git a/slips_files/core/input/input.py b/slips_files/core/input/input.py index d0a93925b4..7d2589326e 100644 --- a/slips_files/core/input/input.py +++ b/slips_files/core/input/input.py @@ -2,6 +2,7 @@ # SPDX-License-Identifier: GPL-2.0-only # Stratosphere Linux IPS. A machine-learning Intrusion Detection System # Copyright (C) 2021 Sebastian Garcia +import time # This program is free software; you can redistribute it and/or # modify it under the terms of the GNU General Public License @@ -126,12 +127,38 @@ def mark_self_as_done_processing(self): "Telling Profiler to stop because " "no more input is arriving.", log_to_logfiles_only=True, ) - number_of_profiler_workers: int = ( - self.db.get_profiler_workers_started() - ) - for _ in range(number_of_profiler_workers): + # ok this very terrible solution is to prevent the race condition + # that happens when the analyzed file is extremely small, that the + # input reads it, sends to the profiler queue, and reaches here, + # before the workers all start!! so we end up sending 0 stop msgs + # because 0 workers has started. this race condition causes slips + # to stay up forever waiting for stop msgs that will never be recvd + # in the profiler. + # this says " if the input took less than 3mins to reach this line, + # give slips extra 10s justt o make sure profilers are started + # before sending the stop msgs" + max_time_slips_can_take_to_start_all_processes = 60 * 3 + if ( + time.time() + < float(self.db.get_slips_start_time()) + + max_time_slips_can_take_to_start_all_processes + ): + self.print( + "Giving Slips time to start all profilers.", + log_to_logfiles_only=True, + ) + time.sleep(20) + + started_workers: int = self.db.get_profiler_workers_started() + self.print( + f"Sending {started_workers} stop " + f"signals for the profiler workers.", + log_to_logfiles_only=True, + ) + for _ in range(started_workers): self.profiler_queue.put("stop") + # this has to be done after the sentinel is put in the queue, # or else we'll have a deadlock when slips is stopping if self.is_input_done_event is not None: @@ -202,7 +229,7 @@ def shutdown_gracefully(self): try: self.active_handler.shutdown_gracefully() except Exception: - pass + self.print_traceback() return True @@ -214,6 +241,9 @@ def give_profiler(self, line): to_send = {"line": line, "input_type": self.input_type} # when the queue is full, it blocks forever until a free slot is # available + if self.conf.generate_performance_plots(): + # record the flow for per-minute stats + self.db.record_flow_per_minute("input") self.profiler_queue.put(to_send, block=True, timeout=None) def main(self): diff --git a/slips_files/core/input/zeek/zeek_dir_input.py b/slips_files/core/input/zeek/zeek_dir_input.py index a02673c211..5efa851b05 100644 --- a/slips_files/core/input/zeek/zeek_dir_input.py +++ b/slips_files/core/input/zeek/zeek_dir_input.py @@ -62,10 +62,9 @@ def run(self): continue if not growing_zeek_dir: - # get the total number of flows slips is going to read + # get the total number of flow in this file total_flows += self.input.get_flows_number(full_path) - # Add log file to the database self.db.add_zeek_file(full_path, interface) # in testing mode, we only need to read one zeek file to know @@ -79,9 +78,8 @@ def run(self): self.input.total_flows = total_flows self.db.set_input_metadata({"total_flows": total_flows}) - # needed in store_flows_read_per_second() + # keeps running until all zeek logs are over. self.input.lines = self.input.zeek_utils.read_zeek_files() - return True def shutdown_gracefully(self): diff --git a/slips_files/core/input_profilers/argus.py b/slips_files/core/input_profilers/argus.py index 604decb945..2c96daa3a2 100644 --- a/slips_files/core/input_profilers/argus.py +++ b/slips_files/core/input_profilers/argus.py @@ -33,6 +33,10 @@ def process_line(self, new_line: dict) -> Tuple[bool, str]: line = new_line["data"] nline = line.strip().split(self.separator) + if self.is_header_line(nline): + self.define_columns(new_line) + return False, "Defined Columns" + def get_value_of(field_name, default_=False): """field_name is used to get the index of the field from the column_idx dict""" @@ -42,6 +46,13 @@ def get_value_of(field_name, default_=False): except (IndexError, KeyError): return default_ + def get_int_value_of(field_name) -> int: + value = get_value_of(field_name, 0) + try: + return int(value) + except (TypeError, ValueError): + return 0 + self.flow: ArgusConn = ArgusConn( starttime=utils.convert_to_datetime(get_value_of("starttime")), endtime=get_value_of("endtime"), @@ -54,12 +65,12 @@ def get_value_of(field_name, default_=False): daddr=get_value_of("daddr"), dport=get_value_of("dport"), state=get_value_of("state"), - pkts=int(get_value_of("pkts")), - spkts=int(get_value_of("spkts")), - dpkts=int(get_value_of("dpkts")), - bytes=int(get_value_of("bytes")), - sbytes=int(get_value_of("sbytes")), - dbytes=int(get_value_of("dbytes")), + pkts=get_int_value_of("pkts"), + spkts=get_int_value_of("spkts"), + dpkts=get_int_value_of("dpkts"), + bytes=get_int_value_of("bytes"), + sbytes=get_int_value_of("sbytes"), + dbytes=get_int_value_of("dbytes"), interface="default", ) @@ -137,3 +148,9 @@ def define_columns(self, new_line: dict) -> dict: ) self.print(traceback.format_exc(), 0, 1) sys.exit(1) + + def is_header_line(self, nline) -> bool: + """Return True when the current line looks like an Argus header.""" + header_tokens = {"starttime", "time", "srcaddr", "dstaddr", "totpkts"} + normalized_fields = {field.strip().lower() for field in nline} + return bool(header_tokens.intersection(normalized_fields)) diff --git a/slips_files/core/input_profilers/zeek_to_slips_maps.py b/slips_files/core/input_profilers/zeek_to_slips_maps.py index ac99eca5d7..ffda7aa506 100644 --- a/slips_files/core/input_profilers/zeek_to_slips_maps.py +++ b/slips_files/core/input_profilers/zeek_to_slips_maps.py @@ -86,9 +86,12 @@ "ts": "starttime", "uid": "uid", "id.orig_h": "saddr", + "id.orig_p": "sport", "id.resp_h": "daddr", + "id.resp_p": "dport", "version": "version", "auth_success": "auth_success", + "auth_attempts": "auth_attempts", "client": "client", "server": "server", "cipher_alg": "cipher_alg", @@ -198,7 +201,8 @@ "ts": "starttime", "host": "saddr", "host_p": "sport", - "name": "software", + "software_type": "software", + "name": "software_name", "version.major": "version_major", "version.minor": "version_minor", "unparsed_version": "unparsed_version", diff --git a/slips_files/core/profiler.py b/slips_files/core/profiler.py index 90d5a52dc7..a87b7f23db 100644 --- a/slips_files/core/profiler.py +++ b/slips_files/core/profiler.py @@ -41,7 +41,6 @@ from slips_files.core.input_profilers.suricata import Suricata from slips_files.core.input_profilers.zeek import ZeekJSON, ZeekTabs from slips_files.core.profiler_worker import ProfilerWorker -from slips_files.core.helpers.localnet_cache import LocalnetCacheShared SUPPORTED_INPUT_TYPES = { InputType.ZEEK: ZeekJSON, @@ -102,14 +101,10 @@ def init( self.profiler_child_processes: List[Process] = [] # to access their internal attributes if needed self.workers: List[ProfilerWorker] = [] - self.stop_aid_manager_event = multiprocessing.Event() # is set by this module to indicate to the monitor thread that # workers stoppped. self.did_all_workers_stop = multiprocessing.Event() self.last_worker_id = -1 - self.handle_setting_local_net_lock = multiprocessing.Lock() - # small, shared JSON cache backed by shared memory (no Manager) - self.localnet_cache = LocalnetCacheShared() # max parallel profiler workers to start when high throughput is detected self.max_workers = 6 # 30MBs max size of this queue to avoid growing forever in mem @@ -120,7 +115,6 @@ def init( self.aid_manager = AIDManager( self.db, self.aid_queue, - self.stop_aid_manager_event, ) now = time.monotonic() self.next_throughput_check_time = now + 300 @@ -224,16 +218,14 @@ def start_profiler_worker(self, worker_id: int = None): logger=self.logger, output_dir=self.output_dir, redis_port=self.redis_port, - termination_event=self.stop_aid_manager_event, + termination_event=self.termination_event, conf=self.conf, ppid=self.ppid, slips_args=self.args, bloom_filters_manager=self.bloom_filters, # module specific kwargs name=worker_name, - localnet_cache=self.localnet_cache, profiler_queue=self.profiler_queue, - handle_setting_local_net_lock=self.handle_setting_local_net_lock, input_handler=self.input_handler_obj, aid_queue=self.aid_queue, aid_manager=self.aid_manager, @@ -270,38 +262,38 @@ def get_handler_obj( return input_handler_cls def shutdown_gracefully(self): - # wait for all flows to be processed by the profiler processes. - self.stop_profiler_workers() - - self.aid_queue.put("stop") - self.stop_aid_manager_event.set() - self.aid_manager.shutdown() - - used_queues = [ - self.profiler_queue, - self.aid_queue, - ] - - for q in used_queues: - # By default if a process is not the creator of the queue then on - # exit it will attempt to join the queue’s background thread. The - # process can call cancel_join_thread() to make join_thread() - # do nothing. - q.cancel_join_thread() - - # close the queues to avoid deadlocks. - # this step SHOULD NEVER be done before closing the workers - q.close() - - if self.profiler_monitor_thread.is_alive(): - self.profiler_monitor_thread.join(timeout=5) - - self.print( - "Stopping.", - log_to_logfiles_only=True, - ) - self.mark_self_as_done_processing() - self.db.set_new_incoming_flows(False) + try: + # wait for all flows to be processed by the profiler processes. + self.stop_profiler_workers() + + self.aid_queue.put("stop") + self.aid_manager.shutdown() + + used_queues = [ + self.profiler_queue, + self.aid_queue, + ] + + for q in used_queues: + # By default if a process is not the creator of the queue then on + # exit it will attempt to join the queue’s background thread. The + # process can call cancel_join_thread() to make join_thread() + # do nothing. + q.cancel_join_thread() + + # close the queues to avoid deadlocks. + # this step SHOULD NEVER be done before closing the workers + q.close() + + if self.profiler_monitor_thread.is_alive(): + self.profiler_monitor_thread.join(timeout=5) + finally: + self.print( + "Stopping.", + log_to_logfiles_only=True, + ) + self.mark_self_as_done_processing() + self.db.set_new_incoming_flows(False) def did_5min_pass_since_last_throughput_check(self) -> bool: """ @@ -398,6 +390,9 @@ def main(self): time.sleep(0.1) self.input_handler_obj = self.get_handler_obj(msg) + # put again that msg in queue to be processed by the profilers, + # we just checked it here to determine the input handler obj + self.profiler_queue.put(msg) if not self.input_handler_obj: self.print("Unsupported input type, exiting.") return 1 @@ -409,7 +404,7 @@ def main(self): utils.start_thread(self.profiler_monitor_thread, self.db) # slips starts with these workers by default until it detects # high throughput that these workers arent enough to handle - num_of_profiler_workers = 5 + num_of_profiler_workers = 3 for worker_id in range(num_of_profiler_workers): self.last_worker_id = worker_id self.start_profiler_worker(worker_id) diff --git a/slips_files/core/profiler_worker.py b/slips_files/core/profiler_worker.py index 0759816591..c43cf3f1c5 100644 --- a/slips_files/core/profiler_worker.py +++ b/slips_files/core/profiler_worker.py @@ -1,27 +1,28 @@ +import csv import json import os -from dataclasses import asdict -import ipaddress import pprint +import time +import ipaddress import multiprocessing +from dataclasses import asdict from typing import ( List, Union, Optional, - Dict, Callable, ) from ipaddress import IPv4Network, IPv6Network, IPv4Address, IPv6Address -import netifaces -import validators import gc from slips_files.common.abstracts.imodule import IModule from slips_files.common.slips_utils import utils +from slips_files.common.performance_paths import get_performance_csv_path from slips_files.common.style import green from slips_files.core.aid_manager import AIDManager from slips_files.core.helpers.flow_handler import FlowHandler +from slips_files.core.helpers.localnet_handler import LocalnetHandler from slips_files.core.helpers.symbols_handler import SymbolHandler from slips_files.core.helpers.whitelist.whitelist import Whitelist from slips_files.core.input_profilers.argus import Argus @@ -37,9 +38,7 @@ class ProfilerWorker(IModule): def init( self, name, - localnet_cache, profiler_queue: multiprocessing.Queue, - handle_setting_local_net_lock: multiprocessing.Lock, input_handler: ( ZeekTabs | ZeekJSON | Argus | Suricata | ZeekTabs | Nfdump ), @@ -58,10 +57,9 @@ def init( # this is an instance of # ZeekTabs | ZeekJSON | Argus | Suricata | ZeekTabs | Nfdump self.input_handler = input_handler - self.handle_setting_local_net_lock = handle_setting_local_net_lock self.read_configuration() self.received_lines = 0 - self.localnet_cache = localnet_cache + self.localnet_handler = LocalnetHandler(self) self.whitelist = Whitelist(self.logger, self.db, self.bloom_filters) self.symbol = SymbolHandler(self.logger, self.db) # stores the MAC addresses of the gateway of each interface @@ -71,6 +69,17 @@ def init( # flag to know which flow is the start of the pcap/file self.first_flow = True self.is_running_non_stop: bool = self.db.is_running_non_stop() + self.slips_start_time = self._get_slips_start_time() + self.latency_logfile = None + if self.generate_performance_plots: + self.latency_logfile = get_performance_csv_path( + self.output_dir, + f"{self._get_latency_filename_prefix()}_latency.csv", + ) + self._initialize_latency_logfile() + self._modified_tws = {} + self._time_to_update_modified_tws = time.time() + self._modified_timewindows_update_period = 3 # in seconds def subscribe_to_channels(self): self.c1 = self.db.subscribe("new_zeek_fields_line") @@ -88,6 +97,9 @@ def read_configuration(self): self.analysis_direction = self.conf.analysis_direction() self.label = self.conf.label() self.width = self.conf.get_tw_width_in_seconds() + self.generate_performance_plots = ( + self.conf.generate_performance_plots() is True + ) def get_msg_from_queue(self, q: multiprocessing.Queue): """ @@ -98,21 +110,9 @@ def get_msg_from_queue(self, q: multiprocessing.Queue): except multiprocessing.queues.Empty: return None except Exception: + self.print_traceback() return None - def get_private_client_ips( - self, - ) -> List[Union[IPv4Network, IPv6Network, IPv4Address, IPv6Address]]: - """ - returns the private ips found in the client_ips param - in the config file - """ - private_clients = [] - for ip in self.client_ips: - if utils.is_private_ip(ip): - private_clients.append(ip) - return private_clients - def convert_starttime_to_unix_ts(self, starttime) -> str: if utils.is_unix_ts(starttime): return starttime @@ -139,6 +139,71 @@ def store_first_seen_ts(self, ts): self.db.set_input_metadata({"file_start": ts}) + def _get_slips_start_time(self) -> float: + slips_start_time = self.db.get_slips_start_time() + try: + return float(slips_start_time) + except (TypeError, ValueError): + return time.time() + + def _get_latency_filename_prefix(self) -> str: + if self.name.startswith("ProfilerWorker_Process_"): + worker_id = self.name.split("_")[-1] + return f"profiler_worker_{worker_id}" + return self.name.lower() + + def _initialize_latency_logfile(self): + if not self.latency_logfile: + return + + os.makedirs(os.path.dirname(self.latency_logfile), exist_ok=True) + if os.path.exists(self.latency_logfile): + return + + with open( + self.latency_logfile, "w", newline="", encoding="utf-8" + ) as f: + writer = csv.writer(f) + writer.writerow( + ["timestamp_now", "flow_uid", "latency_in_seconds"] + ) + + def _log_flow_latency(self, flow, flow_starttime) -> None: + if not self.generate_performance_plots or not self.latency_logfile: + return + + try: + flow_start_ts = float(flow_starttime) + except (TypeError, ValueError): + return + + now = time.time() + timestamp_now = now - self.slips_start_time + latency = now - flow_start_ts + flow_uid = getattr(flow, "uid", "") + + with open( + self.latency_logfile, "a", newline="", encoding="utf-8" + ) as f: + writer = csv.writer(f) + writer.writerow([timestamp_now, flow_uid, int(latency)]) + + def _update_modified_tws_in_the_db(self, profileid: str, twid: str, flow): + """ + to avoid updating the modified tws in the db for every single flow, + we batch the updates and do them every 3 seconds + """ + self._modified_tws.update({f"{profileid}_{twid}": flow.starttime}) + now = time.time() + if now > self._time_to_update_modified_tws: + self._time_to_update_modified_tws = ( + now + self._modified_timewindows_update_period + ) + # now that slips successfully parsed the flow, + # mark this profile as modified + self.db.mark_profile_tw_as_modified(self._modified_tws) + self._modified_tws = {} + def store_features_going_in(self, profileid: str, twid: str, flow): """ If we have the all direction set , slips creates profiles @@ -167,10 +232,7 @@ def store_features_going_in(self, profileid: str, twid: str, flow): self.db.add_ips(profileid, twid, flow, role) # Add the flow with all the fields interpreted to the sqlite db self.aid_manager.submit_aid_task(flow, profileid, twid, self.label) - - # now that slips successfully parsed the flow, - # mark this profile as modified - self.db.mark_profile_tw_as_modified(profileid, twid, flow.starttime) + self._update_modified_tws_in_the_db(profileid, twid, flow) def get_aid_and_store_flow_in_the_db( self, @@ -246,7 +308,7 @@ def store_features_going_out(self, flow, profileid, twid): ) # now that slips successfully parsed the flow, # mark this profile as modified - self.db.mark_profile_tw_as_modified(profileid, twid, flow.starttime) + self._update_modified_tws_in_the_db(profileid, twid, flow) return True def get_rev_profile(self, flow): @@ -267,80 +329,6 @@ def get_rev_profile(self, flow): rev_twid: str = self.db.get_timewindow(flow.starttime, rev_profileid) return rev_profileid, rev_twid - def get_localnet_of_given_interface(self) -> Dict[str, str]: - """ - returns the local network of the given interface only if slips is - running with -i - """ - local_nets = {} - for interface in utils.get_all_interfaces(self.args): - addrs = netifaces.ifaddresses(interface).get(netifaces.AF_INET) - if not addrs: - return local_nets - - for addr in addrs: - ip = addr.get("addr") - netmask = addr.get("netmask") - if ip and netmask: - network = ipaddress.IPv4Network( - f"{ip}/{netmask}", strict=False - ) - local_nets[interface] = str(network) - return local_nets - - def get_local_net_of_flow(self, flow) -> Dict[str, str]: - """ - gets the local network from client_ip - param in the config file, - or by using the localnetwork of the first private - srcip seen in the traffic - """ - local_net = {} - # Reaching this func means slips is running on a file. we either - # have a client ip or not - private_client_ips: List[ - Union[IPv4Network, IPv6Network, IPv4Address, IPv6Address] - ] - # get_private_client_ips from the config file - if private_client_ips := self.get_private_client_ips(): - # does the client ip from the config already have the localnet? - for range_ in private_client_ips: - if isinstance(range_, IPv4Network) or isinstance( - range_, IPv6Network - ): - local_net["default"] = str(range_) - return local_net - - # For now the local network is only ipv4, but it - # could be ipv6 in the future. Todo. - ip: str = flow.saddr - if cidr := utils.get_cidr_of_private_ip(ip): - local_net["default"] = cidr - return local_net - - return local_net - - def handle_setting_local_net(self, flow): - """ - stores the local network if possible - sets the self.localnet_cache dict - """ - # this lock is to avoid running this func from the workers at the - # same time. - with self.handle_setting_local_net_lock: - if not self.should_set_localnet(flow): - return - - if self.db.is_running_non_stop(): - self._set_localnet_cache( - self.get_localnet_of_given_interface() - ) - else: - self._set_localnet_cache(self.get_local_net_of_flow(flow)) - - for interface, local_net in self._iter_localnet_cache_items(): - self.db.set_local_network(local_net, interface) - def is_gw_info_detected(self, info_type: str, interface: str) -> bool: """ checks own attributes and the db for the gw mac/ip @@ -466,72 +454,6 @@ def is_ignored_ip(self, ip: str) -> bool: or ip_obj.is_reserved ) - def should_set_localnet(self, flow) -> bool: - """ - returns true only if the saddr of the current flow is ipv4, private - and we don't have the local_net set already - """ - if self.db.is_running_non_stop(): - if self._localnet_cache_contains(flow.interface): - return False - elif self._localnet_cache_contains("default"): - # running on a file, impossible to get the interface - return False - - if flow.saddr == "0.0.0.0": - return False - - if self.get_private_client_ips(): - # if we have private client ips, we're ready to set the - # localnetwork - return True - - if not validators.ipv4(flow.saddr): - return False - - if self.is_ignored_ip(flow.saddr): - return False - - saddr_obj = ipaddress.ip_address(flow.saddr) - if not utils.is_private_ip(saddr_obj): - return False - - return True - - def _localnet_cache_contains(self, interface: str) -> bool: - """checks""" - cache = self.localnet_cache - if hasattr(cache, "contains"): - return cache.contains(interface) - try: - return interface in cache - except (AttributeError, TypeError): - self.localnet_cache = {} - return False - - def _iter_localnet_cache_items(self): - cache = self.localnet_cache - if hasattr(cache, "items"): - try: - return list(cache.items()) - except TypeError: - pass - if isinstance(cache, dict): - return list(cache.items()) - self.localnet_cache = {} - return [] - - def _set_localnet_cache(self, new_cache: Dict[str, str]) -> None: - cache = self.localnet_cache - if hasattr(cache, "set"): - if cache.set(new_cache): - return - if isinstance(cache, dict): - cache.clear() - cache.update(new_cache) - return - self.localnet_cache = new_cache - def _is_supported_flow_type(self, flow) -> bool: supported_types = ( "ssh", @@ -575,6 +497,9 @@ def add_flow_to_profile(self, flow): # software and weird.log flows are allowed to not have a daddr return False + flow_starttime = self.convert_starttime_to_unix_ts(flow.starttime) + self._log_flow_latency(flow, flow_starttime) + self.get_gateway_info(flow) # Check if the flow is whitelisted and we should not process it if self.whitelist.is_whitelisted_flow(flow): @@ -586,13 +511,13 @@ def add_flow_to_profile(self, flow): # in this tw for this profile profileid = f"profile_{flow.saddr}" self.print(f"Storing data in the profile: {profileid}", 3, 0) - flow.starttime = self.convert_starttime_to_unix_ts(flow.starttime) + flow.starttime = flow_starttime # Create profiles for all ips we see self.db.add_profile(profileid, flow.starttime) # For this 'forward' profile, find the id in the - # database of the tw where the flow belongs. n = time.time() + # database of the tw where the flow belongs. twid = self.db.get_timewindow(flow.starttime, profileid) self.store_features_going_out(flow, profileid, twid) @@ -657,11 +582,6 @@ def main(self): msg = self.get_msg_from_queue(self.profiler_queue) if not msg: - if ( - self.is_input_done_event is not None - and self.is_input_done_event.is_set() - ): - return 1 return if self.is_stop_msg(msg): @@ -689,9 +609,12 @@ def main(self): return self.add_flow_to_profile(flow) - self.handle_setting_local_net(flow) + self.localnet_handler.handle_setting_local_net(flow) self.db.increment_processed_flows() + if self.generate_performance_plots: + self.db.record_flow_per_minute(self.name) + # manually run garbage collection to avoid the latency # introduced by it when slips is given a huge number of flows if self.received_lines % 10000 == 0: diff --git a/tests/module_factory.py b/tests/module_factory.py index b9a4ed9127..d006a1a220 100644 --- a/tests/module_factory.py +++ b/tests/module_factory.py @@ -377,6 +377,23 @@ def create_flowalerts_obj(self, mock_db): flowalerts.print = Mock() return flowalerts + @patch(MODULE_DB_MANAGER, name="mock_db") + def create_bruteforcing_obj(self, mock_db): + from modules.bruteforcing.bruteforcing import Bruteforcing + + bruteforcing = Bruteforcing( + logger=self.logger, + output_dir="dummy_output_dir", + redis_port=6379, + termination_event=Mock(), + slips_args=Mock(), + conf=Mock(), + ppid=Mock(), + bloom_filters_manager=Mock(), + ) + bruteforcing.print = Mock() + return bruteforcing + @patch(DB_MANAGER, name="mock_db") def create_dns_analyzer_obj(self, mock_db): from modules.flowalerts.dns import DNS @@ -561,9 +578,7 @@ def create_profiler_worker_obj(self, mock_db): ppid=Mock(), bloom_filters_manager=Mock(), name="mock_name", - localnet_cache={}, profiler_queue=Mock(), - handle_setting_local_net_lock=Mock(), input_handler=Mock(), aid_queue=Mock(), aid_manager=Mock(), @@ -860,6 +875,61 @@ def create_evidence_handler_obj(self, mock_db): handler.db = mock_db return handler + @patch(MODULE_DB_MANAGER, name="mock_db") + def create_evidence_handler_worker_obj(self, mock_db): + from slips_files.core.evidence_handler_worker import ( + EvidenceHandlerWorker, + ) + + def fake_read_configuration(worker): + worker.width = 3600 + worker.detection_threshold = 0.25 + worker.popup_alerts = False + worker.use_p2p = False + worker.exporting_modules_enabled = False + worker.generate_performance_plots = False + + with ( + patch( + "slips_files.core.evidence_handler_worker.Whitelist", + return_value=Mock(), + ), + patch( + "slips_files.core.evidence_handler_worker.IDMEFv2", + return_value=Mock(), + ), + patch( + "slips_files.core.evidence_handler_worker.Notify", + return_value=Mock(bin_found=False), + ), + patch( + "slips_files.core.evidence_handler_worker." + "EvidenceHandlerWorker.read_configuration", + new=fake_read_configuration, + ), + patch( + "slips_files.core.evidence_handler_worker.utils.get_own_ips", + return_value=[], + ), + ): + worker = EvidenceHandlerWorker( + logger=self.logger, + output_dir="/tmp", + redis_port=6379, + termination_event=Mock(), + slips_args=Mock(), + conf=Mock(), + ppid=Mock(), + bloom_filters_manager=Mock(), + name="EvidenceHandlerWorker_Process_0", + evidence_queue=Mock(), + evidence_logger_q=Mock(), + ) + + worker.db = mock_db + worker.print = Mock() + return worker + def create_evidence_loggr_obj(self): from slips_files.core.evidence_logger import EvidenceLogger @@ -1008,6 +1078,7 @@ def create_process_manager_obj(self): "fidesModule", "irisModule", ] + main_mock.conf.generate_performance_plots.return_value = False main_mock.input_type = InputType.PCAP main_mock.mode = "normal" main_mock.stdout = "" diff --git a/tests/unit/modules/bruteforcing/test_bruteforcing.py b/tests/unit/modules/bruteforcing/test_bruteforcing.py new file mode 100644 index 0000000000..9075fb7cee --- /dev/null +++ b/tests/unit/modules/bruteforcing/test_bruteforcing.py @@ -0,0 +1,175 @@ +# SPDX-FileCopyrightText: 2021 Sebastian Garcia +# SPDX-License-Identifier: GPL-2.0-only + +from slips_files.core.flows.zeek import Notice, SSH, Software +from slips_files.core.structures.evidence import ThreatLevel +from tests.module_factory import ModuleFactory + + +PROFILEID = "profile_147.32.80.40" +TWID = "timewindow1" +SRCIP = "147.32.80.40" +DSTIP = "147.32.80.37" +DPORT = "902" + + +def make_ssh_flow( + uid: str, + client: str = "SSH-2.0-OpenSSH_9.6p1", + auth_success="F", + auth_attempts=1, +): + return SSH( + starttime="1726655400.0", + uid=uid, + saddr=SRCIP, + daddr=DSTIP, + version=2, + auth_success=auth_success, + auth_attempts=auth_attempts, + client=client, + server="SSH-2.0-OpenSSH_9.6p1", + cipher_alg="", + mac_alg="", + compression_alg="", + kex_alg="", + host_key_alg="", + host_key="", + sport="40422", + dport=DPORT, + ) + + +def make_software_flow(): + return Software( + starttime="1726655400.0", + uid="software-uid", + saddr=SRCIP, + sport=40422, + software="SSH::CLIENT", + software_name="libssh", + unparsed_version="libssh2_1.11.0", + version_major="2", + version_minor="1", + ) + + +def make_notice_flow(): + return Notice( + starttime="1726655400.0", + saddr=SRCIP, + daddr="", + sport="", + dport="", + note="SSH::Password_Guessing", + msg=( + f"{SRCIP} appears to be guessing SSH passwords " + f"(seen in 30 connections)." + ), + scanned_port="", + dst="", + scanning_ip=SRCIP, + uid="notice-uid", + ) + + +def drive_threshold(module, client_banner="SSH-2.0-OpenSSH_9.6p1"): + module.db.get_port_info.return_value = "SSH" + for i in range(module.ssh_attempt_threshold): + module._handle_ssh( + PROFILEID, + TWID, + make_ssh_flow(uid=f"uid-{i}", client=client_banner), + ) + return module.db.set_evidence.call_args[0][0] + + +def test_software_banner_increases_bruteforcing_confidence(): + plain_module = ModuleFactory().create_bruteforcing_obj() + plain_evidence = drive_threshold(plain_module) + + banner_module = ModuleFactory().create_bruteforcing_obj() + banner_module._handle_software(make_software_flow()) + banner_evidence = drive_threshold( + banner_module, client_banner="SSH-2.0-libssh2_1.11.0" + ) + + assert banner_evidence.confidence > plain_evidence.confidence + assert plain_evidence.threat_level == ThreatLevel.MEDIUM + assert "libssh" in banner_evidence.description + assert banner_evidence.dst_port == 902 + + +def test_bruteforcing_uses_sparse_bucketed_reporting(): + bruteforcing = ModuleFactory().create_bruteforcing_obj() + bruteforcing.db.get_port_info.return_value = "SSH" + + for attempt in range(1, 25): + bruteforcing._handle_ssh( + PROFILEID, + TWID, + make_ssh_flow(uid=f"uid-{attempt}"), + ) + + assert bruteforcing.db.set_evidence.call_count == 5 + observed_attempt_counts = [ + len(call_args[0][0].uid) + for call_args in bruteforcing.db.set_evidence.call_args_list + ] + assert observed_attempt_counts == [9, 10, 12, 16, 24] + + +def test_confidence_reaches_full_at_30_attempts(): + bruteforcing = ModuleFactory().create_bruteforcing_obj() + threshold_confidence = bruteforcing._calculate_confidence( + bruteforcing.ssh_attempt_threshold, + "SSH-2.0-OpenSSH_9.6p1", + "ssh.log", + ) + full_confidence = bruteforcing._calculate_confidence( + bruteforcing.ssh_full_confidence_attempts, + "SSH-2.0-OpenSSH_9.6p1", + "ssh.log", + ) + + assert threshold_confidence < 1.0 + assert full_confidence == 1.0 + + evidence = drive_threshold(bruteforcing) + assert evidence.threat_level == ThreatLevel.MEDIUM + + +def test_notice_confirmation_emits_zeek_evidence_and_confirms_future_alerts(): + bruteforcing = ModuleFactory().create_bruteforcing_obj() + drive_threshold(bruteforcing) + bruteforcing.db.set_evidence.reset_mock() + + bruteforcing._handle_notice(PROFILEID, TWID, make_notice_flow()) + zeek_evidence = bruteforcing.db.set_evidence.call_args[0][0] + assert zeek_evidence.confidence == 1.0 + assert zeek_evidence.threat_level == ThreatLevel.MEDIUM + assert "Confirmed by Zeek notice.log." in zeek_evidence.description + + bruteforcing.db.set_evidence.reset_mock() + bruteforcing._handle_ssh(PROFILEID, TWID, make_ssh_flow(uid="uid-10")) + confirmed_evidence = bruteforcing.db.set_evidence.call_args[0][0] + assert confirmed_evidence.confidence == 1.0 + assert "Confirmed by Zeek notice.log." in confirmed_evidence.description + + +def test_repeated_ssh_sessions_without_auth_attempts_still_trigger_detection(): + bruteforcing = ModuleFactory().create_bruteforcing_obj() + bruteforcing.db.get_port_info.return_value = "SSH" + + for attempt in range(20): + bruteforcing._handle_ssh( + PROFILEID, + TWID, + make_ssh_flow( + uid=f"uid-{attempt}", + auth_success="", + auth_attempts=0, + ), + ) + + assert bruteforcing.db.set_evidence.call_count == 4 diff --git a/tests/unit/modules/flowalerts/test_conn.py b/tests/unit/modules/flowalerts/test_conn.py index ce07709d44..5d6c520d86 100644 --- a/tests/unit/modules/flowalerts/test_conn.py +++ b/tests/unit/modules/flowalerts/test_conn.py @@ -205,6 +205,43 @@ def test_check_unknown_port_true_case(mocker): mock_set_evidence.assert_called_once_with(twid, flow) +def test_check_unknown_port_uses_lowercase_protocol_for_known_ports(mocker): + conn = ModuleFactory().create_conn_analyzer_obj() + flow = Conn( + starttime="1726249372.312124", + uid="123", + saddr="192.168.1.1", + daddr="147.32.82.7", + dur=1, + proto="UDP", + appproto="", + sport="12345", + dport="53", + spkts=2, + dpkts=1, + sbytes=120, + dbytes=60, + smac="", + dmac="", + state="Established", + history="S", + ) + + flow.interpreted_state = "Established" + conn.db.is_a_port_scanner = Mock(return_value=False) + conn.db.get_port_info = Mock(return_value="DNS") + conn.db.is_ftp_port = Mock(return_value=False) + mocker.patch.object(conn, "port_belongs_to_an_org", return_value=False) + mocker.patch.object(conn, "is_p2p", return_value=False) + mock_set_evidence = mocker.patch.object(conn.set_evidence, "unknown_port") + + profileid = f"profile_{flow.saddr}" + + assert conn.check_unknown_port(profileid, twid, flow) is False + conn.db.get_port_info.assert_called_once_with("53/udp") + mock_set_evidence.assert_not_called() + + @pytest.mark.parametrize( "origstate, saddr, daddr, dport, uids, interpreted_state, expected_calls", [ diff --git a/tests/unit/modules/flowalerts/test_notice.py b/tests/unit/modules/flowalerts/test_notice.py index 22542f67e6..c2238b860c 100644 --- a/tests/unit/modules/flowalerts/test_notice.py +++ b/tests/unit/modules/flowalerts/test_notice.py @@ -184,7 +184,7 @@ def test_check_password_guessing(mocker, flow, expected_call_count): ) }, True, - {"vertical": 1, "horizontal": 1, "password": 1}, + {"vertical": 1, "horizontal": 1, "password": 0}, ), ], ) diff --git a/tests/unit/modules/flowalerts/test_ssh.py b/tests/unit/modules/flowalerts/test_ssh.py index 74835223ca..ad7fb34ce5 100644 --- a/tests/unit/modules/flowalerts/test_ssh.py +++ b/tests/unit/modules/flowalerts/test_ssh.py @@ -85,44 +85,6 @@ async def test_check_successful_ssh( assert mock_detect_slips.called == expected_called_slips -@pytest.mark.parametrize( - "auth_success, expected_call_count", - [ - # Testcase 1: Successful SSH login should not trigger alert - ("true", False), - # Testcase 2: Successful SSH login should not trigger alert - ("T", False), - # Testcase 3: Failed SSH login should trigger alert after threshold - ("F", True), - ], -) -def test_check_ssh_password_guessing(auth_success, expected_call_count): - ssh = ModuleFactory().create_ssh_analyzer_obj() - mock_set_evidence = MagicMock() - ssh.set_evidence.ssh_pw_guessing = mock_set_evidence - for i in range(ssh.pw_guessing_threshold): - flow = SSH( - starttime="1726655400.0", - uid=f"uid_{i}", - saddr="192.168.1.2", - daddr="1.1.1.1", - version="", - auth_success=auth_success, - auth_attempts="", - client="", - server="", - cipher_alg="", - mac_alg="", - compression_alg="", - kex_alg="", - host_key_alg="", - host_key="", - ) - ssh.check_ssh_password_guessing(profileid, twid, flow) - assert mock_set_evidence.call_count == expected_call_count - ssh.password_guessing_cache = {} - - @patch("modules.flowalerts.ssh.ConfigParser") def test_read_configuration(mock_config_parser): mock_parser = mock_config_parser.return_value @@ -189,19 +151,16 @@ async def test_analyze_no_message(): ssh.flowalerts = MagicMock() ssh.flowalerts.get_msg.return_value = None ssh.check_successful_ssh = MagicMock() - ssh.check_ssh_password_guessing = MagicMock() await ssh.analyze({}) ssh.check_successful_ssh.assert_not_called() - ssh.check_ssh_password_guessing.assert_not_called() @pytest.mark.parametrize("auth_success", ["true", "false"]) async def test_analyze_with_message(auth_success): ssh = ModuleFactory().create_ssh_analyzer_obj() ssh.check_successful_ssh = get_mock_coro(True) - ssh.check_ssh_password_guessing = MagicMock() flow = SSH( starttime="1726655400.0", uid="1234", @@ -229,6 +188,3 @@ async def test_analyze_with_message(auth_success): await ssh.analyze({"channel": "new_ssh", "data": json.dumps(msg_data)}) ssh.check_successful_ssh.assert_called_once_with(twid, flow) - ssh.check_ssh_password_guessing.assert_called_once_with( - profileid, twid, flow - ) diff --git a/tests/unit/slips_files/core/database/redis_db/test_profile_handler.py b/tests/unit/slips_files/core/database/redis_db/test_profile_handler.py index 16c39c741b..553ad64897 100644 --- a/tests/unit/slips_files/core/database/redis_db/test_profile_handler.py +++ b/tests/unit/slips_files/core/database/redis_db/test_profile_handler.py @@ -517,7 +517,7 @@ def test_get_modified_tw_since_time( modified_tws = handler._get_modified_tw_since_time(time) handler.r.zrangebyscore.assert_called_once_with( - "ModifiedTW", time, float("+inf"), withscores=True + "modified_timewindows", time, float("+inf"), withscores=True ) assert modified_tws == expected_modified_tws @@ -1812,54 +1812,90 @@ def test_is_blocked_profile_and_tw(profile_tws, twid, expected_result): @pytest.mark.parametrize( - "timestamp, expected_zadd_call", + "timestamp, expected_zadd_calls", [ # Testcase 1: Normal timestamp ( 1000.0, - call("ModifiedTW", {"profile_1_timewindow1": 1000.0}), + [ + call( + "modified_timewindows", + {"profile_1_timewindow1": 1000.0}, + gt=True, + ), + call( + "modified_timewindows", + {"profile_1_timewindow1": 1000.0}, + nx=True, + ), + ], ), # Testcase 2: Timestamp as string ( "1000.0", - call("ModifiedTW", {"profile_1_timewindow1": 1000.0}), + [ + call( + "modified_timewindows", + {"profile_1_timewindow1": "1000.0"}, + gt=True, + ), + call( + "modified_timewindows", + {"profile_1_timewindow1": "1000.0"}, + nx=True, + ), + ], ), ], ) -def test_mark_profile_tw_as_modified(timestamp, expected_zadd_call): +def test_mark_profile_tw_as_modified(timestamp, expected_zadd_calls): handler = ModuleFactory().create_profile_handler_obj() handler.publish = MagicMock() handler.check_tw_to_close = MagicMock() + pipe = Mock() + handler.r.pipeline = Mock(return_value=pipe) profileid = "profile_1" twid = "timewindow1" + modified_tw_details = {f"{profileid}_{twid}": timestamp} with patch("time.time", return_value=1000.0): - handler.mark_profile_tw_as_modified(profileid, twid, timestamp) + handler.mark_profile_tw_as_modified(modified_tw_details) - handler.r.zadd.assert_called_once_with(*expected_zadd_call.args) - handler.publish.assert_called_once_with( - "tw_modified", - json.dumps( - { - "profileid": profileid, - "twid": twid, - } - ), - ) + handler.r.pipeline.assert_called_once_with() + pipe.zadd.assert_has_calls(expected_zadd_calls) + pipe.execute.assert_called_once_with() -def test_mark_profile_tw_as_modified_requires_timestamp(): +def test_mark_profile_tw_as_modified_allows_missing_timestamp(): handler = ModuleFactory().create_profile_handler_obj() handler.publish = MagicMock() handler.check_tw_to_close = MagicMock() + pipe = Mock() + handler.r.pipeline = Mock(return_value=pipe) profileid = "profile_1" twid = "timewindow1" - with pytest.raises(ValueError): - handler.mark_profile_tw_as_modified(profileid, twid, None) + modified_tw_details = {f"{profileid}_{twid}": None} - handler.r.zadd.assert_not_called() + handler.mark_profile_tw_as_modified(modified_tw_details) + + handler.r.pipeline.assert_called_once_with() + pipe.zadd.assert_has_calls( + [ + call( + "modified_timewindows", + {"profile_1_timewindow1": None}, + gt=True, + ), + call( + "modified_timewindows", + {"profile_1_timewindow1": None}, + nx=True, + ), + ] + ) + pipe.execute.assert_called_once_with() handler.publish.assert_not_called() diff --git a/tests/unit/slips_files/core/database/test_database.py b/tests/unit/slips_files/core/database/test_database.py index 0e5790dc8c..5534d17219 100644 --- a/tests/unit/slips_files/core/database/test_database.py +++ b/tests/unit/slips_files/core/database/test_database.py @@ -55,7 +55,7 @@ def test_subscribe(): # invalid channel assert db.subscribe("invalid_channel") is False # valid channel, shoud return a pubsub object - assert isinstance(db.subscribe("tw_modified"), redis.client.PubSub) + assert isinstance(db.subscribe("new_flow"), redis.client.PubSub) def test_profile_moddule_labels(): diff --git a/tests/unit/slips_files/core/helpers/test_localnet_handler.py b/tests/unit/slips_files/core/helpers/test_localnet_handler.py new file mode 100644 index 0000000000..537bad69e0 --- /dev/null +++ b/tests/unit/slips_files/core/helpers/test_localnet_handler.py @@ -0,0 +1,187 @@ +import ipaddress +from unittest.mock import MagicMock, Mock, call, patch + +import netifaces +import pytest + +from slips_files.core.helpers.localnet_handler import LocalnetHandler + + +def create_profiler( + *, client_ips=None, running_non_stop=False, localnet_cache=None +): + profiler = Mock() + profiler.client_ips = client_ips or [] + profiler.args = Mock(interface=None, access_point=None) + profiler.db = Mock() + profiler.db.is_running_non_stop.return_value = running_non_stop + profiler.handle_setting_local_net_lock = MagicMock() + profiler.is_ignored_ip.return_value = False + return profiler + + +def test_get_private_client_ips_filters_private_entries(): + profiler = create_profiler() + handler = LocalnetHandler(profiler) + + private_clients = handler.get_private_client_ips( + [ + "192.168.1.2", + "8.8.8.8", + ipaddress.IPv4Network("10.0.0.0/8"), + ] + ) + + assert private_clients == [ + "192.168.1.2", + ipaddress.IPv4Network("10.0.0.0/8"), + ] + + +def test_get_private_client_ips_returns_empty_list_for_non_iterable(): + profiler = create_profiler() + handler = LocalnetHandler(profiler) + + assert handler.get_private_client_ips(1) == [] + + +def test_get_local_net_of_flow_prefers_configured_default_localnet(): + profiler = create_profiler( + client_ips=[ipaddress.IPv4Network("192.168.1.0/24")] + ) + handler = LocalnetHandler(profiler) + flow = Mock(saddr="10.0.0.8") + + localnet = handler._get_local_net_of_flow(flow) + + assert localnet == {"default": "192.168.1.0/24"} + + +@patch("slips_files.core.helpers.localnet_handler.netifaces.ifaddresses") +@patch("slips_files.core.helpers.localnet_handler.utils.get_all_interfaces") +def test_get_localnet_of_given_interface_returns_ipv4_networks( + mock_get_all_interfaces, mock_ifaddresses +): + profiler = create_profiler(running_non_stop=True) + handler = LocalnetHandler(profiler) + mock_get_all_interfaces.return_value = ["eth0", "wlan0"] + mock_ifaddresses.side_effect = [ + { + netifaces.AF_INET: [ + {"addr": "192.168.1.12", "netmask": "255.255.255.0"} + ] + }, + {netifaces.AF_INET: [{"addr": "10.0.0.25", "netmask": "255.0.0.0"}]}, + ] + + localnets = handler._get_localnet_of_given_interfaces_using_netifaces() + + assert localnets == { + "eth0": "192.168.1.0/24", + "wlan0": "10.0.0.0/8", + } + + +def test_handle_setting_local_net_updates_cache_and_db(): + profiler = create_profiler(running_non_stop=False) + handler = LocalnetHandler(profiler) + handler.localnet_cache = {"old": "127.0.0.0/8"} + handler._should_set_localnet = Mock(return_value=True) + handler._get_local_net_of_flow = Mock( + return_value={"default": "192.168.1.0/24"} + ) + flow = Mock(saddr="192.168.1.8", interface="eth0") + + handler.handle_setting_local_net(flow) + + assert handler.localnet_cache == {"default": "192.168.1.0/24"} + profiler.db.set_local_network.assert_called_once_with( + "192.168.1.0/24", "default" + ) + + +@pytest.mark.parametrize( + "running_non_stop, localnet_cache, client_ips, saddr, interface, " + "is_ignored_ip, expected", + [ + ( + False, + {"default": "192.168.1.0/24"}, + [], + "192.168.1.8", + "eth0", + False, + False, + ), + ( + True, + {"eth0": "192.168.1.0/24"}, + [], + "192.168.1.8", + "eth0", + False, + False, + ), + (False, {}, [], "0.0.0.0", "eth0", False, False), + ( + False, + {}, + [ipaddress.IPv4Network("10.0.0.0/8")], + "8.8.8.8", + "eth0", + False, + True, + ), + (False, {}, [], "not-an-ip", "eth0", False, False), + (False, {}, [], "224.0.0.1", "eth0", True, False), + (False, {}, [], "8.8.8.8", "eth0", False, False), + (False, {}, [], "192.168.1.8", "eth0", False, True), + ], +) +def test_should_set_localnet( + running_non_stop, + localnet_cache, + client_ips, + saddr, + interface, + is_ignored_ip, + expected, +): + profiler = create_profiler( + client_ips=client_ips, + running_non_stop=running_non_stop, + localnet_cache=localnet_cache, + ) + profiler.is_ignored_ip.return_value = is_ignored_ip + handler = LocalnetHandler(profiler) + handler.localnet_cache = localnet_cache + flow = Mock(saddr=saddr, interface=interface) + + assert handler._should_set_localnet(flow) is expected + + +def test_handle_setting_local_net_stores_interface_localnets_in_non_stop_mode(): + profiler = create_profiler(running_non_stop=True) + handler = LocalnetHandler(profiler) + handler._should_set_localnet = Mock(return_value=True) + handler._get_localnet_of_given_interfaces_using_netifaces = Mock( + return_value={ + "eth0": "192.168.1.0/24", + "wlan0": "10.0.0.0/8", + } + ) + flow = Mock(saddr="192.168.1.8", interface="eth0") + + handler.handle_setting_local_net(flow) + + assert handler.localnet_cache == { + "eth0": "192.168.1.0/24", + "wlan0": "10.0.0.0/8", + } + profiler.db.set_local_network.assert_has_calls( + [ + call("192.168.1.0/24", "eth0"), + call("10.0.0.0/8", "wlan0"), + ], + any_order=False, + ) diff --git a/tests/unit/slips_files/core/input/test_argus_input_profiler.py b/tests/unit/slips_files/core/input/test_argus_input_profiler.py new file mode 100644 index 0000000000..b0884eab0a --- /dev/null +++ b/tests/unit/slips_files/core/input/test_argus_input_profiler.py @@ -0,0 +1,39 @@ +# SPDX-FileCopyrightText: 2021 Sebastian Garcia +# SPDX-License-Identifier: GPL-2.0-only + +from unittest.mock import Mock + +from slips_files.core.input_profilers.argus import Argus + + +def test_argus_parser_skips_repeated_headers_and_parses_short_binetflow(): + parser = Argus(Mock()) + header = { + "data": ( + "StartTime,Dur,Proto,SrcAddr,Sport,Dir,DstAddr,Dport," + "State,sTos,dTos,TotPkts,TotBytes,SrcBytes,Label" + ) + } + flow_line = { + "data": ( + "2018/09/27 22:40:52.362768,193.831726,tcp,192.168.2.1,52893," + " ,192.168.2.12,22,CON,16,16,35,3766,1224," + ) + } + + flow, err = parser.process_line(header) + assert flow is False + assert err == "Defined Columns" + + flow, err = parser.process_line(header) + assert flow is False + assert err == "Defined Columns" + + flow, err = parser.process_line(flow_line) + assert err == "" + assert flow.pkts == 35 + assert flow.bytes == 3766 + assert flow.sbytes == 1224 + assert flow.dbytes == 0 + assert flow.spkts == 0 + assert flow.dpkts == 0 diff --git a/tests/unit/slips_files/core/input/test_input.py b/tests/unit/slips_files/core/input/test_input.py index 3c9ddb5003..c89ba7eac1 100644 --- a/tests/unit/slips_files/core/input/test_input.py +++ b/tests/unit/slips_files/core/input/test_input.py @@ -309,6 +309,24 @@ def test_read_from_stdin(line_type: str, line: str): assert line_sent["input_type"] == InputType.STDIN +def test_give_profiler_skips_flow_per_minute_when_disabled(): + input = ModuleFactory().create_input_obj("", InputType.STDIN) + input.conf.generate_performance_plots.return_value = False + + input.give_profiler({"line": "value"}) + + input.db.record_flow_per_minute.assert_not_called() + + +def test_give_profiler_records_flow_per_minute_when_enabled(): + input = ModuleFactory().create_input_obj("", InputType.STDIN) + input.conf.generate_performance_plots.return_value = True + + input.give_profiler({"line": "value"}) + + input.db.record_flow_per_minute.assert_called_once_with("input") + + @pytest.mark.parametrize( "line, input_type, expected_line, expected_input_type", [ diff --git a/tests/unit/slips_files/core/input/test_zeek_input_profiler.py b/tests/unit/slips_files/core/input/test_zeek_input_profiler.py new file mode 100644 index 0000000000..b6dfdf8be7 --- /dev/null +++ b/tests/unit/slips_files/core/input/test_zeek_input_profiler.py @@ -0,0 +1,67 @@ +# SPDX-FileCopyrightText: 2021 Sebastian Garcia +# SPDX-License-Identifier: GPL-2.0-only + +from unittest.mock import Mock + +from slips_files.core.input_profilers.zeek import ZeekJSON + + +def test_zeek_json_maps_software_type_and_banner_fields(): + parser = ZeekJSON(Mock()) + flow, err = parser.process_line( + { + "type": "software.log", + "interface": "default", + "data": { + "ts": 1774173495.641272, + "host": "147.32.80.40", + "host_p": 40422, + "software_type": "SSH::CLIENT", + "name": "libssh", + "version.major": 2, + "version.minor": 1, + "version.minor2": 11, + "version.minor3": 0, + "unparsed_version": "libssh2_1.11.0", + }, + } + ) + + assert err == "" + assert flow.software == "SSH::CLIENT" + assert flow.software_name == "libssh" + assert flow.unparsed_version == "libssh2_1.11.0" + + +def test_zeek_json_maps_ssh_ports_and_auth_attempts(): + parser = ZeekJSON(Mock()) + flow, err = parser.process_line( + { + "type": "ssh.log", + "interface": "default", + "data": { + "ts": 1774173495.641272, + "uid": "CpUMTT6FJDsiSlCre", + "id.orig_h": "147.32.80.40", + "id.orig_p": 40422, + "id.resp_h": "147.32.80.37", + "id.resp_p": 902, + "version": 2, + "auth_attempts": 3, + "auth_success": "F", + "client": "SSH-2.0-libssh2_1.11.0", + "server": "SSH-2.0-OpenSSH_9.6p1 Ubuntu-3ubuntu13.11", + "cipher_alg": "", + "mac_alg": "", + "compression_alg": "", + "kex_alg": "", + "host_key_alg": "", + "host_key": "", + }, + } + ) + + assert err == "" + assert flow.sport == 40422 + assert flow.dport == 902 + assert flow.auth_attempts == 3 diff --git a/tests/unit/slips_files/core/test_evidence_handler.py b/tests/unit/slips_files/core/test_evidence_handler.py index 0feaad7f3b..e889a16130 100644 --- a/tests/unit/slips_files/core/test_evidence_handler.py +++ b/tests/unit/slips_files/core/test_evidence_handler.py @@ -1,471 +1,152 @@ # SPDX-FileCopyrightText: 2021 Sebastian Garcia # SPDX-License-Identifier: GPL-2.0-only -from multiprocessing import Event - -import pytest -from unittest.mock import Mock, MagicMock, patch - -from slips_files.core.structures.alerts import Alert -from slips_files.core.structures.evidence import ( - Evidence, - ProfileID, - EvidenceType, - TimeWindow, - Attacker, - IoCType, - Direction, - ThreatLevel, -) + +from unittest.mock import Mock, call, patch + +from slips_files.core.evidence_handler import DEFAULT_EVIDENCE_HANDLER_WORKERS from tests.module_factory import ModuleFactory -from datetime import datetime - - -@pytest.mark.parametrize( - "profileid, our_ips, expected_result, expected_publish_call_count", - [ - # testcase1: IP not in our_ips, should block - ("192.168.1.100", ["10.0.0.1", "172.16.0.1"], True, 1), - # testcase2: IP in our_ips, should not block - ("10.0.0.1", ["10.0.0.1", "172.16.0.1"], False, 0), - # testcase3: Empty our_ips, should block - ("8.8.8.8", [], True, 1), - ], -) -def test_decide_blocking( - mocker, profileid, our_ips, expected_result, expected_publish_call_count -): - evidence_handler = ModuleFactory().create_evidence_handler_obj() - evidence_handler.blocking_modules_supported = True - evidence_handler.our_ips = our_ips - with patch.object(evidence_handler.db, "publish") as mock_publish: - tw = TimeWindow( - 2, "2025-05-09T13:27:45.123456", "2025-05-09T13:27:45.123456" - ) - mocker.patch( - "slips_files.common.slips_utils.Utils.get_interface_of_ip", - return_value="eth0", - ) - result = evidence_handler.decide_blocking(profileid, tw) - - assert result == expected_result - assert mock_publish.call_count == expected_publish_call_count def test_shutdown_gracefully(): - evidence_handler = ModuleFactory().create_evidence_handler_obj() - evidence_handler.logger_thread = Mock() - evidence_handler.logger_stop_signal = Event() - - evidence_handler.shutdown_gracefully() - - assert evidence_handler.logger_stop_signal.is_set() - evidence_handler.logger_thread.join.assert_called_once_with(timeout=5) - - -@pytest.mark.parametrize( - "profileid, twid, past_alerts, expected_output", - [ - # testcase1: No past alerts - ("profile1_192.168.1.1", "timewindow1", {}, []), - # testcase2: One past alert - ( - "profile2_10.0.0.1", - "timewindow2", - {"alert1": '["evidence1", "evidence2"]'}, - ["evidence1", "evidence2"], - ), - ], -) -def test_get_evidence_that_were_part_of_a_past_alert( - profileid, twid, past_alerts, expected_output -): - evidence_handler = ModuleFactory().create_evidence_handler_obj() - evidence_handler.db.get_profileid_twid_alerts.return_value = past_alerts - - result = evidence_handler.get_evidence_that_were_part_of_a_past_alert( - profileid, twid - ) - assert result == expected_output + handler = ModuleFactory().create_evidence_handler_obj() + handler.stop_evidence_workers = Mock() + handler.logger_stop_signal = Mock() + handler.logger_thread = Mock() + handler.evidence_worker_queue = Mock() + handler.evidence_logger_q = Mock() + handler.shutdown_gracefully() -def setup_handler(popup_enabled, blocked, mark_blocked=None): + handler.stop_evidence_workers.assert_called_once() + handler.logger_stop_signal.set.assert_called_once() + handler.logger_thread.join.assert_called_once_with(timeout=5) + handler.evidence_worker_queue.cancel_join_thread.assert_called_once() + handler.evidence_worker_queue.close.assert_called_once() + handler.evidence_logger_q.cancel_join_thread.assert_called_once() + handler.evidence_logger_q.close.assert_called_once() + + +def test_stop_evidence_workers(): handler = ModuleFactory().create_evidence_handler_obj() - handler.popup_alerts = popup_enabled - - alert = Alert( - profile=ProfileID("1.2.3.4"), - timewindow=TimeWindow(1), - last_evidence=Mock(), - accumulated_threat_level=12.2, - last_flow_datetime="2024/10/04 15:45:30.123456+0000", - ) - evidence = {"k": MagicMock(spec=Evidence)} - - handler.db.set_alert = MagicMock() - handler.decide_blocking = MagicMock(side_effect=[False, mark_blocked]) - handler.db.is_blocked_profile_and_tw = MagicMock(return_value=blocked) - handler.send_to_exporting_module = MagicMock() - handler.formatter.format_evidence_for_printing = MagicMock( - return_value="formatted_alert" - ) - handler.print = MagicMock() - handler.show_popup = MagicMock() - handler.db.mark_profile_and_timewindow_as_blocked = MagicMock() - handler.log_alert = MagicMock() - - return handler, alert, evidence - - -@pytest.mark.parametrize("popup_enabled", [True, False]) -def test_handle_new_alert_already_blocked(popup_enabled): - handler, alert, evidence = setup_handler(popup_enabled, blocked=True) - handler.handle_new_alert(alert, evidence) - - handler.db.set_alert.assert_called_once_with(alert, evidence) - handler.db.is_blocked_profile_and_tw.assert_called_once() - handler.send_to_exporting_module.assert_not_called() - handler.print.assert_not_called() - handler.show_popup.assert_not_called() - handler.db.mark_profile_and_timewindow_as_blocked.assert_not_called() - handler.log_alert.assert_not_called() - - -@pytest.mark.parametrize( - "popup_enabled, expect_popup", - [ - (True, True), - (False, False), - ], -) -def test_handle_new_alert_not_blocked(popup_enabled, expect_popup): - handler, alert, evidence = setup_handler( - popup_enabled, blocked=False, mark_blocked=True + process_1 = Mock() + process_2 = Mock() + handler.evidence_worker_child_processes = [process_1, process_2] + handler.evidence_worker_queue = Mock() + + handler.stop_evidence_workers() + + assert handler.evidence_worker_queue.put.call_args_list == [ + call("stop"), + call("stop"), + ] + process_1.join.assert_called_once() + process_2.join.assert_called_once() + + +@patch("slips_files.core.evidence_handler.EvidenceHandlerWorker") +def test_start_evidence_worker(mock_worker_cls): + handler = ModuleFactory().create_evidence_handler_obj() + worker = mock_worker_cls.return_value + handler.evidence_worker_child_processes = [] + handler.evidence_worker_queue = Mock() + handler.evidence_logger_q = Mock() + + handler.start_evidence_worker(7) + + mock_worker_cls.assert_called_once_with( + logger=handler.logger, + output_dir=handler.output_dir, + redis_port=handler.redis_port, + termination_event=handler.termination_event, + conf=handler.conf, + ppid=handler.ppid, + slips_args=handler.args, + bloom_filters_manager=handler.bloom_filters, + name="EvidenceHandlerWorker_Process_7", + evidence_queue=handler.evidence_worker_queue, + evidence_logger_q=handler.evidence_logger_q, ) - handler.handle_new_alert(alert, evidence) + worker.start.assert_called_once() + assert handler.evidence_worker_child_processes == [worker] - handler.send_to_exporting_module.assert_called_once_with(evidence) - handler.print.assert_called_once_with("formatted_alert", 1, 0) - if expect_popup: - handler.show_popup.assert_called_once_with(alert) - else: - handler.show_popup.assert_not_called() +def test_should_stop_returns_false_if_termination_not_set(): + handler = ModuleFactory().create_evidence_handler_obj() + handler.termination_event.is_set.return_value = False - handler.db.mark_profile_and_timewindow_as_blocked.assert_not_called() - handler.log_alert.assert_called_once_with(alert, blocked=False) + assert handler.should_stop() is False -@pytest.mark.parametrize( - "data", - [ - "Test log entry", - "Another log entry", - ], -) -def test_add_to_log_file(data): - evidence_handler = ModuleFactory().create_evidence_handler_obj() - evidence_handler.evidence_logger_q.put = Mock() +@patch("slips_files.core.evidence_handler.time.time", return_value=100.0) +def test_should_stop_waits_when_messages_are_still_arriving(_mock_time): + handler = ModuleFactory().create_evidence_handler_obj() + handler.termination_event.is_set.return_value = True + handler.is_msg_received_in_any_channel = Mock(return_value=True) + handler.last_msg_received_time = 10.0 - # Act - evidence_handler.add_to_log_file(data) + assert handler.should_stop() is False + assert handler.last_msg_received_time == 100.0 - # Assert - evidence_handler.evidence_logger_q.put.assert_called_once_with( - {"to_log": data, "where": "alerts.log"} - ) +@patch("slips_files.core.evidence_handler.time.time", return_value=120.0) +def test_should_stop_waits_for_grace_period(_mock_time): + handler = ModuleFactory().create_evidence_handler_obj() + handler.termination_event.is_set.return_value = True + handler.is_msg_received_in_any_channel = Mock(return_value=False) + handler.last_msg_received_time = 100.0 -@pytest.mark.parametrize( - "all_uids, timewindow, accumulated_threat_level", - [ # Testcase1: Basic alert with UIDs and threat level - ( - ["uid1", "uid2"], - 1, - 0.5, - ), - # Testcase2: Alert without UIDs, high threat level - ( - [], - 10, - 1.0, - ), - ], -) -def test_add_alert_to_json_log_file( - all_uids, timewindow, accumulated_threat_level -): - mock_file = Mock() - alert = Alert( - profile=ProfileID("192.168.1.20"), - timewindow=TimeWindow( - timewindow, - start_time="2024-10-04T18:46:50+03:00", - end_time="2024-10-04T19:46:50+03:00", - ), - last_evidence=Evidence( - evidence_type=EvidenceType.ARP_SCAN, - description="ARP scan detected", - attacker=Attacker( - direction=Direction.SRC, - ioc_type=IoCType.IP, - value="192.168.1.20", - ), - threat_level=ThreatLevel.INFO, - profile=ProfileID("192.168.1.20"), - timewindow=TimeWindow(timewindow), - uid=all_uids, - timestamp="1728417813.8868346", - ), - accumulated_threat_level=accumulated_threat_level, - last_flow_datetime="2024/10/04 15:45:30.123456+0000", - ) - evidence_handler = ModuleFactory().create_evidence_handler_obj() - evidence_handler.jsonfile = mock_file - evidence_handler.idmefv2.convert_to_idmef_alert = Mock( - return_value="alert_in_idmef_format" - ) - evidence_handler.evidence_logger_q.put = Mock() - - evidence_handler.add_alert_to_json_log_file(alert) - evidence_handler.evidence_logger_q.put.assert_called_once_with( - { - "to_log": "alert_in_idmef_format", - "where": "alerts.json", - } - ) + assert handler.should_stop() is False -def test_show_popup(): - evidence_handler = ModuleFactory().create_evidence_handler_obj() - evidence_handler.notify = Mock() - alert = Mock(spec=Alert) - evidence_handler.formatter.get_printable_alert = Mock( - return_value="alert_time_desc" - ) +@patch("slips_files.core.evidence_handler.time.time", return_value=131.0) +def test_should_stop_after_grace_period(_mock_time): + handler = ModuleFactory().create_evidence_handler_obj() + handler.termination_event.is_set.return_value = True + handler.is_msg_received_in_any_channel = Mock(return_value=False) + handler.last_msg_received_time = 100.0 - evidence_handler.show_popup(alert) + assert handler.should_stop() is True - evidence_handler.notify.show_popup.assert_called_once_with( - "alert_time_desc" - ) +def test_pre_main_starts_default_workers(): + handler = ModuleFactory().create_evidence_handler_obj() + handler.start_evidence_worker = Mock() -def test_send_to_exporting_module(): - evidence_handler = ModuleFactory().create_evidence_handler_obj() - tw_evidence = { - "evidence1": Evidence( - evidence_type=EvidenceType.ARP_SCAN, - description="ARP scan detected", - attacker=Attacker( - direction=Direction.SRC, - ioc_type=IoCType.IP, - value="192.168.1.1", - ), - threat_level=ThreatLevel.MEDIUM, - profile=ProfileID(ip="192.168.1.1"), - timewindow=TimeWindow(number=1), - uid=["uid1"], - timestamp="2023/04/01 10:00:00.000000+0000", - ), - "evidence2": Evidence( - evidence_type=EvidenceType.DNS_WITHOUT_CONNECTION, - description="DNS query without connection", - attacker=Attacker( - direction=Direction.SRC, - ioc_type=IoCType.IP, - value="192.168.1.2", - ), - threat_level=ThreatLevel.LOW, - profile=ProfileID(ip="192.168.1.2"), - timewindow=TimeWindow(number=1), - uid=["uid2"], - timestamp="2023/04/01 10:01:00.000000+0000", - ), - } - - evidence_handler.db.publish = Mock() - evidence_handler.send_to_exporting_module(tw_evidence) - assert evidence_handler.db.publish.call_count == 2 - - -@pytest.mark.parametrize( - "sys_argv, running_non_stop, expected_result", - [ - # testcase 1: running non stop with -p enabled - (["-i", "-p"], True, True), - # testcase 2: custom flows but the module is disabled - (["-i", "-im"], False, False), - # testcase 3: -i not in sys.argv and not running non stop - ([], False, False), - ], -) -def test_is_blocking_module_supported( - sys_argv, running_non_stop, expected_result -): - evidence_handler = ModuleFactory().create_evidence_handler_obj() - evidence_handler.is_running_non_stop = running_non_stop - - with patch("sys.argv", sys_argv): - result = evidence_handler.is_blocking_modules_supported() - assert result == expected_result - - -@pytest.mark.parametrize( - "evidence, past_evidence_ids, expected_result", - [ - # testcase1: Evidence not filtered - ( - Evidence( - evidence_type=EvidenceType.ARP_SCAN, - description="", - attacker=Attacker( - direction="SRC", - ioc_type=IoCType.IP, - value="192.168.1.1", - ), - threat_level=ThreatLevel.INFO, - profile=ProfileID("192.168.1.1"), - timewindow=TimeWindow(1), - uid=[], - timestamp=datetime.now().strftime("%Y/%m/%d %H:%M:%S.%f%z"), - id="1", - ), - [], - False, - ), - # testcase2: Evidence filtered (part of past alert) - ( - Evidence( - evidence_type=EvidenceType.ARP_SCAN, - description="", - attacker=Attacker( - direction="SRC", - ioc_type=IoCType.IP, - value="192.168.1.1", - ), - threat_level=ThreatLevel.INFO, - profile=ProfileID("192.168.1.1"), - timewindow=TimeWindow(1), - uid=[], - timestamp=datetime.now().strftime("%Y/%m/%d %H:%M:%S.%f%z"), - id="2", - ), - ["2"], - True, - ), - # testcase3: Evidence filtered (evidence that wasnt done by the given - # profileid) - ( - Evidence( - evidence_type=EvidenceType.ARP_SCAN, - description="", - attacker=Attacker( - direction="DST", - ioc_type=IoCType.IP, - value="192.168.1.1", - ), - threat_level=ThreatLevel.INFO, - profile=ProfileID("192.168.1.1"), - timewindow=TimeWindow(1), - uid=[], - timestamp=datetime.now().strftime("%Y/%m/%d %H:%M:%S.%f%z"), - id="3", - ), - [], - True, - ), - ], -) -def test_is_filtered_evidence(evidence, past_evidence_ids, expected_result): - evidence_handler = ModuleFactory().create_evidence_handler_obj() - result = evidence_handler.is_filtered_evidence(evidence, past_evidence_ids) - assert result == expected_result - - -@pytest.mark.parametrize( - "evidence, expected_result", - [ # Testcase1: Attacker direction is SRC - (Mock(attacker=Mock(direction="SRC")), False), - # Testcase2: Attacker direction is DST - (Mock(attacker=Mock(direction="DST")), True), - ], -) -def test_is_evidence_done_by_others(evidence, expected_result): - evidence_handler = ModuleFactory().create_evidence_handler_obj() - result = evidence_handler.is_evidence_done_by_others(evidence) - assert result == expected_result - - -@pytest.mark.parametrize( - "confidence, threat_level, expected_output", - [ - # Testcase 1: Low threat level, confidence 0.5 - (0.5, ThreatLevel.LOW, 0.1), - # Testcase 2: Medium threat level, full confidence - (1.0, ThreatLevel.MEDIUM, 0.5), - # Testcase 3: High threat level, confidence 0.8 - (0.8, ThreatLevel.HIGH, 0.64), - # Testcase 4: Critical threat level, confidence 0.3 - (0.3, ThreatLevel.CRITICAL, 0.3), - # Testcase 5: Info threat level, zero confidence - (0.0, ThreatLevel.INFO, 0.0), - ], -) -def test_get_threat_level(confidence, threat_level, expected_output): - evidence_handler = ModuleFactory().create_evidence_handler_obj() - evidence = Mock(spec=Evidence) - evidence.confidence = confidence - evidence.threat_level = threat_level - with patch.object(evidence_handler, "print") as mock_print: - result = evidence_handler.get_threat_level(evidence) - - assert pytest.approx(result, abs=1e-6) == expected_output - mock_print.assert_called_once_with( - f"\t\tWeighted Threat Level: {result}", 3, 0 + handler.pre_main() + + assert handler.start_evidence_worker.call_count == ( + DEFAULT_EVIDENCE_HANDLER_WORKERS ) + handler.start_evidence_worker.assert_has_calls([call(0), call(1), call(2)]) -@pytest.mark.parametrize( - "ip, twid, flow_datetime, " "accumulated_threat_level, blocked", - [ - # testcase1: IP blocked by blocking module - ( - "192.168.1.100", - 1, - "2023/10/26 10:10:10", - 0.8, - True, +def test_main_queues_received_messages(): + handler = ModuleFactory().create_evidence_handler_obj() + handler.should_stop = Mock(side_effect=[False, True]) + handler.evidence_worker_queue = Mock() + + def get_msg(channel): + if channel == "evidence_added": + return {"data": "evidence"} + if channel == "new_blame": + return {"data": "blame"} + return None + + handler.get_msg = Mock(side_effect=get_msg) + + handler.main() + + assert handler.evidence_worker_queue.put.call_args_list == [ + call( + { + "channel": "evidence_added", + "message": {"data": "evidence"}, + } ), - # testcase2: IP not blocked by blocking module - ( - "10.0.0.100", - 2, - "2023/10/26 11:11:11", - 1.0, - False, + call( + { + "channel": "new_blame", + "message": {"data": "blame"}, + } ), - ], -) -def test_log_alert( - ip, - twid, - flow_datetime, - accumulated_threat_level, - blocked, -): - evidence_handler = ModuleFactory().create_evidence_handler_obj() - evidence_handler.width = 300 - evidence_handler.add_alert_to_json_log_file = Mock() - evidence_handler.add_to_log_file = Mock() - alert = Alert( - profile=ProfileID(ip), - timewindow=TimeWindow(twid), - last_evidence=Mock(), - accumulated_threat_level=accumulated_threat_level, - last_flow_datetime=flow_datetime, - ) - evidence_handler.log_alert(alert, blocked=blocked) - - evidence_handler.add_alert_to_json_log_file.assert_called_once() - assert flow_datetime in evidence_handler.add_to_log_file.call_args[0][0] - assert str(twid) in evidence_handler.add_to_log_file.call_args[0][0] + ] diff --git a/tests/unit/slips_files/core/test_evidence_handler_worker.py b/tests/unit/slips_files/core/test_evidence_handler_worker.py new file mode 100644 index 0000000000..4ad9a1fe4d --- /dev/null +++ b/tests/unit/slips_files/core/test_evidence_handler_worker.py @@ -0,0 +1,416 @@ +# SPDX-FileCopyrightText: 2021 Sebastian Garcia +# SPDX-License-Identifier: GPL-2.0-only +from datetime import datetime +from unittest.mock import MagicMock, Mock, patch + +import pytest + +from slips_files.core.structures.alerts import Alert +from slips_files.core.structures.evidence import ( + Attacker, + Direction, + Evidence, + EvidenceType, + IoCType, + ProfileID, + ThreatLevel, + TimeWindow, +) +from tests.module_factory import ModuleFactory + + +@pytest.mark.parametrize( + "profileid, our_ips, expected_result, expected_publish_call_count", + [ + ("192.168.1.100", ["10.0.0.1", "172.16.0.1"], True, 1), + ("10.0.0.1", ["10.0.0.1", "172.16.0.1"], False, 0), + ("8.8.8.8", [], True, 1), + ], +) +def test_decide_blocking( + mocker, profileid, our_ips, expected_result, expected_publish_call_count +): + worker = ModuleFactory().create_evidence_handler_worker_obj() + worker.blocking_modules_supported = True + worker.our_ips = our_ips + with patch.object(worker.db, "publish") as mock_publish: + tw = TimeWindow( + 2, "2025-05-09T13:27:45.123456", "2025-05-09T13:27:45.123456" + ) + mocker.patch( + "slips_files.common.slips_utils.Utils.get_interface_of_ip", + return_value="eth0", + ) + + result = worker.decide_blocking(profileid, tw) + + assert result == expected_result + assert mock_publish.call_count == expected_publish_call_count + + +@pytest.mark.parametrize( + "profileid, twid, past_alerts, expected_output", + [ + ("profile1_192.168.1.1", "timewindow1", {}, []), + ( + "profile2_10.0.0.1", + "timewindow2", + {"alert1": '["evidence1", "evidence2"]'}, + ["evidence1", "evidence2"], + ), + ], +) +def test_get_evidence_that_were_part_of_a_past_alert( + profileid, twid, past_alerts, expected_output +): + worker = ModuleFactory().create_evidence_handler_worker_obj() + worker.db.get_profileid_twid_alerts.return_value = past_alerts + + result = worker.get_evidence_that_were_part_of_a_past_alert( + profileid, twid + ) + + assert result == expected_output + + +def setup_worker(popup_enabled, blocked, mark_blocked=None): + worker = ModuleFactory().create_evidence_handler_worker_obj() + worker.popup_alerts = popup_enabled + + alert = Alert( + profile=ProfileID("1.2.3.4"), + timewindow=TimeWindow(1), + last_evidence=Mock(), + accumulated_threat_level=12.2, + last_flow_datetime="2024/10/04 15:45:30.123456+0000", + ) + evidence = {"k": MagicMock(spec=Evidence)} + + worker.db.set_alert = MagicMock() + worker.decide_blocking = MagicMock(side_effect=[False, mark_blocked]) + worker.db.is_blocked_profile_and_tw = MagicMock(return_value=blocked) + worker.send_to_exporting_module = MagicMock() + worker.formatter.format_evidence_for_printing = MagicMock( + return_value="formatted_alert" + ) + worker.print = MagicMock() + worker.show_popup = MagicMock() + worker.db.mark_profile_and_timewindow_as_blocked = MagicMock() + worker.log_alert = MagicMock() + + return worker, alert, evidence + + +@pytest.mark.parametrize("popup_enabled", [True, False]) +def test_handle_new_alert_already_blocked(popup_enabled): + worker, alert, evidence = setup_worker(popup_enabled, blocked=True) + + worker.handle_new_alert(alert, evidence) + + worker.db.set_alert.assert_called_once_with(alert, evidence) + worker.db.is_blocked_profile_and_tw.assert_called_once() + worker.send_to_exporting_module.assert_not_called() + worker.print.assert_not_called() + worker.show_popup.assert_not_called() + worker.db.mark_profile_and_timewindow_as_blocked.assert_not_called() + worker.log_alert.assert_not_called() + + +@pytest.mark.parametrize( + "popup_enabled, expect_popup", + [ + (True, True), + (False, False), + ], +) +def test_handle_new_alert_not_blocked(popup_enabled, expect_popup): + worker, alert, evidence = setup_worker( + popup_enabled, blocked=False, mark_blocked=True + ) + + worker.handle_new_alert(alert, evidence) + + worker.send_to_exporting_module.assert_called_once_with(evidence) + worker.print.assert_called_once_with("formatted_alert", 1, 0) + if expect_popup: + worker.show_popup.assert_called_once_with(alert) + else: + worker.show_popup.assert_not_called() + worker.db.mark_profile_and_timewindow_as_blocked.assert_not_called() + worker.log_alert.assert_called_once_with(alert, blocked=False) + + +@pytest.mark.parametrize("data", ["Test log entry", "Another log entry"]) +def test_add_to_log_file(data): + worker = ModuleFactory().create_evidence_handler_worker_obj() + worker.evidence_logger_q.put = Mock() + + worker.add_to_log_file(data) + + worker.evidence_logger_q.put.assert_called_once_with( + {"to_log": data, "where": "alerts.log"} + ) + + +@pytest.mark.parametrize( + "all_uids, timewindow, accumulated_threat_level", + [ + (["uid1", "uid2"], 1, 0.5), + ([], 10, 1.0), + ], +) +def test_add_alert_to_json_log_file( + all_uids, timewindow, accumulated_threat_level +): + alert = Alert( + profile=ProfileID("192.168.1.20"), + timewindow=TimeWindow( + timewindow, + start_time="2024-10-04T18:46:50+03:00", + end_time="2024-10-04T19:46:50+03:00", + ), + last_evidence=Evidence( + evidence_type=EvidenceType.ARP_SCAN, + description="ARP scan detected", + attacker=Attacker( + direction=Direction.SRC, + ioc_type=IoCType.IP, + value="192.168.1.20", + ), + threat_level=ThreatLevel.INFO, + profile=ProfileID("192.168.1.20"), + timewindow=TimeWindow(timewindow), + uid=all_uids, + timestamp="1728417813.8868346", + ), + accumulated_threat_level=accumulated_threat_level, + last_flow_datetime="2024/10/04 15:45:30.123456+0000", + ) + worker = ModuleFactory().create_evidence_handler_worker_obj() + worker.idmefv2.convert_to_idmef_alert = Mock( + return_value="alert_in_idmef_format" + ) + worker.evidence_logger_q.put = Mock() + + worker.add_alert_to_json_log_file(alert) + + worker.evidence_logger_q.put.assert_called_once_with( + { + "to_log": "alert_in_idmef_format", + "where": "alerts.json", + } + ) + + +def test_show_popup(): + worker = ModuleFactory().create_evidence_handler_worker_obj() + worker.notify = Mock() + alert = Mock(spec=Alert) + worker.formatter.get_printable_alert = Mock(return_value="alert_time_desc") + + worker.show_popup(alert) + + worker.notify.show_popup.assert_called_once_with("alert_time_desc") + + +def test_send_to_exporting_module(): + worker = ModuleFactory().create_evidence_handler_worker_obj() + tw_evidence = { + "evidence1": Evidence( + evidence_type=EvidenceType.ARP_SCAN, + description="ARP scan detected", + attacker=Attacker( + direction=Direction.SRC, + ioc_type=IoCType.IP, + value="192.168.1.1", + ), + threat_level=ThreatLevel.MEDIUM, + profile=ProfileID(ip="192.168.1.1"), + timewindow=TimeWindow(number=1), + uid=["uid1"], + timestamp="2023/04/01 10:00:00.000000+0000", + ), + "evidence2": Evidence( + evidence_type=EvidenceType.DNS_WITHOUT_CONNECTION, + description="DNS query without connection", + attacker=Attacker( + direction=Direction.SRC, + ioc_type=IoCType.IP, + value="192.168.1.2", + ), + threat_level=ThreatLevel.LOW, + profile=ProfileID(ip="192.168.1.2"), + timewindow=TimeWindow(number=1), + uid=["uid2"], + timestamp="2023/04/01 10:01:00.000000+0000", + ), + } + + worker.exporting_modules_enabled = True + worker.db.publish = Mock() + + worker.send_to_exporting_module(tw_evidence) + + assert worker.db.publish.call_count == 2 + + +@pytest.mark.parametrize( + "sys_argv, running_non_stop, expected_result", + [ + (["-i", "-p"], True, True), + (["-i", "-im"], False, False), + ([], False, False), + ], +) +def test_is_blocking_module_supported( + sys_argv, running_non_stop, expected_result +): + worker = ModuleFactory().create_evidence_handler_worker_obj() + worker.is_running_non_stop = running_non_stop + + with patch("sys.argv", sys_argv): + result = worker.is_blocking_modules_supported() + + assert result == expected_result + + +@pytest.mark.parametrize( + "evidence, past_evidence_ids, expected_result", + [ + ( + Evidence( + evidence_type=EvidenceType.ARP_SCAN, + description="", + attacker=Attacker( + direction="SRC", + ioc_type=IoCType.IP, + value="192.168.1.1", + ), + threat_level=ThreatLevel.INFO, + profile=ProfileID("192.168.1.1"), + timewindow=TimeWindow(1), + uid=[], + timestamp=datetime.now().strftime("%Y/%m/%d %H:%M:%S.%f%z"), + id="1", + ), + [], + False, + ), + ( + Evidence( + evidence_type=EvidenceType.ARP_SCAN, + description="", + attacker=Attacker( + direction="SRC", + ioc_type=IoCType.IP, + value="192.168.1.1", + ), + threat_level=ThreatLevel.INFO, + profile=ProfileID("192.168.1.1"), + timewindow=TimeWindow(1), + uid=[], + timestamp=datetime.now().strftime("%Y/%m/%d %H:%M:%S.%f%z"), + id="2", + ), + ["2"], + True, + ), + ( + Evidence( + evidence_type=EvidenceType.ARP_SCAN, + description="", + attacker=Attacker( + direction="DST", + ioc_type=IoCType.IP, + value="192.168.1.1", + ), + threat_level=ThreatLevel.INFO, + profile=ProfileID("192.168.1.1"), + timewindow=TimeWindow(1), + uid=[], + timestamp=datetime.now().strftime("%Y/%m/%d %H:%M:%S.%f%z"), + id="3", + ), + [], + True, + ), + ], +) +def test_is_filtered_evidence(evidence, past_evidence_ids, expected_result): + worker = ModuleFactory().create_evidence_handler_worker_obj() + + result = worker.is_filtered_evidence(evidence, past_evidence_ids) + + assert result == expected_result + + +@pytest.mark.parametrize( + "evidence, expected_result", + [ + (Mock(attacker=Mock(direction="SRC")), False), + (Mock(attacker=Mock(direction="DST")), True), + ], +) +def test_is_evidence_done_by_others(evidence, expected_result): + worker = ModuleFactory().create_evidence_handler_worker_obj() + + result = worker.is_evidence_done_by_others(evidence) + + assert result == expected_result + + +@pytest.mark.parametrize( + "confidence, threat_level, expected_output", + [ + (0.5, ThreatLevel.LOW, 0.1), + (1.0, ThreatLevel.MEDIUM, 0.5), + (0.8, ThreatLevel.HIGH, 0.64), + (0.3, ThreatLevel.CRITICAL, 0.3), + (0.0, ThreatLevel.INFO, 0.0), + ], +) +def test_get_threat_level(confidence, threat_level, expected_output): + worker = ModuleFactory().create_evidence_handler_worker_obj() + evidence = Mock(spec=Evidence) + evidence.confidence = confidence + evidence.threat_level = threat_level + + with patch.object(worker, "print") as mock_print: + result = worker.get_threat_level(evidence) + + assert pytest.approx(result, abs=1e-6) == expected_output + mock_print.assert_called_once_with( + f"\t\tWeighted Threat Level: {result}", 3, 0 + ) + + +@pytest.mark.parametrize( + "ip, twid, flow_datetime, accumulated_threat_level, blocked", + [ + ("192.168.1.100", 1, "2023/10/26 10:10:10", 0.8, True), + ("10.0.0.100", 2, "2023/10/26 11:11:11", 1.0, False), + ], +) +def test_log_alert( + ip, + twid, + flow_datetime, + accumulated_threat_level, + blocked, +): + worker = ModuleFactory().create_evidence_handler_worker_obj() + worker.add_alert_to_json_log_file = Mock() + worker.add_to_log_file = Mock() + alert = Alert( + profile=ProfileID(ip), + timewindow=TimeWindow(twid), + last_evidence=Mock(), + accumulated_threat_level=accumulated_threat_level, + last_flow_datetime=flow_datetime, + ) + + worker.log_alert(alert, blocked=blocked) + + worker.add_alert_to_json_log_file.assert_called_once() + assert flow_datetime in worker.add_to_log_file.call_args[0][0] + assert str(twid) in worker.add_to_log_file.call_args[0][0] diff --git a/tests/unit/slips_files/core/test_evidence_logger.py b/tests/unit/slips_files/core/test_evidence_logger.py index ef45bcb82d..32e9244ff4 100644 --- a/tests/unit/slips_files/core/test_evidence_logger.py +++ b/tests/unit/slips_files/core/test_evidence_logger.py @@ -2,7 +2,7 @@ # SPDX-License-Identifier: GPL-2.0-only import pytest import os -from unittest.mock import MagicMock, patch, Mock +from unittest.mock import MagicMock, patch, Mock, call import queue import threading @@ -12,26 +12,48 @@ @pytest.mark.parametrize( "output_dir, file_to_clean, file_exists", [ - # testcase1: File doesn't exist ("/tmp", "nonexistent.log", False), - # testcase2: File exists ("/tmp", "existing.log", True), + ("/tmp", "/var/log/app.log", True), ], ) def test_clean_file(output_dir, file_to_clean, file_exists): logger = ModuleFactory().create_evidence_loggr_obj() + with patch("os.path.exists") as mock_exists, patch( - "builtins.open" - ) as mock_open: + "os.makedirs" + ) as mock_makedirs, patch("builtins.open") as mock_open: + mock_exists.return_value = file_exists + mock_file = Mock() - mock_open.return_value = mock_file + truncate_handle = Mock() + mock_open.side_effect = ( + [truncate_handle, mock_file] if file_exists else [mock_file] + ) result = logger.clean_file(output_dir, file_to_clean) - expected_path = os.path.join(output_dir, file_to_clean) + expected_path = ( + file_to_clean + if os.path.isabs(file_to_clean) + else os.path.join(output_dir, file_to_clean) + ) + expected_dir = os.path.dirname(expected_path) + mock_exists.assert_called_once_with(expected_path) - mock_open.assert_called_with(expected_path, "a") + mock_makedirs.assert_called_once_with(expected_dir, exist_ok=True) + + if file_exists: + assert mock_open.call_args_list == [ + call(expected_path, "w"), + call(expected_path, "a"), + ] + truncate_handle.close.assert_called_once_with() + else: + assert mock_open.call_args_list == [ + call(expected_path, "a"), + ] assert result == mock_file diff --git a/tests/unit/slips_files/core/test_profiler.py b/tests/unit/slips_files/core/test_profiler.py index 8fee317189..56af98abe1 100644 --- a/tests/unit/slips_files/core/test_profiler.py +++ b/tests/unit/slips_files/core/test_profiler.py @@ -26,22 +26,20 @@ def test_mark_process_as_done_processing(monkeypatch): @pytest.mark.parametrize( - "msg_from_queue, handler_obj, should_stop_side_effect, expected_start_workers, expect_print_called", + "msg_from_queue, handler_obj, expected_start_workers", [ - # Case 1: triggers all branches - ({"line": {"f1": "v1"}}, Mock(), [False, True], 5, False), + # Case 1: valid input starts the default profiler workers + ({"line": {"f1": "v1"}}, Mock(), 3), # Case 2: unsupported input type, no input_handler_obj - ({"line": {"f1": "v1"}}, None, [True], 0, True), + ({"line": {"f1": "v1"}}, None, 0), # Case 3: empty queue initially, then valid msg - ({"line": {"f1": "v1"}}, Mock(), [False, True], 5, False), + (None, Mock(), 3), ], ) def test_main( msg_from_queue, handler_obj, - should_stop_side_effect, expected_start_workers, - expect_print_called, ): profiler = ModuleFactory().create_profiler_obj() profiler.last_worker_id = 0 @@ -52,9 +50,7 @@ def test_main( profiler.store_flows_read_per_second = Mock() profiler._update_lines_read_by_all_workers = Mock() profiler.print = Mock() - - # Mock should_stop - profiler.should_stop = Mock(side_effect=should_stop_side_effect) + profiler.profiler_monitor_thread = Mock() # Handle empty queue case if msg_from_queue is None: @@ -69,18 +65,23 @@ def test_main( profiler.profiler_queue = Mock() profiler.workers = [] - with patch("time.sleep"): + with ( + patch("time.sleep"), + patch("slips_files.core.profiler.utils.start_thread") as start_thread, + ): profiler.main() if handler_obj: - handler_obj.process_line.assert_called_once_with( - msg_from_queue["line"] + handler_obj.process_line.assert_called_once_with({"f1": "v1"}) + start_thread.assert_called_once_with( + profiler.profiler_monitor_thread, profiler.db ) assert ( profiler.start_profiler_worker.call_count == expected_start_workers ) else: profiler.print.assert_called_once() + start_thread.assert_not_called() assert profiler.start_profiler_worker.call_count == 0 @@ -91,10 +92,21 @@ def test_shutdown_gracefully(monkeypatch): Mock(received_lines=20), Mock(received_lines=3), ] + profiler.stop_profiler_workers = Mock() + profiler.aid_queue = Mock() + profiler.aid_manager = Mock() + profiler.profiler_queue = Mock() + profiler.profiler_monitor_thread = Mock() profiler.mark_self_as_done_processing = Mock() - - # monkeypatch.setattr(profiler, "print", Mock()) profiler.shutdown_gracefully() + + profiler.stop_profiler_workers.assert_called_once() + profiler.aid_queue.put.assert_called_once_with("stop") + profiler.aid_manager.shutdown.assert_called_once() + profiler.profiler_queue.cancel_join_thread.assert_called_once() + profiler.profiler_queue.close.assert_called_once() + profiler.aid_queue.cancel_join_thread.assert_called_once() + profiler.aid_queue.close.assert_called_once() profiler.print.assert_called_with("Stopping.", log_to_logfiles_only=True) profiler.mark_self_as_done_processing.assert_called_once() diff --git a/tests/unit/slips_files/core/test_profiler_worker.py b/tests/unit/slips_files/core/test_profiler_worker.py index 13ec0f6fb6..8477719223 100644 --- a/tests/unit/slips_files/core/test_profiler_worker.py +++ b/tests/unit/slips_files/core/test_profiler_worker.py @@ -1,29 +1,51 @@ # SPDX-FileCopyrightText: 2021 Sebastian Garcia # SPDX-License-Identifier: GPL-2.0-only -"""Unit test for slips_files/core/iperformance_profiler.py""" -import queue -from unittest.mock import Mock, MagicMock +"""Unit tests for slips_files/core/profiler_worker.py.""" -from tests.module_factory import ModuleFactory -from tests.unit.common_test_utils import do_nothing -import pytest +import csv import json -from slips_files.core.profiler import SUPPORTED_INPUT_TYPES, SEPARATORS -from slips_files.core.flows.zeek import Conn -import ipaddress -from unittest.mock import patch +from unittest.mock import Mock, patch + +import pytest + from slips_files.common.input_type import InputType +from slips_files.core.flows.zeek import Conn +from slips_files.core.profiler import SEPARATORS, SUPPORTED_INPUT_TYPES +from tests.module_factory import ModuleFactory +from tests.unit.common_test_utils import do_nothing -# get zeek flow def get_zeek_flow(file, flow_type): - # returns the first flow in the given file - with open(file) as f: + with open(file, encoding="utf-8") as f: sample_flow = f.readline().replace("\n", "") sample_flow = json.loads(sample_flow) - sample_flow = {"data": sample_flow, "type": flow_type, "interface": "eth0"} - return sample_flow + return {"data": sample_flow, "type": flow_type, "interface": "eth0"} + + +def make_conn(**overrides): + data = { + "starttime": "1.0", + "uid": "1234", + "saddr": "192.168.1.1", + "daddr": "8.8.8.8", + "dur": 5, + "proto": "TCP", + "appproto": "dhcp", + "sport": 80, + "dport": 88, + "spkts": 20, + "dpkts": 20, + "sbytes": 20, + "dbytes": 20, + "smac": "", + "dmac": "", + "state": "Established", + "history": "", + "interface": "eth0", + } + data.update(overrides) + return Conn(**data) @pytest.mark.parametrize( @@ -37,14 +59,10 @@ def get_zeek_flow(file, flow_type): ("dataset/test9-mixed-zeek-dir/files.log", "files.log"), ], ) -def test_process_line_zeek_json( - file, - flow_type, -): +def test_process_line_zeek_json(file, flow_type): profiler = ModuleFactory().create_profiler_worker_obj() profiler.symbol = Mock() profiler.db.get_timewindow = Mock(return_value="timewindow1") - # we're testing another functionality here profiler.whitelist.is_whitelisted_flow = do_nothing profiler.input_type = InputType.ZEEK profiler.input_handler = SUPPORTED_INPUT_TYPES[profiler.input_type]( @@ -52,350 +70,321 @@ def test_process_line_zeek_json( ) profiler.separator = SEPARATORS[profiler.input_type] - sample_flow = get_zeek_flow(file, flow_type) - # required to get a flow object to call add_flow_to_profile on - flow, err = profiler.input_handler.process_line(sample_flow) + flow, err = profiler.input_handler.process_line( + get_zeek_flow(file, flow_type) + ) assert not err assert flow -def test_get_rev_profile(): +def test_read_configuration(): profiler = ModuleFactory().create_profiler_worker_obj() - flow: Conn = Conn( - starttime="1.0", - uid="1234", - saddr="192.168.1.1", - daddr="8.8.8.8", - dur=5, - proto="TCP", - appproto="dhcp", - sport=80, - dport=88, - spkts=20, - dpkts=20, - sbytes=20, - dbytes=20, - smac="", - dmac="", - state="Established", - history="", - ) + profiler.conf.client_ips.return_value = ["192.168.1.1", "10.0.0.1"] + profiler.conf.local_whitelist_path.return_value = "path/to/whitelist" + profiler.conf.ts_format.return_value = "unixtimestamp" + profiler.conf.analysis_direction.return_value = "all" + profiler.conf.label.return_value = "malicious" + profiler.conf.get_tw_width_in_seconds.return_value = 1.0 + profiler.conf.generate_performance_plots.return_value = True - profiler.db.get_timewindow.return_value = "timewindow1" - assert profiler.get_rev_profile(flow) == ("profile_8.8.8.8", "timewindow1") - - -def test_get_rev_profile_no_daddr( - flow, -): - profiler = ModuleFactory().create_profiler_worker_obj() - flow.daddr = None - assert profiler.get_rev_profile(flow) == (False, False) + profiler.read_configuration() + assert profiler.client_ips == ["192.168.1.1", "10.0.0.1"] + assert profiler.local_whitelist_path == "path/to/whitelist" + assert profiler.timeformat == "unixtimestamp" + assert profiler.analysis_direction == "all" + assert profiler.label == "malicious" + assert profiler.width == 1.0 + assert profiler.generate_performance_plots is True -def test_get_rev_profile_existing_profileid(): - profiler = ModuleFactory().create_profiler_worker_obj() - flow: Conn = Conn( - starttime="1.0", - uid="1234", - saddr="192.168.1.1", - daddr="8.8.8.8", - dur=5, - proto="TCP", - appproto="dhcp", - sport=80, - dport=88, - spkts=20, - dpkts=20, - sbytes=20, - dbytes=20, - smac="", - dmac="", - state="Established", - history="", - ) - profiler.db.get_timewindow.return_value = "existing_timewindow" - assert profiler.get_rev_profile(flow) == ( - "profile_8.8.8.8", - "existing_timewindow", - ) +def test_get_slips_start_time_uses_db_value(): + profiler = ModuleFactory().create_profiler_worker_obj() + profiler.db.get_slips_start_time.return_value = "123.5" + assert profiler._get_slips_start_time() == 123.5 -def test_get_rev_profile_no_timewindow(): - profiler = ModuleFactory().create_profiler_worker_obj() - flow: Conn = Conn( - starttime="1.0", - uid="1234", - saddr="192.168.1.1", - daddr="8.8.8.8", - dur=5, - proto="TCP", - appproto="dhcp", - sport=80, - dport=88, - spkts=20, - dpkts=20, - sbytes=20, - dbytes=20, - smac="", - dmac="", - state="Established", - history="", - ) - profiler.db.get_timewindow.return_value = None +@patch("slips_files.core.profiler_worker.time.time", return_value=99.0) +def test_get_slips_start_time_falls_back_to_now(mock_time): + profiler = ModuleFactory().create_profiler_worker_obj() + profiler.db.get_slips_start_time.return_value = "invalid" + mock_time.reset_mock() - profile_id, tw_id = profiler.get_rev_profile(flow) - assert profile_id == "profile_8.8.8.8" - assert tw_id is None + assert profiler._get_slips_start_time() == 99.0 + mock_time.assert_called_once() @pytest.mark.parametrize( - "client_ips, expected_private_ips", + "name, expected_prefix", [ - (["192.168.1.1", "10.0.0.1"], ["192.168.1.1", "10.0.0.1"]), - (["8.8.8.8", "1.1.1.1"], []), - (["192.168.1.1", "8.8.8.8"], ["192.168.1.1"]), + ("ProfilerWorker_Process_2", "profiler_worker_2"), + ("ProfilerWorker", "profilerworker"), + ("mock_name", "mock_name"), ], ) -def test_get_private_client_ips(client_ips, expected_private_ips, monkeypatch): +def test_get_latency_filename_prefix(name, expected_prefix): profiler = ModuleFactory().create_profiler_worker_obj() - profiler.client_ips = client_ips - with patch( - "slips_files.core.profiler_worker.utils.is_private_ip" - ) as mock_is_private_ip: + profiler.name = name + + assert profiler._get_latency_filename_prefix() == expected_prefix + + +def test_initialize_latency_logfile_creates_header(tmp_path): + profiler = ModuleFactory().create_profiler_worker_obj() + profiler.latency_logfile = str(tmp_path / "latency" / "worker.csv") - def is_private_ip(ip): - ip_obj = ipaddress.ip_address(ip) - return ipaddress.ip_address(ip_obj).is_private + profiler._initialize_latency_logfile() - mock_is_private_ip.side_effect = is_private_ip + with open(profiler.latency_logfile, encoding="utf-8") as f: + rows = list(csv.reader(f)) - private_ips = profiler.get_private_client_ips() - assert set(private_ips) == set(expected_private_ips) + assert rows == [["timestamp_now", "flow_uid", "latency_in_seconds"]] -def test_convert_starttime_to_epoch(): +def test_initialize_latency_logfile_is_noop_when_file_exists(tmp_path): profiler = ModuleFactory().create_profiler_worker_obj() - starttime = "2023-04-04 12:00:00" + logfile = tmp_path / "worker.csv" + logfile.write_text("existing\n", encoding="utf-8") + profiler.latency_logfile = str(logfile) - with patch( - "slips_files.core.profiler_worker.utils.convert_ts_format" - ) as mock_convert_ts_format: - mock_convert_ts_format.return_value = 1680604800 + profiler._initialize_latency_logfile() - converted = profiler.convert_starttime_to_unix_ts(starttime) + assert logfile.read_text(encoding="utf-8") == "existing\n" - mock_convert_ts_format.assert_called_once_with( - "2023-04-04 12:00:00", "unixtimestamp" - ) - assert converted == 1680604800 +@patch("slips_files.core.profiler_worker.time.time", side_effect=[0.0, 120.0]) +def test_log_flow_latency_appends_row(mock_time, tmp_path): + profiler = ModuleFactory().create_profiler_worker_obj() + profiler.generate_performance_plots = True + profiler.slips_start_time = 100.0 + profiler.latency_logfile = str(tmp_path / "latency.csv") + profiler._initialize_latency_logfile() + flow = Mock(uid="flow-1") -@pytest.mark.parametrize( - "saddr, localnet_cache, running_non_stop, expected_result", - [ - ("192.168.1.1", {}, True, True), - ("192.168.1.1", {"eth0": "some_ip"}, True, False), - ("8.8.8.8", {"default": "ip"}, False, False), - ], + profiler._log_flow_latency(flow, "110") + + with open(profiler.latency_logfile, encoding="utf-8") as f: + rows = list(csv.reader(f)) + + assert rows[1] == ["20.0", "flow-1", "10"] + + +def test_log_flow_latency_skips_invalid_starttime(tmp_path): + profiler = ModuleFactory().create_profiler_worker_obj() + profiler.generate_performance_plots = True + profiler.latency_logfile = str(tmp_path / "latency.csv") + profiler._initialize_latency_logfile() + + profiler._log_flow_latency(Mock(uid="flow-1"), "invalid") + + with open(profiler.latency_logfile, encoding="utf-8") as f: + rows = list(csv.reader(f)) + + assert len(rows) == 1 + + +@patch( + "slips_files.core.profiler_worker.time.time", side_effect=[0.0, 2.0, 4.5] ) -def test_should_set_localnet( - saddr, localnet_cache, running_non_stop, expected_result -): +def test_update_modified_tws_batches_then_flushes(mock_time): profiler = ModuleFactory().create_profiler_worker_obj() - profiler.client_ips = [] - profiler.db.is_running_non_stop = Mock(return_value=running_non_stop) + profiler._modified_tws = {} + profiler._time_to_update_modified_tws = 3.0 + profiler._modified_timewindows_update_period = 3 + flow1 = Mock(starttime="1") + flow2 = Mock(starttime="2") - flow = Mock() - flow.saddr = saddr - flow.interface = "eth0" + profiler._update_modified_tws_in_the_db("profile1", "tw1", flow1) + profiler._update_modified_tws_in_the_db("profile2", "tw2", flow2) - profiler.localnet_cache = localnet_cache - assert profiler.should_set_localnet(flow) == expected_result + profiler.db.mark_profile_tw_as_modified.assert_called_once_with( + {"profile1_tw1": "1", "profile2_tw2": "2"} + ) + assert profiler._modified_tws == {} + assert profiler._time_to_update_modified_tws == 7.5 -@patch("slips_files.core.profiler.ConfigParser") -def test_read_configuration( - mock_config_parser, -): +def test_get_rev_profile(): profiler = ModuleFactory().create_profiler_worker_obj() - mock_conf = mock_config_parser.return_value + flow = make_conn() + profiler.db.get_timewindow.return_value = "timewindow1" - mock_conf.local_whitelist_path.return_value = "path/to/whitelist" - mock_conf.ts_format.return_value = "unixtimestamp" - mock_conf.analysis_direction.return_value = "all" - mock_conf.label.return_value = "malicious" - mock_conf.get_tw_width_in_seconds.return_value = 1.0 - mock_conf.client_ips.return_value = ["192.168.1.1", "10.0.0.1"] - profiler.conf = mock_conf - profiler.read_configuration() + assert profiler.get_rev_profile(flow) == ("profile_8.8.8.8", "timewindow1") + profiler.db.add_profile.assert_called_once_with("profile_8.8.8.8", "1.0") - assert profiler.local_whitelist_path == "path/to/whitelist" - assert profiler.timeformat == "unixtimestamp" - assert profiler.analysis_direction == "all" - assert profiler.label == "malicious" - assert profiler.width == 1.0 - assert profiler.client_ips == ["192.168.1.1", "10.0.0.1"] + +def test_get_rev_profile_no_daddr(): + profiler = ModuleFactory().create_profiler_worker_obj() + flow = make_conn(daddr=None) + + assert profiler.get_rev_profile(flow) == (False, False) -def test_add_flow_to_profile_unsupported_flow(): +def test_convert_starttime_to_unix_ts_returns_input_for_unix_timestamp(): profiler = ModuleFactory().create_profiler_worker_obj() + + assert ( + profiler.convert_starttime_to_unix_ts("1712500000.0") == "1712500000.0" + ) + + +def test_convert_starttime_to_unix_ts_converts_formatted_timestamp(): + profiler = ModuleFactory().create_profiler_worker_obj() + + with patch( + "slips_files.core.profiler_worker.utils.convert_ts_format", + return_value=1680604800, + ) as mock_convert: + assert ( + profiler.convert_starttime_to_unix_ts("2023-04-04 12:00:00") + == 1680604800 + ) + + mock_convert.assert_called_once_with( + "2023-04-04 12:00:00", "unixtimestamp" + ) + + +def test_convert_starttime_to_unix_ts_returns_original_on_error(): + profiler = ModuleFactory().create_profiler_worker_obj() + + with patch( + "slips_files.core.profiler_worker.utils.convert_ts_format", + side_effect=ValueError, + ): + assert ( + profiler.convert_starttime_to_unix_ts("invalid-ts") == "invalid-ts" + ) + + profiler.print.assert_called_once() + + +def test_get_aid_and_store_flow_in_the_db_submits_only_for_conn_handler(): + profiler = ModuleFactory().create_profiler_worker_obj() + handle_conn = Mock() + other_handler = Mock() flow = Mock() - flow.type_ = "unsupported" - flow_parser = Mock() - flow_parser.is_supported_flow.return_value = False - result = profiler.add_flow_to_profile(flow) - assert result is False + profiler.get_aid_and_store_flow_in_the_db( + handle_conn, handle_conn, flow, "profile", "tw1" + ) + profiler.get_aid_and_store_flow_in_the_db( + other_handler, handle_conn, flow, "profile", "tw1" + ) + + profiler.aid_manager.submit_aid_task.assert_called_once_with( + flow, "profile", "tw1", "benign" + ) @patch("slips_files.core.profiler_worker.FlowHandler") -def test_store_features_going_out(mock_flowhandler): +def test_store_features_going_out_conn_flow(mock_flow_handler): profiler = ModuleFactory().create_profiler_worker_obj() profiler.get_aid_and_store_flow_in_the_db = Mock() + profiler._update_modified_tws_in_the_db = Mock() + flow = make_conn(type_="conn") - flow = Mock(type_="conn") + assert ( + profiler.store_features_going_out(flow, "profile_test", "tw1") is True + ) - profileid = "profile_test" - twid = "timewindow1" - is_stored = profiler.store_features_going_out(flow, profileid, twid) - assert is_stored - mock_flowhandler.return_value.handle_conn.assert_called_once() + mock_flow_handler.return_value.handle_conn.assert_called_once() profiler.get_aid_and_store_flow_in_the_db.assert_called_once() - profiler.db.mark_profile_tw_as_modified.assert_called_once() + profiler._update_modified_tws_in_the_db.assert_called_once_with( + "profile_test", "tw1", flow + ) -def test_store_features_going_in_non_conn_flow(): +@patch("slips_files.core.profiler_worker.FlowHandler") +def test_store_features_going_out_matches_substring_type(mock_flow_handler): profiler = ModuleFactory().create_profiler_worker_obj() - flow = Mock(type_="dns", saddr="192.168.1.1", dport=53, proto="UDP") - profileid = "profile_test_dns" - twid = "tw_test_dns" - profiler.store_features_going_in(profileid, twid, flow) - profiler.db.add_tuple.assert_not_called() - profiler.db.add_ips.assert_not_called() - profiler.db.add_port.assert_not_called() - profiler.db.add_flow.assert_not_called() - profiler.db.mark_profile_tw_as_modified.assert_not_called() + profiler.get_aid_and_store_flow_in_the_db = Mock() + profiler._update_modified_tws_in_the_db = Mock() + flow = make_conn(type_="conn.log") + + assert ( + profiler.store_features_going_out(flow, "profile_test", "tw1") is True + ) + + mock_flow_handler.return_value.handle_conn.assert_called_once() @patch("slips_files.core.profiler_worker.FlowHandler") def test_store_features_going_out_unsupported_type(mock_flow_handler): profiler = ModuleFactory().create_profiler_worker_obj() - flow = Mock(type_="unsupported_type") - profileid = "profile_test" - twid = "twid_test" - result = profiler.store_features_going_out(flow, profileid, twid) + assert ( + profiler.store_features_going_out( + Mock(type_="unsupported", starttime="1"), "profile_test", "tw1" + ) + is False + ) + mock_flow_handler.return_value.handle_conn.assert_not_called() - assert result is False -def test_handle_in_flows_valid_daddr(): +def test_store_features_going_in_stores_conn_flow(): profiler = ModuleFactory().create_profiler_worker_obj() - flow = Mock(type_="conn", daddr="8.8.8.8") - profiler.get_rev_profile = Mock(return_value=("rev_profile", "rev_twid")) - profiler.store_features_going_in = Mock() + profiler.symbol.compute = Mock() + profiler.symbol.compute.return_value = "symbol" + profiler._update_modified_tws_in_the_db = Mock() + flow = make_conn(type_="conn") - profiler.handle_in_flow(flow) + profiler.store_features_going_in("profile_test", "tw1", flow) - profiler.get_rev_profile.assert_called_once() - profiler.store_features_going_in.assert_called_once_with( - "rev_profile", "rev_twid", flow + profiler.db.add_tuple.assert_called_once() + profiler.db.add_ips.assert_called_once() + profiler.aid_manager.submit_aid_task.assert_called_once_with( + flow, "profile_test", "tw1", profiler.label + ) + profiler._update_modified_tws_in_the_db.assert_called_once_with( + "profile_test", "tw1", flow ) -@pytest.mark.parametrize( - "client_ips, saddr, expected_cidr", - [ - ( - [ipaddress.IPv4Network("192.168.1.0/24")], - "10.0.0.1", - "192.168.1.0/24", - ), - ( - [ipaddress.IPv4Network("172.16.0.0/16")], - "10.0.0.1", - "172.16.0.0/16", - ), - ([], "10.0.0.1", "10.0.0.0/8"), - ], -) -def test_get_local_net(client_ips, saddr, expected_cidr): +def test_store_features_going_in_skips_unsupported_flow(): profiler = ModuleFactory().create_profiler_worker_obj() - profiler.args.interface = None - flow = Mock() - flow.saddr = saddr - - if not client_ips: - with patch.object( - profiler, "get_private_client_ips", return_value=client_ips - ), patch( - "slips_files.common.slips_utils.Utils.get_cidr_of_private_ip", - return_value="10.0.0.0/8", - ): - local_net = profiler.get_local_net_of_flow(flow) - else: - with patch.object( - profiler, "get_private_client_ips", return_value=client_ips - ): - local_net = profiler.get_local_net_of_flow(flow) - - assert local_net == {"default": expected_cidr} - - -def test_get_local_net_from_flow(): - profiler = ModuleFactory().create_profiler_worker_obj() - profiler.args.interface = None - with patch.object( - profiler, "get_private_client_ips", return_value=[] - ), patch( - "slips_files.common.slips_utils.Utils.get_cidr_of_private_ip", - return_value="10.0.0.0/8", - ): - flow = Mock() - flow.saddr = "10.0.0.1" - local_net = profiler.get_local_net_of_flow(flow) + profiler.store_features_going_in( + "profile_test", "tw1", Mock(type_="dns", saddr="192.168.1.1") + ) - assert local_net == {"default": "10.0.0.0/8"} + profiler.db.add_tuple.assert_not_called() + profiler.aid_manager.submit_aid_task.assert_not_called() -def test_handle_setting_local_net_when_already_set(): +def test_store_features_going_in_skips_invalid_source_ip(): profiler = ModuleFactory().create_profiler_worker_obj() - mock_lock = MagicMock() - mock_lock.__enter__.return_value = None - mock_lock.__exit__.return_value = None - profiler.handle_setting_local_net_lock = mock_lock + profiler.symbol.compute = Mock(return_value="symbol") - local_net = "192.168.1.0/24" - profiler.should_set_localnet = Mock(return_value=False) - profiler.localnet_cache = {"default": local_net} - flow = Mock() - profiler.handle_setting_local_net(flow) - profiler.db.set_local_network.assert_not_called() + profiler.store_features_going_in( + "profile_test", "tw1", Mock(type_="conn", saddr="not-an-ip") + ) + + profiler.db.add_tuple.assert_not_called() -def test_handle_setting_local_net(): +def test_handle_in_flow_stores_reverse_profile(): profiler = ModuleFactory().create_profiler_worker_obj() - mock_lock = MagicMock() - mock_lock.__enter__.return_value = None - mock_lock.__exit__.return_value = None - profiler.handle_setting_local_net_lock = mock_lock + flow = make_conn(type_="conn") + profiler.get_rev_profile = Mock(return_value=("rev_profile", "rev_twid")) + profiler.store_features_going_in = Mock() - local_net = "192.168.1.0/24" - profiler.should_set_localnet = Mock(return_value=True) - profiler.get_local_net_of_flow = Mock(return_value={"default": local_net}) - profiler.get_local_net = Mock(return_value=local_net) - profiler.db.is_running_non_stop = Mock(return_value=False) + profiler.handle_in_flow(flow) - flow = Mock() - flow.saddr = "192.168.1.1" + profiler.store_features_going_in.assert_called_once_with( + "rev_profile", "rev_twid", flow + ) + + +def test_handle_in_flow_skips_software_flows(): + profiler = ModuleFactory().create_profiler_worker_obj() - profiler.handle_setting_local_net(flow) - profiler.db.set_local_network.assert_called_once_with(local_net, "default") + profiler.handle_in_flow(Mock(type_="software")) + + profiler.db.add_profile.assert_not_called() @patch("slips_files.core.profiler_worker.utils.is_private_ip") @@ -404,33 +393,11 @@ def test_get_gateway_info_sets_mac_and_ip( mock_is_ignored_ip, mock_is_private_ip ): profiler = ModuleFactory().create_profiler_worker_obj() - # mac not detected, ip not detected - profiler.is_gw_info_detected = Mock() - profiler.is_gw_info_detected.side_effect = [False, False] + profiler.is_gw_info_detected = Mock(side_effect=[False, False]) + profiler.get_gw_ip_using_gw_mac = Mock(return_value="8.8.8.1") mock_is_private_ip.return_value = True mock_is_ignored_ip.return_value = False - profiler.get_gw_ip_using_gw_mac = Mock() - profiler.get_gw_ip_using_gw_mac.return_value = "8.8.8.1" - flow: Conn = Conn( - starttime="1.0", - uid="1234", - saddr="192.168.1.1", - daddr="8.8.8.8", - dur=5, - proto="TCP", - appproto="dhcp", - sport=80, - dport=88, - spkts=20, - dpkts=20, - sbytes=20, - dbytes=20, - smac="", - dmac="00:11:22:33:44:55", - state="Established", - history="", - interface="eth0", - ) + flow = make_conn(dmac="00:11:22:33:44:55") profiler.get_gateway_info(flow) @@ -438,55 +405,43 @@ def test_get_gateway_info_sets_mac_and_ip( profiler.db.set_default_gateway.assert_any_call("IP", "8.8.8.1", "eth0") -@patch("slips_files.core.profiler_worker.utils.is_private_ip") -def test_get_gateway_info_no_mac_detected(mock_is_private_ip): +def test_get_gateway_info_skips_flows_without_dmac(): profiler = ModuleFactory().create_profiler_worker_obj() + flow = Mock(spec=["interface"]) + flow.interface = "eth0" - # mac not detected, ip not detected - profiler.is_gw_info_detected = Mock() - profiler.is_gw_info_detected.side_effect = [False, False] - mock_is_private_ip.return_value = False - flow: Conn = Conn( - starttime="1.0", - uid="1234", - saddr="192.168.1.1", - daddr="8.8.8.8", - dur=5, - proto="TCP", - appproto="dhcp", - sport=80, - dport=88, - spkts=20, - dpkts=20, - sbytes=20, - dbytes=20, - smac="", - dmac="00:11:22:33:44:55", - state="Established", - history="", - ) profiler.get_gateway_info(flow) - # mac and ip should not be set profiler.db.set_default_gateway.assert_not_called() - profiler.print.assert_not_called() -def test_get_gateway_info_mac_detected_but_no_ip(): +@patch( + "slips_files.core.profiler_worker.utils.is_private_ip", return_value=False +) +def test_get_gateway_info_does_not_set_gateway_for_non_private_source(_mock): profiler = ModuleFactory().create_profiler_worker_obj() - flow = Mock() - flow.dmac = "123" - # mac detected, ip not detected profiler.is_gw_info_detected = Mock() - profiler.is_gw_info_detected.side_effect = [True, False] - profiler.get_gw_ip_using_gw_mac = Mock() - profiler.get_gw_ip_using_gw_mac.return_value = None + profiler.is_gw_info_detected.side_effect = [False, False] - profiler.get_gateway_info(flow) + profiler.get_gateway_info(make_conn(dmac="00:11:22:33:44:55")) - # assertions for mac profiler.db.set_default_gateway.assert_not_called() - profiler.print.assert_not_called() + + +def test_get_gw_ip_using_gw_mac_prefers_ipv4(): + profiler = ModuleFactory().create_profiler_worker_obj() + profiler.db.get_ip_of_mac.return_value = json.dumps( + ["2001:db8::1", "192.168.0.1"] + ) + + assert profiler.get_gw_ip_using_gw_mac("mac") == "192.168.0.1" + + +def test_get_gw_ip_using_gw_mac_returns_none_when_missing(): + profiler = ModuleFactory().create_profiler_worker_obj() + profiler.db.get_ip_of_mac.return_value = None + + assert profiler.get_gw_ip_using_gw_mac("mac") is None @pytest.mark.parametrize( @@ -496,129 +451,262 @@ def test_get_gateway_info_mac_detected_but_no_ip(): ("ip", "gw_ips", "get_gateway_ip", "192.168.1.1"), ], ) -def test_is_gw_info_detected(info_type, attr_name, db_method, db_value): - # create a profiler object using the ModuleFactory +def test_is_gw_info_detected_loads_from_db( + info_type, attr_name, db_method, db_value +): profiler = ModuleFactory().create_profiler_worker_obj() - - # ensure gw_macs / gw_ips exist as dicts setattr(profiler, attr_name, {}) + setattr(profiler.db, db_method, Mock(return_value=db_value)) - # mock the db method - mock_method = Mock(return_value=db_value) - setattr(profiler.db, db_method, mock_method) + assert profiler.is_gw_info_detected(info_type, "eth0") is True + assert getattr(profiler, attr_name)["eth0"] == db_value - # call the function - result = profiler.is_gw_info_detected(info_type, "eth0") - # verify - assert result is True - assert getattr(profiler, attr_name)["eth0"] == db_value - mock_method.assert_called_once_with("eth0") +def test_is_gw_info_detected_uses_cached_value(): + profiler = ModuleFactory().create_profiler_worker_obj() + profiler.gw_macs = {"eth0": "mac"} + + assert profiler.is_gw_info_detected("mac", "eth0") is True + profiler.db.get_gateway_mac.assert_not_called() def test_is_gw_info_detected_unsupported_info_type(): - # create a profiler object using the ModuleFactory profiler = ModuleFactory().create_profiler_worker_obj() - # test with an unsupported info_type - with pytest.raises(ValueError) as exc_info: - profiler.is_gw_info_detected("unsupported_type", "eth0") + with pytest.raises(ValueError, match="Unsupported info_type"): + profiler.is_gw_info_detected("unsupported", "eth0") + + +@pytest.mark.parametrize( + ("ip", "expected"), + [ + ("224.0.0.1", True), + ("127.0.0.1", True), + ("169.254.1.1", True), + ("240.0.0.1", True), + ("8.8.8.8", False), + ("not-an-ip", True), + ], +) +def test_is_ignored_ip(ip, expected): + profiler = ModuleFactory().create_profiler_worker_obj() - assert str(exc_info.value) == "Unsupported info_type: unsupported_type" + assert profiler.is_ignored_ip(ip) is expected -def test_main_no_msg(): +@pytest.mark.parametrize( + ("starttime", "type_", "expected"), + [ + ("1", "conn", True), + ("1", "http", True), + (None, "conn", False), + ("1", "conn.log", False), + ("1", "unsupported", False), + ], +) +def test_is_supported_flow_type(starttime, type_, expected): profiler = ModuleFactory().create_profiler_worker_obj() - profiler.should_stop_profiler_workers = Mock() - profiler.get_msg_from_queue = Mock() - profiler.add_flow_to_profile = Mock() - profiler.input_handler = Mock() - profiler.print = Mock() - profiler.get_handler_obj = Mock() - profiler.print_traceback = Mock() - - profiler.should_stop_profiler_workers.side_effect = [ - False, - True, - ] # Run loop once - profiler.get_msg_from_queue.return_value = ( - None # Empty message (no message in queue) + + assert ( + profiler._is_supported_flow_type( + Mock(starttime=starttime, type_=type_) + ) + is expected ) - profiler.main() - profiler.get_handler_obj.assert_not_called() - profiler.input_handler.process_line.assert_not_called() - profiler.add_flow_to_profile.assert_not_called() - profiler.print.assert_any_call( - "Module didn't subscribe to new_zeek_fields_line and is trying to get msgs from it." +def test_add_flow_to_profile_returns_false_for_unsupported_flow(): + profiler = ModuleFactory().create_profiler_worker_obj() + + assert ( + profiler.add_flow_to_profile( + Mock( + type_="unsupported", + starttime="1", + saddr="1.1.1.1", + daddr="2.2.2.2", + ) + ) + is False + ) + + +def test_add_flow_to_profile_rejects_invalid_addresses(): + profiler = ModuleFactory().create_profiler_worker_obj() + flow = Mock(type_="conn", starttime="1", saddr="bad", daddr=None) + + assert profiler.add_flow_to_profile(flow) is False + + +def test_add_flow_to_profile_stops_after_whitelist(): + profiler = ModuleFactory().create_profiler_worker_obj() + flow = make_conn(type_="conn") + profiler.convert_starttime_to_unix_ts = Mock(return_value="2.0") + profiler._log_flow_latency = Mock() + profiler.get_gateway_info = Mock() + profiler.whitelist.is_whitelisted_flow = Mock(return_value=True) + profiler.store_features_going_out = Mock() + assert profiler.add_flow_to_profile(flow) is True + + profiler.db.add_profile.assert_not_called() + profiler.store_features_going_out.assert_not_called() + + +def test_add_flow_to_profile_stores_forward_and_reverse_flows(): + profiler = ModuleFactory().create_profiler_worker_obj() + flow = make_conn(type_="conn") + profiler.analysis_direction = "all" + profiler.convert_starttime_to_unix_ts = Mock(return_value="2.0") + profiler._log_flow_latency = Mock() + profiler.get_gateway_info = Mock() + profiler.whitelist.is_whitelisted_flow = Mock(return_value=False) + profiler.store_features_going_out = Mock() + profiler.handle_in_flow = Mock() + profiler.db.get_timewindow.return_value = "tw1" + profiler.db.is_cyst_enabled.return_value = False + + assert profiler.add_flow_to_profile(flow) is True + + profiler.db.add_profile.assert_called_once_with( + "profile_192.168.1.1", "2.0" + ) + profiler.store_features_going_out.assert_called_once_with( + flow, "profile_192.168.1.1", "tw1" ) + profiler.handle_in_flow.assert_called_once_with(flow) + assert flow.starttime == "2.0" -def test_is_stop_msg(monkeypatch): +def test_update_the_files_input_handler_knows_about(): profiler = ModuleFactory().create_profiler_worker_obj() + profiler.input_handler.line_processor_cache = {} + msg = {"data": json.dumps({"conn.log": {"foo": 1}})} + + profiler.update_the_files_input_handler_knows_about(msg) + + assert profiler.input_handler.line_processor_cache == { + "conn.log": {"foo": 1} + } + + +def test_is_stop_msg(): + profiler = ModuleFactory().create_profiler_worker_obj() + assert profiler.is_stop_msg("stop") is True assert profiler.is_stop_msg("not_stop") is False -def test_main_stop_msg_received(): +def test_should_stop_always_returns_false(): profiler = ModuleFactory().create_profiler_worker_obj() - profiler.should_stop = Mock(side_effect=[False, True]) - - profiler.profiler_queue = Mock(spec=queue.Queue) - profiler.profiler_queue.get.return_value = "stop" - stopped = profiler.main() - assert stopped + assert profiler.should_stop() is False -def test_main(): +def test_pre_main_updates_line_processor_cache(): profiler = ModuleFactory().create_profiler_worker_obj() - profiler.should_stop_profiler_workers = Mock() - profiler.get_msg_from_queue = Mock() - profiler.input_handler = Mock() - profiler.add_flow_to_profile = Mock() - profiler.handle_setting_local_net = Mock() - profiler.print = Mock() - profiler.print_traceback = Mock() - profiler.should_stop_profiler_workers.side_effect = [ - False, - True, - ] # Run once - profiler.get_msg_from_queue.return_value = { - "line": {"key": "value"}, - "input_type": InputType.ZEEK, + profiler.name = "ProfilerWorker_Process_2" + profiler.input_handler.line_processor_cache = {} + profiler.db.get_line_processors.return_value = { + "conn.log": json.dumps({"ts": 0}) } - mock_flow = Mock() - profiler.input_handler.process_line = Mock(return_value=(mock_flow, "")) + + profiler.pre_main() + + assert profiler.input_handler.line_processor_cache == { + "conn.log": {"ts": 0} + } + + +def test_main_returns_when_queue_is_empty(): + profiler = ModuleFactory().create_profiler_worker_obj() + profiler.get_msg = Mock(return_value=None) + profiler.get_msg_from_queue = Mock(return_value=None) + + assert profiler.main() is None + + +def test_main_stops_on_stop_message(): + profiler = ModuleFactory().create_profiler_worker_obj() + profiler.get_msg = Mock(return_value=None) + profiler.get_msg_from_queue = Mock(return_value="stop") + + assert profiler.main() == 1 + + +def test_main_requeues_unknown_line_processor_until_input_done(): + profiler = ModuleFactory().create_profiler_worker_obj() + profiler.get_msg = Mock(return_value=None) + msg = {"line": {"foo": "bar"}} + profiler.get_msg_from_queue = Mock(return_value=msg) + profiler.is_input_done_event.is_set.return_value = False + profiler.input_handler.process_line = Mock( + return_value=(None, "unknown line_processor") + ) profiler.main() - profiler.input_handler.process_line.assert_called_once() - profiler.add_flow_to_profile.assert_called_once() - profiler.handle_setting_local_net.assert_called_once() - profiler.db.increment_processed_flows.assert_called_once() + profiler.profiler_queue.put.assert_called_once_with(msg) + profiler.db.increment_processed_flows.assert_not_called() -def test_main_handle_exception(): +def test_main_does_not_requeue_unknown_line_processor_after_input_done(): profiler = ModuleFactory().create_profiler_worker_obj() - profiler.should_stop_profiler_workers = Mock() - profiler.get_msg_from_queue = Mock() - profiler.input_handler = Mock() - profiler.print = Mock() - profiler.print_traceback = Mock() + profiler.get_msg = Mock(return_value=None) + msg = {"line": {"foo": "bar"}} + profiler.get_msg_from_queue = Mock(return_value=msg) + profiler.is_input_done_event.is_set.return_value = True + profiler.input_handler.process_line = Mock( + return_value=(None, "unknown line_processor") + ) - profiler.should_stop_profiler_workers.side_effect = [ - False, - True, - ] # Run loop once - profiler.get_msg_from_queue.return_value = { - "line": {"key": "value"}, - "input_type": "invalid_type", - } - profiler.input_handler.process_line.side_effect = Exception( - "Test exception" + profiler.main() + + profiler.profiler_queue.put.assert_not_called() + + +def test_main_processes_valid_flow_and_records_performance(): + profiler = ModuleFactory().create_profiler_worker_obj() + profiler.generate_performance_plots = True + profiler.get_msg = Mock(return_value=None) + profiler.get_msg_from_queue = Mock(return_value={"line": {"foo": "bar"}}) + profiler.is_stop_msg = Mock(return_value=False) + flow = Mock() + profiler.input_handler.process_line = Mock(return_value=(flow, None)) + profiler.add_flow_to_profile = Mock() + profiler.localnet_handler.handle_setting_local_net = Mock() + + assert profiler.main() is None + + profiler.add_flow_to_profile.assert_called_once_with(flow) + profiler.localnet_handler.handle_setting_local_net.assert_called_once_with( + flow ) + profiler.db.increment_processed_flows.assert_called_once() + profiler.db.record_flow_per_minute.assert_called_once_with(profiler.name) + + +def test_main_collects_gc_every_10000_flows(): + profiler = ModuleFactory().create_profiler_worker_obj() + profiler.get_msg = Mock(return_value=None) + profiler.get_msg_from_queue = Mock(return_value={"line": {"foo": "bar"}}) + profiler.input_handler.process_line = Mock(return_value=(Mock(), None)) + profiler.add_flow_to_profile = Mock() + profiler.localnet_handler.handle_setting_local_net = Mock() + profiler.received_lines = 9999 + + with patch("slips_files.core.profiler_worker.gc.collect") as mock_collect: + profiler.main() + + mock_collect.assert_called_once() + + +def test_main_logs_exception(): + profiler = ModuleFactory().create_profiler_worker_obj() + profiler.get_msg = Mock(return_value=None) + profiler.get_msg_from_queue = Mock(return_value={"line": {"foo": "bar"}}) + profiler.input_handler.process_line = Mock(side_effect=Exception("boom")) + profiler.print_traceback = Mock(return_value="traceback") profiler.main() - profiler.print_traceback.assert_called_once() + + profiler.print.assert_called_once() diff --git a/webinterface/analysis/analysis.py b/webinterface/analysis/analysis.py index 9b0ac3ccc4..de6c2cf764 100644 --- a/webinterface/analysis/analysis.py +++ b/webinterface/analysis/analysis.py @@ -37,7 +37,7 @@ def get_all_tw_with_ts(profileid): tw_date = ts_to_date(tw_ts) dict_tws[tw_n]["tw"] = tw_n dict_tws[tw_n]["name"] = ( - "TW " + tw_n.split("timewindow")[1] + ":" + tw_date + "TW " + tw_n.split("timewindow")[1] + " [ " + tw_date + " ]" ) dict_tws[tw_n]["blocked"] = False # needed to color profiles return dict_tws @@ -253,6 +253,7 @@ def set_timeline( """ data = [] profileid = f"profile_{ip}" + if timeline := db.get_profiled_tw_timeline(profileid, timewindow): for flow in timeline: flow = json.loads(flow)