FKITDEV-8521: Fix invalid wait times

PR Context Brief

Single commit 54001f0 on customization/nusz. Fixes phantom 3-hour waiting times in operator dashboard caused by 3 interacting bugs in vuer_oss CustomerService.

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

FileDelta
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 logichas() vs get() 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

FixWhatFileLine(s)
#1No null cachingserver/service/CustomerService.jsL287-289
#2Tighter LIKE patternserver/service/CustomerService.jsL235
#3Real-time cache update listenerserver/service/CustomerService.jsL33-55

pageVisit creation chain (the “slow path”):

StepFileLine(s)
Template sets page IDvuer_css/.../waiting-room.template.twigL3
Exit page IDvuer_css/.../waiting-room-exit.template.twigL2
Client emits socket eventvuer_css/client/features/auth.jsL36
CSS queue client → RabbitMQvuer_css/server/queue/queue_client/CustomerHistory.jsL4-6
OSS queue server receivesvuer_oss/server/queue/queue_server/CustomerHistory.jsL22-31
afterSave hook emits eventvuer_oss/server/db/model/customerhistory.jsL114-116

Tests: test/tests/unit/services/customer-service.test.js (366 lines, new file)