Incomex AI Portal
KB-6DA3

S174-INV-05 Ops RCA

21 min read Revision 1
s174investigationrcaopswatchdoglogrotatersyslog

S174-INV-05 — RCA 3 TD vận hành (Đ31 watchdog + logrotate + rsyslog)

Date: 2026-04-09
Mode: READ-ONLY
Scope: Điều tra 5 tầng "tại sao" cho 3 TD vận hành mở lâu, không sửa hệ thống

1. Executive Summary

Kết luận ngắn

  • TD-1 / Đ31 watchdog stale: gốc thật là security hardening commit d9217ca5 (2026-04-02 12:53:12 +0700) đã biến sync-check.js từ hardcoded fallback sang require AGENT_DATA_URL, nhưng host cron runner không có env contract tương ứng. cron-integrity.sh không export AGENT_DATA_URL, /opt/incomex/docker/.env cũng không có key này, nên từ slot 2026-04-02 12:00:02 CEST runner fail-fast và watchdog đóng băng ở last_seen_at=2026-04-02T04:01:15.687Z.
  • TD-2 / logrotate duplicate fail: gốc thật là 2 nguồn cấu hình logrotate cùng quản lý cùng log target: GitOps file /etc/logrotate.d/incomex và 2 standalone file drift /etc/logrotate.d/config-integrity, /etc/logrotate.d/mcp-health. Cả 3 file đều có mtime 2026-02-28, nhưng quy trình triển khai không có validate logrotate -d / CI gate, nên duplicate đi vào production và fail hằng ngày. Earliest retained journal evidence là 2026-03-28 00:00:02, không phải 2026-04-02.
  • TD-3 / rsyslog omfile suspend: gốc thật là route UFW của package ufw vẫn ghi về /var/log/ufw.log, nhưng file đích hiện không tồn tại; khi có [UFW BLOCK], rsyslog gặp open error: Permission denied rồi omfile suspended/resumed. Đây là log-path drift ở OS layer, không phải cùng lỗi trực tiếp với logrotate duplicate, nhưng cùng họ "vận hành nền drift, không có guardrail".

Pattern observation

  • Cả 3 TD cùng họ gốc: thay đổi ở lớp vận hành nền (cron/env/log configs/log paths) không có contract check trước deploy và không có monitor vòng 2 đủ mạnh.
  • TD-1 là pattern gần nhất với PG backup RCA: thay đổi một dependency contract (AGENT_DATA_URL) nhưng không grep dependency / không verify consumer host-side.
  • TD-2 là pattern GitOps drift: thêm config mới nhưng không reconcile config cũ ngoài repo.
  • TD-3 là pattern OS drift: package route còn đó nhưng log target biến mất, không có health check cho path ownership/existence.

Khuyến nghị gộp/tách mission fix

  • Mission A (ưu tiên 1): TD-1 Đ31 runner + watchdog
    Lý do: đây là "cảnh sát hệ thống"; stale thì mất lớp phát hiện lỗi ứng dụng.
  • Mission B (ưu tiên 2): TD-2 + TD-3 logging subsystem
    Lý do: cùng ownership/log stack (/etc/logrotate.d, rsyslog, /var/log/*), verify chéo thuận tiện, tránh fix từng mảnh rồi bỏ sót tương tác.

2. Timeline riêng cho từng TD

TD-1 — Đ31 watchdog stale

  • 2026-04-02 06:00:02 CEST: runner còn sống. cron-20260402-060001.log kết thúc với:
    • WATCHDOG: alive
    • Results logged to measurement_log (run_id: cron-20260402-060001)
  • 2026-04-02T04:01:15.687Z: watchdog last_seen_at cuối cùng còn được log, thấy trong watchdog.log.
  • 2026-04-02 12:00:02 CEST: slot fail đầu tiên còn giữ được evidence:
    • Error: Missing required env: AGENT_DATA_URL
  • 2026-04-02 12:53:12 +0700: commit d9217ca5d32622d2f6dd064da84a1c184bd516cb authored, nội dung:
    • All now require env vars — fail fast if missing.
    • diff đổi AGENT_DATA_URL từ hardcoded fallback sang required env.
  • 2026-04-03 đến 2026-04-09: tất cả cron-*.log của Đ31 co xuống khoảng 1.1K, cùng một stacktrace thiếu env.
  • 2026-04-09: không có monitor Kuma tên watchdog/Điều 31/dieu31 (count(*) = 0).

TD-2 — logrotate duplicate fail

  • 2026-02-28 06:09:25 +0100: /etc/logrotate.d/config-integrity và /etc/logrotate.d/mcp-health có mtime này.
  • 2026-02-28 07:08:33 +0100: /etc/logrotate.d/incomex có mtime này.
  • 2026-02-28 12:40:34 +0700: commit bc1ae1d4e675deeec0997baeec02c848086c9ba0 thêm infra/logrotate/incomex vào GitOps.
  • Earliest retained journal evidence:
    • 2026-03-28 00:00:02: logrotate.service fail vì duplicate /var/log/config-integrity.log và /var/log/mcp-health.log.
  • 2026-03-28 đến 2026-04-09: fail lặp lại hàng ngày cùng một error signature.

TD-3 — rsyslog omfile suspend

  • /etc/rsyslog.d/20-ufw.conf là file package-managed bởi ufw, mtime 2023-05-16.
  • Earliest retained journal evidence:
    • 2026-04-01 00:00:00: kernel: [UFW BLOCK] ... đi kèm chuỗi action 'action-0-builtin:omfile' suspended.
  • 2026-04-05 00:00:39: syslog hiện rõ nguyên nhân:
    • file '/var/log/ufw.log': open error: Permission denied
  • 2026-04-09: /var/log/ufw.log* không tồn tại (no_ufw_logs), rsyslog vẫn lặp suspended/resumed.

3. Chain of Failure — 5 tầng × 3 TD

TD-1 — Đ31 watchdog stale

Tầng 1 — Hiện tượng

  • Cron hiện tại:
    • 0 */6 * * * /opt/incomex/deploys/web-test/scripts/integrity/cron-integrity.sh >> /opt/incomex/logs/integrity/cron.log 2>&1
    • 0 * * * * /opt/incomex/deploys/web-test/scripts/integrity/watchdog-monitor.sh >> /opt/incomex/logs/integrity/watchdog.log 2>&1
  • Watchdog state không nằm ở local state file; script đọc từ Directus system_issues:
    • watchdog-monitor.sh:25 query .../items/system_issues?...sort=-last_seen_at&fields=last_seen_at,occurrence_count
  • watchdog.log cho thấy state đóng băng ở:
    • WATCHDOG ALERT: Runner Điều 31 không chạy từ 2026-04-02T04:01:15.687Z

Tầng 2 — Cơ chế fail

  • sync-check.js fail ngay khi require():
    • const AGENT_DATA_URL = process.env.AGENT_DATA_URL;
    • if (!AGENT_DATA_URL) throw new Error('Missing required env: AGENT_DATA_URL');
  • Slot fail đầu tiên còn giữ được:
=== Điều 31 Cron — cron-20260402-120002 ===
Time: Thu Apr  2 12:00:02 CEST 2026
/opt/incomex/deploys/web-test/scripts/integrity/runners/sync-check.js:9
if (!AGENT_DATA_URL) throw new Error('Missing required env: AGENT_DATA_URL');
...
Error: Missing required env: AGENT_DATA_URL

Tầng 3 — Vì sao env mất

  • Commit gốc:
commit d9217ca5d32622d2f6dd064da84a1c184bd516cb
Date:   Thu Apr 2 12:53:12 2026 +0700
fix(security): remove hardcoded credentials, URLs, UUIDs (§0-AU GĐ1) (#664)
All now require env vars — fail fast if missing.
  • Diff trực tiếp:
-const AGENT_DATA_URL = process.env.AGENT_DATA_URL || 'https://vps.incomexsaigoncorp.vn/api';
+const AGENT_DATA_URL = process.env.AGENT_DATA_URL;
+if (!AGENT_DATA_URL) throw new Error('Missing required env: AGENT_DATA_URL');
  • Host cron wrapper không export AGENT_DATA_URL. cron-integrity.sh chỉ export DIRECTUS_TOKEN, DIRECTUS_URL, SITE_URL, DATABASE_URL.
  • /opt/incomex/docker/.env trên VPS không có AGENT_DATA_URL.
  • AGENT_DATA_URL chỉ thấy trong env của Directus container, không phải host cron:
    • infra/docker/docker-compose.yml:87-88
    • FLOWS_ENV_ALLOW_LIST: "WEB_URL,AGENT_DATA_URL,AGENT_DATA_API_KEY"
    • AGENT_DATA_URL: http://agent-data:8000

Tầng 4 — Vì sao 6 ngày không ai biết

  • watchdog-monitor.sh chỉ:
    • query Directus
    • echo "WATCHDOG ALERT: ..."
    • exit 1
  • Không có push monitor / Kuma heartbeat trong script.
  • Trên VPS hiện không có monitor Kuma liên quan tên watchdog/Điều 31/dieu31:
    • SQLite query select count(*) ... trả 0
  • Kết quả: runner chết, watchdog phát hiện stale, nhưng chính watchdog không có monitor vòng 2. Đây là recursive blind spot.

Tầng 5 — Gốc thật

Nguyên nhân sâu nhất là commit hardening d9217ca5 đã đổi sync-check.js sang require host env, nhưng hệ thống không có env contract + preflight check + external liveness monitor cho runner host-side, nên một thay đổi "đúng về security" đã giết runner production một cách lặp lại.

Q2 — Làm sao để vĩnh viễn không quay lại

  • Fix trực tiếp:
    • thiết lập AGENT_DATA_URL rõ ràng cho host runner
    • thêm preflight trong cron-integrity.sh để fail trước khi vào Node, với message rõ
  • Fix hệ thống:
    • mọi thay đổi từ hardcoded -> env cho cron host phải có checklist "consumer matrix" và verify tất cả execution contexts
    • thêm monitor ngoài cho watchdog-monitor.sh hoặc heartbeat riêng cho runner; không để watchdog chỉ ghi log local
    • CI/deploy gate phải chặn merge/deploy nếu script production require env mà host crontab/context chưa được wiring

TD-2 — logrotate duplicate fail

Tầng 1 — Hiện tượng

  • systemctl status logrotate.service:
    • error: incomex:8 duplicate log entry for /var/log/config-integrity.log
    • error: mcp-health:1 duplicate log entry for /var/log/mcp-health.log
  • logrotate -d /etc/logrotate.conf lặp lại cùng error.

Tầng 2 — Cơ chế fail

  • Duplicate source được xác nhận:
/etc/logrotate.d/incomex:8:/var/log/mcp-health.log
/etc/logrotate.d/incomex:9:/var/log/config-integrity.log
/etc/logrotate.d/config-integrity:1:/var/log/config-integrity.log {
/etc/logrotate.d/mcp-health:1:/var/log/mcp-health.log {
  • Nội dung /etc/logrotate.d/incomex còn ghi rõ provenance:
    • Install: cp /opt/incomex/infra/logrotate/incomex /etc/logrotate.d/incomex

Tầng 3 — Vì sao duplicate xuất hiện

  • GitOps commit:
    • bc1ae1d4e675deeec0997baeec02c848086c9ba0
    • feat: add cron and logrotate configs to GitOps (WEB-87) (#403)
  • File GitOps thêm cả hai log vào rule incomex.
  • Đồng thời trên VPS tồn tại hai standalone file ngoài repo:
    • /etc/logrotate.d/config-integrity
    • /etc/logrotate.d/mcp-health
  • dpkg -S cho hai file standalone trả:
    • no path found matching pattern ...
  • Repo search không có source cho hai standalone file này.

Tầng 4 — Vì sao không bị phát hiện lúc deploy

  • Repo chỉ có comment verify:
    • # Verify: logrotate -d /etc/logrotate.d/incomex
  • Nhưng không thấy workflow/script/CI gate nào thực sự chạy validation logrotate:
    • rg -n "logrotate -d|/etc/logrotate.d|rsyslog" ... chỉ trả về comment trong infra/logrotate/incomex
  • Nghĩa là deploy đã thêm GitOps config mới nhưng không reconcile existing server state và không validate merged config set.

Tầng 5 — Gốc thật

Nguyên nhân sâu nhất là cùng một log target bị quản lý bởi hai nguồn cấu hình độc lập từ 2026-02-28 (GitOps incomex + standalone drift files ngoài repo), trong khi quy trình deploy không có bước reconcile state cũ hoặc validate logrotate -d trên cấu hình hợp nhất.

Q2 — Làm sao để vĩnh viễn không quay lại

  • Fix trực tiếp:
    • chọn một nguồn truth duy nhất cho mcp-health.log và config-integrity.log
    • loại bỏ duplicate rule ở source còn lại
  • Fix hệ thống:
    • mọi mission thay đổi /etc/logrotate.d/* phải chạy logrotate -d /etc/logrotate.conf
    • GitOps rollout cho /etc/* phải có bước "scan existing server files for overlapping targets"
    • thêm CI/pipeline guard cho manifest logrotate chứ không chỉ comment "Verify"

TD-3 — rsyslog omfile suspend

Tầng 1 — Hiện tượng

  • rsyslog.service vẫn active (running) nhưng liên tục:
    • action 'action-0-builtin:omfile' suspended
    • ... resumed
  • Earliest retained journal evidence:
    • Apr 01 00:00:00 ... kernel: [UFW BLOCK] ...
    • ngay sau đó là chuỗi omfile suspended/resumed

Tầng 2 — Cơ chế fail

  • 20-ufw.conf của package ufw cấu hình:
:msg,contains,"[UFW " /var/log/ufw.log
  • Evidence nguyên nhân trực tiếp:
Apr 05 00:00:39 ... kernel: [UFW BLOCK] ...
Apr 05 00:00:39 ... rsyslogd: file '/var/log/ufw.log': open error: Permission denied
Apr 05 00:00:39 ... action 'action-0-builtin:omfile' suspended
  • File đích hiện không tồn tại:
    • ls -lah /var/log/ufw.log* -> no_ufw_logs

Tầng 3 — Vì sao nó fail

  • /etc/rsyslog.d/20-ufw.conf là file package-managed bởi ufw, còn nguyên từ 2023-05-16.
  • Nhưng /var/log/ufw.log đã biến mất, và /var/log là:
    • drwxr-xr-x root syslog /var/log
  • Khi UFW block phát sinh, rsyslog cố ghi vào /var/log/ufw.log nhưng gặp:
    • open error: Permission denied

Tầng 4 — Có liên quan logrotate không

  • Có liên quan theo nghĩa cùng subsystem log, nhưng không phải cùng lỗi trực tiếp với duplicate logrotate.
  • Evidence quan trọng:
    • Apr 01 00:00:00: rsyslog omfile suspended xuất hiện trước
    • Apr 01 00:00:02: logrotate.service mới bắt đầu
  • Tuy vậy, Apr 05 cho thấy logrotate gửi SIGHUP cho rsyslog rồi ngay sau một UFW event, lỗi ufw.log lại bộc lộ. Tức là:
    • logrotate có thể retrigger/expose
    • nhưng gốc không phải duplicate logrotate

Tầng 5 — Gốc thật

Nguyên nhân sâu nhất là OS logging path của ufw bị drift: route /var/log/ufw.log vẫn còn trong rsyslog package config, nhưng logfile đích không còn và không có cơ chế bảo đảm tồn tại/quyền đúng; mỗi UFW event lại kích hoạt Permission denied rồi omfile suspend.

Q2 — Làm sao để vĩnh viễn không quay lại

  • Fix trực tiếp:
    • khôi phục/log-manage /var/log/ufw.log đúng quyền hoặc bỏ route nếu policy không dùng file này
    • verify rsyslog clean sau UFW event
  • Fix hệ thống:
    • thêm sanity check cho các omfile targets quan trọng (exists + owner + writable semantics)
    • sau mọi thay đổi logrotate/rsyslog hoặc image rebuild, chạy smoke check cho rsyslog outputs
    • đừng xem service active là đủ; cần alert khi journal có open error / omfile suspended

4. Gốc thật cho mỗi TD

  • TD-1: Nguyên nhân sâu nhất là hardening commit đã thay fallback bằng required env nhưng không có host-side env contract và monitor vòng 2.
  • TD-2: Nguyên nhân sâu nhất là hai nguồn config độc lập cùng quản lý một log target mà không có merged-config validation.
  • TD-3: Nguyên nhân sâu nhất là UFW log route còn sống nhưng logfile đích đã drift mất, khiến rsyslog fail ở mức file-open.

5. Đề xuất fix 2 lớp và thứ tự ưu tiên

Ưu tiên fix

  1. TD-1 Đ31 runner/watchdog
  2. TD-3 rsyslog ufw.log path
  3. TD-2 logrotate duplicate

Lý do: TD-1 làm mù lớp phát hiện ứng dụng; TD-3 làm nền logging rung lắc; TD-2 fail daily và cần xử lý cùng TD-3 để đóng log subsystem.

Đề xuất mission fix

  • Mission A: D31 runner + watchdog
    • Lớp 1: restore AGENT_DATA_URL cho host cron, thêm preflight
    • Lớp 2: thêm monitor vòng 2 cho watchdog-monitor hoặc runner heartbeat
  • Mission B: logging subsystem
    • Lớp 1: reconcile /etc/logrotate.d/* và khôi phục/chuẩn hóa /var/log/ufw.log
    • Lớp 2: thêm validate/smoke test cho logrotate + rsyslog outputs

Không nên gộp cả 3 TD vào 1 mission fix duy nhất; D31 và logging subsystem khác execution context, khác verify path, khác rollback surface.

6. Unknowns / Chưa đủ bằng chứng

  • TD-1: commit source đã rõ, nhưng chưa chứng minh được chính xác deploy job/người nào đưa thay đổi đó lên VPS trước slot 2026-04-02 12:00:02 CEST.
  • TD-2: chưa xác định được ai/tác vụ nào tạo hai standalone file /etc/logrotate.d/config-integrity và /etc/logrotate.d/mcp-health; chỉ chứng minh được chúng là ngoài repo và ngoài package manager.
  • TD-3: chưa xác định được khi nào /var/log/ufw.log biến mất; chỉ chứng minh được hiện tại nó không tồn tại và route của package ufw vẫn đang trỏ vào đó.

7. Appendix — Commands + outputs

A. D31 current cron + logs

ssh root@38.242.240.89 'date -Is; echo "---"; crontab -l'
ssh root@38.242.240.89 'tail -n 120 /opt/incomex/logs/integrity/watchdog.log; echo "---"; tail -n 120 /opt/incomex/logs/integrity/cron.log'
ssh root@38.242.240.89 'sed -n "1,40p" /opt/incomex/logs/integrity/cron-20260402-120002.log'
ssh root@38.242.240.89 'sed -n "1,20p" /opt/incomex/logs/integrity/cron-20260402-060001.log; echo "---"; tail -n 8 /opt/incomex/logs/integrity/cron-20260402-060001.log'

Key outputs:

0 */6 * * * /opt/incomex/deploys/web-test/scripts/integrity/cron-integrity.sh >> /opt/incomex/logs/integrity/cron.log 2>&1
0 * * * * /opt/incomex/deploys/web-test/scripts/integrity/watchdog-monitor.sh >> /opt/incomex/logs/integrity/watchdog.log 2>&1

WATCHDOG ALERT: Runner Điều 31 không chạy từ 2026-04-02T04:01:15.687Z

=== Điều 31 Cron — cron-20260402-120002 ===
Error: Missing required env: AGENT_DATA_URL

=== Điều 31 Cron — cron-20260402-060001 ===
WATCHDOG: alive
Results logged to measurement_log (run_id: cron-20260402-060001)

B. D31 source / git evidence

git show --patch d9217ca5d32622d2f6dd064da84a1c184bd516cb -- scripts/integrity/runners/sync-check.js
git blame -L 6,10 scripts/integrity/runners/sync-check.js
nl -ba scripts/integrity/cron-integrity.sh | sed -n '1,80p'
nl -ba infra/docker/docker-compose.yml | sed -n '84,92p'
ssh root@38.242.240.89 'grep -n "^AGENT_DATA_URL=\|^FLOWS_ENV_ALLOW_LIST=" /opt/incomex/docker/.env 2>/dev/null || true'

Key outputs:

const AGENT_DATA_URL = process.env.AGENT_DATA_URL;
if (!AGENT_DATA_URL) throw new Error('Missing required env: AGENT_DATA_URL');

d9217ca5 (Nguyễn Minh Huyên 2026-04-02 12:53:12 +0700  8) const AGENT_DATA_URL = process.env.AGENT_DATA_URL;
d9217ca5 (Nguyễn Minh Huyên 2026-04-02 12:53:12 +0700  9) if (!AGENT_DATA_URL) throw new Error('Missing required env: AGENT_DATA_URL');

FLOWS_ENV_ALLOW_LIST: "WEB_URL,AGENT_DATA_URL,AGENT_DATA_API_KEY"
AGENT_DATA_URL: http://agent-data:8000

=== .env AGENT_DATA_URL
---

C. logrotate evidence

ssh root@38.242.240.89 'systemctl status logrotate.service --no-pager -l'
ssh root@38.242.240.89 'logrotate -d /etc/logrotate.conf 2>&1 | sed -n "1,220p"'
ssh root@38.242.240.89 'grep -R -n "/var/log/config-integrity.log\|/var/log/mcp-health.log" /etc/logrotate.d /etc/logrotate.conf 2>/dev/null'
ssh root@38.242.240.89 'for f in /etc/logrotate.d/config-integrity /etc/logrotate.d/mcp-health /etc/logrotate.d/incomex; do echo "===== $f"; nl -ba "$f"; done'
ssh root@38.242.240.89 'dpkg -S /etc/logrotate.d/config-integrity /etc/logrotate.d/mcp-health 2>&1 || true'
ssh root@38.242.240.89 'journalctl -u logrotate.service --since "2026-03-28" --no-pager -l | sed -n "1,120p"'

Key outputs:

error: incomex:8 duplicate log entry for /var/log/config-integrity.log
error: mcp-health:1 duplicate log entry for /var/log/mcp-health.log

/etc/logrotate.d/config-integrity:1:/var/log/config-integrity.log {
/etc/logrotate.d/mcp-health:1:/var/log/mcp-health.log {
/etc/logrotate.d/incomex:8:/var/log/mcp-health.log
/etc/logrotate.d/incomex:9:/var/log/config-integrity.log

dpkg-query: no path found matching pattern /etc/logrotate.d/config-integrity
dpkg-query: no path found matching pattern /etc/logrotate.d/mcp-health

Mar 28 00:00:02 ... logrotate[2745173]: error: incomex:8 duplicate log entry for /var/log/config-integrity.log
Mar 28 00:00:02 ... logrotate[2745173]: error: mcp-health:1 duplicate log entry for /var/log/mcp-health.log

D. rsyslog evidence

ssh root@38.242.240.89 'systemctl status rsyslog.service --no-pager -l'
ssh root@38.242.240.89 'journalctl --since "2026-04-01 00:00:00" --until "2026-04-01 00:02:00" --no-pager -l | grep -E "logrotate.service|rsyslogd|UFW BLOCK|ufw.log"'
ssh root@38.242.240.89 'journalctl --since "2026-04-05 00:00:20" --until "2026-04-05 00:01:00" --no-pager -l | grep -E "logrotate.service|rsyslogd|UFW BLOCK|ufw.log"'
ssh root@38.242.240.89 'dpkg -S /etc/rsyslog.d/20-ufw.conf 2>&1 || true; echo "---"; cat /etc/rsyslog.d/20-ufw.conf'
ssh root@38.242.240.89 'ls -lah /var/log/ufw.log* 2>/dev/null || echo "no_ufw_logs"'
ssh root@38.242.240.89 'ls -ld /var/log'

Key outputs:

Apr 01 00:00:00 ... kernel: [UFW BLOCK] ...
Apr 01 00:00:00 ... rsyslogd ... action 'action-0-builtin:omfile' suspended
Apr 01 00:00:02 ... Starting logrotate.service

Apr 05 00:00:39 ... rsyslogd: file '/var/log/ufw.log': open error: Permission denied
Apr 05 00:00:39 ... action 'action-0-builtin:omfile' suspended

ufw: /etc/rsyslog.d/20-ufw.conf
:msg,contains,"[UFW " /var/log/ufw.log

no_ufw_logs
drwxr-xr-x 11 root syslog 4096 Apr  9 00:00 /var/log

E. Kuma / recursive blind spot

ssh root@38.242.240.89 "sqlite3 /opt/incomex/uptime-kuma/kuma.db \"select count(*) from monitor where name like '%watchdog%' or name like '%Điều 31%' or name like '%dieu31%';\""

Key output:

0