improvement(redis): pair lock acquire failures with connection state

A lock acquire is often a process's first Redis call, so an unusable
connection surfaces there as `Error: Command timed out` — a rejection
carrying only ioredis timer frames, no app frame, and nothing to separate a
handshake still in flight from a socket that died silently. `status` is what
separates them, so log it alongside the failure.

Read before the reclaim, which awaits and would otherwise report the state it
left behind rather than the one that failed.

Author: waleedlatif1

apps/sim/lib/core/config/redis.test.ts

@@ -1,12 +1,20 @@
 import { createMockRedis } from '@sim/testing'
 import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest'
 
-const { mockEnv, MockRedisConstructor } = vi.hoisted(() => ({
+const { mockEnv, MockRedisConstructor, mockLogger } = vi.hoisted(() => ({
   mockEnv: {
     REDIS_URL: 'redis://localhost:6379' as string | undefined,
     REDIS_TLS_SERVERNAME: undefined as string | undefined,
   },
   MockRedisConstructor: vi.fn(),
+  mockLogger: {
+    info: vi.fn(),
+    warn: vi.fn(),
+    error: vi.fn(),
+    debug: vi.fn(),
+    trace: vi.fn(),
+    fatal: vi.fn(),
+  },
 }))
 
 const mockRedisInstance = createMockRedis()
@@ -20,6 +28,15 @@ MockRedisConstructor.mockImplementation(
 
 vi.unmock('@/lib/core/config/redis')
 vi.mock('@/lib/core/config/env', () => ({ env: mockEnv }))
+/** Overrides the global mock, whose `createLogger` returns a fresh spy per call,
+ *  so assertions can reach the instance this module captured at import. */
+vi.mock('@sim/logger', () => ({
+  createLogger: () => mockLogger,
+  logger: mockLogger,
+  runWithRequestContext: <T>(_ctx: unknown, fn: () => T): T => fn(),
+  getRequestContext: () => undefined,
+  setRequestTraceId: () => {},
+}))
 vi.mock('ioredis', () => ({
   default: MockRedisConstructor,
 }))
@@ -383,6 +400,54 @@ describe('redis config', () => {
       expect(await acquireLock(lockKey, value, ttlSeconds)).toBe(true)
       expect(mockRedisInstance.set).not.toHaveBeenCalled()
     })
+
+    it('pairs the failure with connection state so the cause is not left to timing', async () => {
+      // The bare rejection carries only ioredis timer frames, so without this
+      // there is nothing to separate a handshake still in flight from a socket
+      // that died silently.
+      mockRedisInstance.status = 'connecting'
+      mockRedisInstance.set.mockRejectedValueOnce(new Error('Command timed out'))
+
+      await expect(acquireLock(lockKey, value, ttlSeconds)).rejects.toThrow('Command timed out')
+      expect(mockLogger.error).toHaveBeenCalledWith(
+        'Redis lock acquire failed',
+        expect.objectContaining({
+          lockKey,
+          error: 'Command timed out',
+          redis: expect.objectContaining({ status: 'connecting' }),
+        })
+      )
+    })
+
+    it('reads connection state before the reclaim, which resolves against a live socket', async () => {
+      // The reclaim awaits, so a connection that completes inside that window
+      // would leave a diagnostic read after it reporting `ready` — hiding the
+      // very handshake that failed.
+      mockRedisInstance.status = 'connecting'
+      mockRedisInstance.set.mockRejectedValueOnce(new Error('Command timed out'))
+      // Mutates the constructed client, not the shared instance it was copied from.
+      mockRedisInstance.eval.mockImplementationOnce(async () => {
+        Object.assign(getRedisClient() ?? {}, { status: 'ready' })
+        return 1
+      })
+
+      await expect(
+        acquireLock(lockKey, value, ttlSeconds, { reclaimOnFailure: true })
+      ).rejects.toThrow('Command timed out')
+      expect(mockLogger.error).toHaveBeenCalledWith(
+        'Redis lock acquire failed',
+        expect.objectContaining({ redis: expect.objectContaining({ status: 'connecting' }) })
+      )
+    })
+
+    it('stays quiet on the taken and contended paths, which poll routes run constantly', async () => {
+      mockRedisInstance.set.mockResolvedValueOnce('OK')
+      await acquireLock(lockKey, value, ttlSeconds)
+      mockRedisInstance.set.mockResolvedValueOnce(null)
+      await acquireLock(lockKey, value, ttlSeconds)
+
+      expect(mockLogger.error).not.toHaveBeenCalled()
+    })
   })
 
   describe('capability validation', () => {

apps/sim/lib/core/config/redis.ts

@@ -406,6 +406,20 @@ export async function acquireLock(
     const result = await redis.set(lockKey, value, 'EX', expirySeconds, 'NX')
     return result === 'OK'
   } catch (error) {
+    /**
+     * Read the connection state before the reclaim below, which awaits and so
+     * would report the state it left behind rather than the one that failed.
+     * A lock acquire is often a run's first Redis call, so it is where an
+     * unusable connection surfaces — as an `Error: Command timed out` carrying
+     * only ioredis timer frames, no app frame, and no way to tell a handshake
+     * still in flight from a socket that died silently. `status` separates
+     * them, which is what makes the next occurrence self-diagnosing.
+     */
+    logger.error('Redis lock acquire failed', {
+      lockKey,
+      error: toError(error).message,
+      redis: describeRedisConnection(),
+    })
     // Best effort, and the same compare-and-delete `releaseLock` runs on the
     // success path: it deletes only while `value` still owns the key. If Redis
     // is still unreachable the TTL stays the backstop, which is the behavior