FKITDEV-8521: Fix invalid wait times
PR Context Brief
Single commit
54001f0oncustomization/nusz. Fixes phantom 3-hour waiting times in operator dashboard caused by 3 interacting bugs in vuer_ossCustomerService.
Origin
SLAMKB-17 — MKB reported a phantom 3h waiting time in weekly reports (week 27). Customer 88349 had unstable internet, kept disconnecting/reconnecting to the waiting room. The server cached the original stale timestamp and never updated it.
Changes
| File | Delta |
|---|---|
server/service/CustomerService.js | +30 / -2 |
test/tests/unit/services/customer-service.test.js | +366 (new) |
3 Bugs Fixed
1. Null cache poisoning
userWaitingHistory.set(id, null) permanently poisoned the cache — has() returned true, so the DB was never re-queried. Fix: only cache valid records.
2. Overly broad LIKE
%waiting-room% matched waiting-room-exit too. Fix: tightened to %"page":"waiting-room"%.
3. Stale cache (race condition)
Cache only updated on poll interval. If customer reconnected between polls, stale timestamp persisted. Fix: new customerHistory:updated event listener instantly refreshes cache on reconnect.
Review Focus
- Event listener guard clauses (constructor) — null, type, line membership, content.page exact match
- LIKE pattern — will
%"page":"waiting-room"%break on JSON with spaces in keys? (Sequelize serializes without spaces, so this is safe)- Cache logic —
has()vsget()still correct when entry doesn’t exist (yes —has()returns false, falls through to DB query)
Test Coverage
366 lines covering: null caching prevention, cache invalidation on line exit, event listener guard clauses (7 cases), LIKE pattern specificity, cache-then-requery flow.
Room 53695: Bug vs Fix Flow
The core issue: when a customer re-enters the waiting room, the fast RPC path (join-waiting-room) wins a race against the slower queue-based pagevisit DB write. The poll reads stale/empty data and caches it permanently.
Old Code (Buggy)
Bug: Poll reads stale data, caches it permanently. Dashboard shows ~2h phantom wait.
sequenceDiagram participant C as Customer participant OSS as vuer_oss participant DB as PostgreSQL participant Cache as Cache Note over C,Cache: Session 1: normal Note over C: auth.js:36 → pagevisit.js:6 → CustomerHistory.js:4 C->>DB: pageVisit {page: "waiting-room"} 09:48 Note over C: Room 53610 (09:57-09:59) Note over OSS: CustomerService.js:201 — line cleanup OSS->>Cache: delete (cleanup) Note over C: waiting-room-exit.template.twig:2 C->>DB: pageVisit {page: "waiting-room-exit"} 09:59 Note over C,Cache: Session 2: re-enters queue par RPC (fast) — WaitingRoomService.js OSS->>OSS: addToLine → poll triggers and Queue (slow) — queue_server/CustomerHistory.js:22 Note over DB: pageVisit write pending... end rect rgba(255, 200, 200, 0.3) Note over OSS,DB: BUG: CustomerService.js:211 — LIKE too broad OSS->>DB: SELECT ... LIKE '%waiting-room%' alt matches waiting-room-exit DB-->>OSS: createdAt: 09:59 (wrong record!) Note over OSS: CustomerService.js:264 — caches stale OSS->>Cache: set(id, 09:59) else no match yet DB-->>OSS: null Note over OSS: CustomerService.js:264 — caches null OSS->>Cache: set(id, null) end Note over Cache: Cache poisoned — never re-queried end Note over DB: customerhistory.js:114 — afterSave fires Note over OSS: No listener in old code! Note over DB: write completes {page: "waiting-room"} 10:00 Note over Cache: Correct record exists but cache ignores it rect rgba(255, 200, 200, 0.3) Note over OSS: CustomerService.js:260 — reads from cache OSS->>Cache: get(id) Cache-->>OSS: 09:59 or null Note over OSS: Dashboard: ~2h wait (actual ~5min) end
New Code (Fixed)
Fix: (1) no null caching, (2) exact LIKE match, (3) afterSave event updates cache instantly.
sequenceDiagram participant C as Customer participant OSS as vuer_oss participant DB as PostgreSQL participant Cache as Cache Note over C,Cache: Session 1: same as before Note over C: auth.js:36 → pagevisit.js:6 → CustomerHistory.js:4 C->>DB: pageVisit {page: "waiting-room"} 09:48 Note over C: Room 53610 (09:57-09:59) Note over OSS: CustomerService.js:201 — line cleanup OSS->>Cache: delete (cleanup) Note over C: waiting-room-exit.template.twig:2 C->>DB: pageVisit {page: "waiting-room-exit"} 09:59 Note over C,Cache: Session 2: re-enters queue par RPC (fast) — WaitingRoomService.js OSS->>OSS: addToLine → poll triggers and Queue (slow) — queue_server/CustomerHistory.js:22 Note over DB: pageVisit write pending... end rect rgb(220, 245, 220) Note over OSS,DB: FIX #2: CustomerService.js:235 — exact LIKE OSS->>DB: SELECT ... LIKE '%"page":"waiting-room"%' DB-->>OSS: empty (exit page excluded!) Note over OSS: FIX #1: CustomerService.js:287 — skip null cache Note over Cache: has(id) = false → will retry next poll end rect rgb(200, 240, 200) Note over DB: customerhistory.js:114 — afterSave fires DB->>OSS: emit customerHistory:updated Note over OSS: FIX #3: CustomerService.js:33-55 — event listener OSS->>OSS: type=pageVisit ✓ inLine ✓ page=waiting-room ✓ OSS->>Cache: set(id, 10:00) Note over Cache: Instantly correct! end rect rgb(180, 235, 180) Note over OSS: CustomerService.js:260 — reads from cache OSS->>Cache: get(id) Cache-->>OSS: 10:00 ✓ Note over OSS: Dashboard: actual wait time end
Code Pointers
| Fix | What | File | Line(s) |
|---|---|---|---|
| #1 | No null caching | server/service/CustomerService.js | L287-289 |
| #2 | Tighter LIKE pattern | server/service/CustomerService.js | L235 |
| #3 | Real-time cache update listener | server/service/CustomerService.js | L33-55 |
pageVisit creation chain (the “slow path”):
| Step | File | Line(s) |
|---|---|---|
| Template sets page ID | vuer_css/.../waiting-room.template.twig | L3 |
| Exit page ID | vuer_css/.../waiting-room-exit.template.twig | L2 |
| Client emits socket event | vuer_css/client/features/auth.js | L36 |
| CSS queue client → RabbitMQ | vuer_css/server/queue/queue_client/CustomerHistory.js | L4-6 |
| OSS queue server receives | vuer_oss/server/queue/queue_server/CustomerHistory.js | L22-31 |
afterSave hook emits event | vuer_oss/server/db/model/customerhistory.js | L114-116 |
Tests: test/tests/unit/services/customer-service.test.js (366 lines, new file)