You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@tooling.apache.org by as...@apache.org on 2026/04/22 04:53:06 UTC

(tooling-agents) branch main updated: ASVS L3 audit: 16.2.2 (logging_and_monitoring)

This is an automated email from the ASF dual-hosted git repository.

asf-tooling pushed a commit to branch main
in repository https://gitbox.apache.org/repos/asf/tooling-agents.git


The following commit(s) were added to refs/heads/main by this push:
     new 6e2e696  ASVS L3 audit: 16.2.2 (logging_and_monitoring)
6e2e696 is described below

commit 6e2e6966e4fa2bb04e5ea38f48eeddb3b008d397
Author: ASF Tooling Team <ro...@apache.org>
AuthorDate: Wed Apr 22 06:53:01 2026 +0200

    ASVS L3 audit: 16.2.2 (logging_and_monitoring)
---
 .../v3/d0aa7e9/logging_and_monitoring/16.2.2.md    | 410 +++++++++++++++++++++
 1 file changed, 410 insertions(+)

diff --git a/repos/apache/ASVS/reports/steve/v3/d0aa7e9/logging_and_monitoring/16.2.2.md b/repos/apache/ASVS/reports/steve/v3/d0aa7e9/logging_and_monitoring/16.2.2.md
new file mode 100644
index 0000000..39821fe
--- /dev/null
+++ b/repos/apache/ASVS/reports/steve/v3/d0aa7e9/logging_and_monitoring/16.2.2.md
@@ -0,0 +1,410 @@
+# ASVS 16.2.2 Security Audit Report
+
+## Executive Summary
+
+**Repository:** apache/steve  
+**Audit Date:** Apr 22, 2026  
+**Auditor:** Tooling Agents  
+**ASVS Requirement:** 16.2.2 — Verify that time sources for all logging components are synchronized, and that timestamps in security event metadata use UTC or include an explicit time zone offset. UTC is recommended to ensure consistency across distributed systems and to prevent confusion during daylight saving time transitions.
+
+**Files Analyzed:** 4 relevant out of 4 total, 0 skipped
+
+**Finding Summary:**
+
+| Severity | Count |
+|----------|-------|
+| Critical | 0 |
+| High | 1 |
+| Medium | 2 |
+| Low | 0 |
+| **Total** | **3** |
+
+**Key Issues Identified:**
+
+The audit identified significant violations of ASVS 16.2.2 regarding time synchronization and UTC/timezone-aware timestamps in security event logs. The system has two distinct logging components (web server and tally CLI) with incompatible configurations—one producing timestamps in local time without timezone offsets, and the other producing security event logs with no timestamps whatsoever.
+
+---
+
+## Security Controls Inventory
+
+| Control | Location | Status | Coverage |
+|---------|----------|--------|----------|
+| Web server logging format | `main.py:55-59, 85-91` | **DEFICIENT** | Local time, no timezone, no year, no seconds |
+| Tally CLI logging format | `tally.py:145` | **MISSING** | Default format has no timestamps at all |
+| UTC enforcement (`Formatter.converter`) | All files | **ABSENT** | Never configured anywhere |
+| Timezone offset in format string (`%z` or `%Z`) | All files | **ABSENT** | Not present in any date format |
+| Synchronized format across components | `main.py` vs `tally.py` | **INCONSISTENT** | Different formats per component |
+
+---
+
+## Critical File Review
+
+### `v3/server/main.py` — Logging Configuration
+
+| Line(s) | Element | ASVS 16.2.2 Compliance | Notes |
+|----------|---------|------------------------|-------|
+| 23 | `DATE_FORMAT = '%m/%d %H:%M'` | ❌ FAIL | No TZ, no year, no seconds |
+| 55-59 | `run_standalone()` basicConfig | ❌ FAIL | Uses local time implicitly |
+| 85-91 | `run_asgi()` basicConfig | ❌ FAIL | Same deficient format |
+| — | `Formatter.converter` | ❌ MISSING | Never set to `time.gmtime` |
+
+### `v3/server/bin/tally.py` — CLI Logging
+
+| Line(s) | Element | ASVS 16.2.2 Compliance | Notes |
+|----------|---------|------------------------|-------|
+| 145 | `logging.basicConfig(level=logging.INFO)` | ❌ FAIL | No format specified, no timestamps |
+| 97 | `_LOGGER.error(...)` | ❌ FAIL | Security event without timestamp |
+| 102-105 | `_LOGGER.info(...)` | ❌ FAIL | Tally operations without timestamp |
+
+### `v3/server/pages.py` — Security Event Log Calls
+
+| Line(s) | Security Event | Timestamp Quality | Compliance |
+|----------|---------------|-------------------|------------|
+| 101 | Election date change | Local, no TZ | ❌ FAIL |
+| 371 | Vote submission | Local, no TZ | ❌ FAIL |
+| 374 | Vote error | Local, no TZ | ❌ FAIL |
+| 394-395 | Election creation | Local, no TZ | ❌ FAIL |
+| 415 | Election opening | Local, no TZ | ❌ FAIL |
+| 428 | Election closing | Local, no TZ | ❌ FAIL |
+| 451 | Issue addition | Local, no TZ | ❌ FAIL |
+| 472-473 | Issue editing | Local, no TZ | ❌ FAIL |
+| 489-490 | Issue deletion | Local, no TZ | ❌ FAIL |
+
+### `v3/steve/election.py` — Library-Level Logging
+
+| Line(s) | Security Event | Compliance | Notes |
+|----------|---------------|------------|-------|
+| 186 | Issue creation | ⚠️ DEPENDS | Inherits caller's format |
+| 197 | Issue update | ⚠️ DEPENDS | Inherits caller's format |
+| 381 | Election creation | ⚠️ DEPENDS | Inherits caller's format |
+
+---
+
+## Findings
+
+### HIGH Severity
+
+#### ASVS-1622-HIGH-001: Tally CLI Security Event Logs Lack Timestamps Entirely
+
+**Location:** `v3/server/bin/tally.py`, line 145  
+**Function:** `__main__` block / `main()` / `tally_election()`  
+**Gap Type:** Type A — Entry point with NO control
+
+**Vulnerable Code:**
+
+```python
+# tally.py:145
+if __name__ == '__main__':
+    logging.basicConfig(level=logging.INFO)
+```
+
+Python's `logging.basicConfig()` without a `format` argument uses the default `BASIC_FORMAT`: `"%(levelname)s:%(name)s:%(message)s"` — which contains **no timestamp field** (`asctime`).
+
+**Security Events Affected (no timestamps):**
+
+| Location | Log Statement | Security Event |
+|----------|---------------|----------------|
+| `tally.py:102` | `_LOGGER.info(f'Tallying one issue: {issue_id}')` | Tally initiation |
+| `tally.py:105` | `_LOGGER.info(f'Tallying {len(issues)} issues ...')` | Bulk tally operation |
+| `tally.py:97` | `_LOGGER.error('No issues to tally in this election.')` | Tally error |
+| `election.py:186` | `_LOGGER.info(f'Created issue[I:{iid}] in election[E:{self.eid}]')` | Issue creation (when called from tally context) |
+| `election.py:197` | `_LOGGER.info(f'Updated issue[I:{iid}] in election[E:{self.eid}]')` | Issue update |
+
+**Example Log Output (current):**
+```
+INFO:__main__:Tallying 5 issues ...
+```
+
+**Data Flow:**
+
+The tally CLI is invoked as a separate process, typically after an election closes. It reads encrypted votes from the database, decrypts them, tallies results, and updates election state. All of these operations are logged through the `_LOGGER` instance, which inherits the root logger configuration established at line 145.
+
+**Impact:** 
+
+Tally operations are the most sensitive phase in the election lifecycle—they decrypt votes and produce results. Without timestamps, there is no way to establish:
+- When a tally operation occurred relative to election close
+- Whether a tally was run during an authorized window
+- Temporal correlation with other system events for incident investigation
+- An auditable timeline of vote counting operations
+
+**Proof of Concept:**
+
+1. Run tally CLI: `python tally.py --election abc123`
+2. Observe log output lacks any timestamp information
+3. Cannot determine when tally occurred or correlate with election closure time
+4. Forensic analysis of unauthorized tally operations is impossible
+
+**Remediation:**
+
+```python
+if __name__ == '__main__':
+    logging.basicConfig(
+        level=logging.INFO,
+        style='{',
+        format='[{asctime}|{levelname}|{name}] {message}',
+        datefmt='%Y-%m-%dT%H:%M:%S%z',  # ISO 8601 with timezone
+    )
+    # Force UTC for all log timestamps
+    logging.Formatter.converter = time.gmtime
+```
+
+Or, if using UTC (recommended by ASVS):
+```python
+import time
+
+logging.basicConfig(
+    level=logging.INFO,
+    style='{',
+    format='[{asctime}Z|{levelname}|{name}] {message}',
+    datefmt='%Y-%m-%dT%H:%M:%S',
+)
+logging.Formatter.converter = time.gmtime
+```
+
+---
+
+### MEDIUM Severity
+
+#### ASVS-1622-MEDIUM-002: Web Server Log Timestamps Use Local Time Without Timezone Offset, Year, or Seconds
+
+**Location:** `v3/server/main.py`, lines 23, 55-59, 85-91  
+**Functions:** `run_standalone()`, `run_asgi()`  
+**Gap Type:** Type C — Control CALLED but RESULT insufficient
+
+**Vulnerable Code:**
+
+```python
+# main.py:23
+DATE_FORMAT = '%m/%d %H:%M'
+
+# main.py:55-59 (run_standalone)
+logging.basicConfig(
+    level=logging.DEBUG,
+    style='{',
+    format='[{asctime}|{levelname}|{name}] {message}',
+    datefmt=DATE_FORMAT,  # '%m/%d %H:%M' — local time, no TZ, no year, no seconds
+)
+
+# main.py:85-91 (run_asgi) — identical configuration
+logging.basicConfig(
+    level=logging.DEBUG,
+    style='{',
+    format='[{asctime}|{levelname}|{name}] {message}',
+    datefmt=DATE_FORMAT,
+)
+```
+
+**Issues with `'%m/%d %H:%M'`:**
+
+| Deficiency | ASVS Requirement | Impact |
+|------------|-------------------|--------|
+| No timezone offset (`%z` or `%Z`) | "include an explicit time zone offset" | Cannot determine time reference; ambiguous during DST transitions |
+| No UTC enforcement | "UTC is recommended" | `time.localtime()` is Python's default `Formatter.converter` |
+| No year (`%Y`) | Implied by "consistency across distributed systems" | Cannot distinguish events across year boundaries |
+| No seconds (`%S`) | Precision for security event correlation | Cannot order events within the same minute |
+
+**Security Events Affected (all web server logs in `pages.py`):**
+
+| Location | Log Statement | Security Event |
+|----------|---------------|----------------|
+| `pages.py:101` | `User set {field} for election` | Election date modification |
+| `pages.py:371` | `User voted on issue` | Vote submission |
+| `pages.py:374` | `Error adding vote` | Vote submission failure |
+| `pages.py:394-395` | `User created election` | Election creation |
+| `pages.py:415` | `User opened election` | Election state change (open) |
+| `pages.py:428` | `User closed election` | Election state change (close) |
+| `pages.py:451` | `User added issue` | Issue creation |
+| `pages.py:472-473` | `User edited issue` | Issue modification |
+| `pages.py:489-490` | `User deleted issue` | Issue deletion |
+
+**Example Log Output (current):**
+```
+[01/15 14:30|INFO|pages] User[U:jdoe] opened election[E:abc123]
+```
+
+**Data Flow:**
+
+Web requests flow through the Flask/Bottle application, triggering security-relevant operations in `pages.py`. Each operation logs through the root logger configured in `main.py`. The timestamp format is applied uniformly to all log entries.
+
+**Impact:**
+
+During a DST transition (e.g., November 3 at 1:30 AM), this timestamp is ambiguous — it could be EDT or EST. An attacker could exploit this window to make unauthorized actions harder to trace.
+
+**Proof of Concept Scenario:**
+
+1. Server runs in US Eastern timezone
+2. On November 3 at 1:15 AM EDT, admin legitimately closes election
+3. At 1:15 AM EST (one hour later, same wall-clock time), unauthorized tally is run
+4. Both log entries show `[11/03 01:15|INFO|...]` — indistinguishable
+5. Forensic investigation cannot determine the order or legitimacy of operations
+
+**Remediation:**
+
+```python
+import time
+
+DATE_FORMAT = '%Y-%m-%dT%H:%M:%SZ'  # ISO 8601 UTC format
+
+def run_standalone():
+    formatter = logging.Formatter(
+        fmt='[{asctime}|{levelname}|{name}] {message}',
+        datefmt=DATE_FORMAT,
+        style='{',
+    )
+    formatter.converter = time.gmtime  # Force UTC
+    
+    handler = logging.StreamHandler()
+    handler.setFormatter(formatter)
+    
+    root_logger = logging.getLogger()
+    root_logger.setLevel(logging.DEBUG)
+    root_logger.addHandler(handler)
+```
+
+---
+
+#### ASVS-1622-MEDIUM-003: Unsynchronized Logging Configuration Between Web Server and Tally CLI Components
+
+**Location:** `v3/server/main.py:23,55-59` vs `v3/server/bin/tally.py:145`  
+**Functions:** `run_standalone()`/`run_asgi()` vs `__main__` block  
+**Gap Type:** Type A — No synchronization control exists
+
+**Evidence of Desynchronization:**
+
+| Attribute | Web Server (`main.py`) | Tally CLI (`tally.py`) |
+|-----------|----------------------|----------------------|
+| Format string | `'[{asctime}\|{levelname}\|{name}] {message}'` | Default: `'%(levelname)s:%(name)s:%(message)s'` |
+| Date format | `'%m/%d %H:%M'` (local, no TZ) | N/A (no timestamp) |
+| Timestamp present | Yes (local time) | **No** |
+| Time reference | `time.localtime()` (implicit) | N/A |
+| Style | `{` (new-style) | `%` (old-style, default) |
+
+**Data Flow:**
+
+The `election.py` module's `_LOGGER` inherits formatting from the root logger configured by whichever entry point runs it:
+
+```
+election.py:_LOGGER.info(f'Created election[E:{eid}]')
+  ├── Called from web server → format: [01/15 14:30|INFO|steve.election] Created election[E:abc]
+  └── Called from tally CLI  → format: INFO:steve.election:Created election[E:abc]
+```
+
+The same security event (`election.py` logging) produces fundamentally different log entries depending on the entry point, making SIEM correlation impossible.
+
+**Impact:**
+
+- Security event logs from the web server and CLI tools cannot be correlated by automated analysis tools
+- The same `election.py` module produces different log formats depending on calling context
+- Cross-component incident investigation (e.g., "was the election modified between web close and CLI tally?") requires manual reconciliation
+- Violates ASVS 16.2.2: "time sources for all logging components are synchronized"
+
+**Proof of Concept:**
+
+1. Create election via web interface → log format: `[01/15 14:30|INFO|steve.election] Created election[E:abc123]`
+2. Run tally via CLI → log format: `INFO:steve.election:Tallying election[E:abc123]`
+3. Attempt to correlate events in SIEM → parsing fails due to incompatible formats
+4. Manual investigation required to establish event timeline
+
+**Remediation:**
+
+Create a shared logging configuration module:
+
+```python
+# v3/steve/log_config.py
+import time
+import logging
+
+LOG_FORMAT = '[{asctime}|{levelname}|{name}] {message}'
+LOG_DATEFMT = '%Y-%m-%dT%H:%M:%SZ'  # ISO 8601 UTC
+LOG_STYLE = '{'
+
+def configure_logging(level=logging.INFO):
+    """Configure logging consistently across all components."""
+    formatter = logging.Formatter(
+        fmt=LOG_FORMAT,
+        datefmt=LOG_DATEFMT,
+        style=LOG_STYLE,
+    )
+    formatter.converter = time.gmtime  # Enforce UTC
+    
+    handler = logging.StreamHandler()
+    handler.setFormatter(formatter)
+    
+    root = logging.getLogger()
+    root.setLevel(level)
+    root.addHandler(handler)
+```
+
+Then use in both entry points:
+```python
+# main.py
+from steve.log_config import configure_logging
+configure_logging(logging.DEBUG)
+
+# tally.py
+from steve.log_config import configure_logging
+configure_logging(logging.INFO)
+```
+
+---
+
+## Positive Security Patterns
+
+| Pattern | Location | Description |
+|---------|----------|-------------|
+| Structured log format | `main.py:57` | Uses `[asctime|level|name] message` — machine-parseable delimiters |
+| User attribution in logs | `pages.py` (all log calls) | Consistently includes `User[U:{uid}]` in security events |
+| Entity identification | `pages.py`, `election.py` | Uses structured tags: `election[E:{eid}]`, `issue[I:{iid}]` |
+| Outcome logging | `pages.py:371,374` | Both success and failure paths for vote submission are logged |
+| No vote content in logs | `pages.py:371` | Vote submissions log voter/issue IDs but never vote content |
+| Separate security events | `pages.py` | Each state-changing operation has its own log entry |
+
+---
+
+## Architecture Observations
+
+1. **Two-component architecture with no shared logging config**: The web server (`main.py`) and CLI tool (`tally.py`) are separate entry points that independently configure Python's root logger. There is no shared logging module, leading to divergent timestamp formats and the inability to correlate events across components.
+
+2. **Python logging defaults favor local time**: Python's `logging.Formatter` defaults to `time.localtime()` for timestamp generation. Without explicit `converter = time.gmtime`, all timestamps will be in server-local time. This is a common oversight in Python applications.
+
+3. **No NTP/time synchronization verification**: While NTP synchronization is typically an infrastructure concern rather than application code, the application makes no attempt to verify or log the system's time synchronization status (e.g., checking `ntpstat` or similar on startup).
+
+4. **Election-specific timestamp handling**: The `datetime.datetime.fromtimestamp()` calls in `pages.py:579` and `tally.py:80` also use local time for election metadata display. While these are not logging timestamps per se, they create a systemic pattern of local-time-without-timezone usage that increases confusion risk.
+
+---
+
+## Recommendations Summary
+
+### Immediate Actions (Critical Priority)
+
+| Priority | Recommendation | Effort | Impact | Finding Reference |
+|----------|---------------|--------|--------|-------------------|
+| 1 | Add timestamps to tally CLI logging | Low | HIGH — Critical audit trail gap for vote counting | ASVS-1622-HIGH-001 |
+| 2 | Create shared logging configuration module | Low | MEDIUM — Ensures consistency across all components | ASVS-1622-MEDIUM-003 |
+
+### Short-term Actions (High Priority)
+
+| Priority | Recommendation | Effort | Impact | Finding Reference |
+|----------|---------------|--------|--------|-------------------|
+| 3 | Switch all log timestamps to UTC with `time.gmtime` converter | Low | MEDIUM — Eliminates DST ambiguity | ASVS-1622-HIGH-001, ASVS-1622-MEDIUM-002, ASVS-1622-MEDIUM-003 |
+| 4 | Use ISO 8601 format `%Y-%m-%dT%H:%M:%SZ` with year and seconds | Low | MEDIUM — Enables proper SIEM ingestion and cross-year correlation | ASVS-1622-MEDIUM-002 |
+
+### Long-term Actions (Medium Priority)
+
+| Priority | Recommendation | Effort | Impact | Finding Reference |
+|----------|---------------|--------|--------|-------------------|
+| 5 | Add timezone offset to any non-UTC timestamps if UTC is not feasible | Low | MEDIUM — Meets minimum ASVS requirement | ASVS-1622-MEDIUM-002 |
+
+---
+
+## Appendix: Files Analyzed
+
+<details>
+<summary>Click to expand file list</summary>
+
+- `v3/server/bin/tally.py` (relevance: 10)
+- `v3/server/main.py` (relevance: 10)
+- `v3/server/pages.py` (relevance: 10)
+- `v3/steve/election.py` (relevance: 10)
+
+</details>
\ No newline at end of file


---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@tooling.apache.org
For additional commands, e-mail: commits-help@tooling.apache.org