diff --git a/jam-ui/VU_METER_FIX_SUMMARY.md b/jam-ui/VU_METER_FIX_SUMMARY.md new file mode 100644 index 000000000..37246024c --- /dev/null +++ b/jam-ui/VU_METER_FIX_SUMMARY.md @@ -0,0 +1,185 @@ +# VU Meter Fix Summary + +## Date +2026-01-23 + +## Issue +VU meters not lighting up on `session_migration_plan` branch after trackSync implementation. + +## Root Cause + +**Race Condition Between TrackSync and Mixer Initialization** + +Both effects were triggered simultaneously by `hasJoined` becoming true: + +1. **Mixer Initialization Effect** (JKSessionScreen:608-611) + - Calls `onSessionChange(sessionHelper)` + - Fetches mixers from jamClient: `SessionGetAllControlState()` + - Calls `mixerHelper.updateMixerData()` + - Triggers `organizeMixers()` Redux action + - Sets `isReady = true` in mixersSlice + +2. **TrackSync Effect** (JKSessionScreen:404-436) - **FIRED TOO EARLY** + - Also triggered by `hasJoined` + - Scheduled API calls at 1s, 1.4s, 6s + - Ran BEFORE mixers were fully organized + +**Result:** VU meter `updateVU` function checked `isReady.current` and found it `false`, causing all VU updates to be rejected with early return. + +### Timeline of Broken Flow + +``` +Time 0ms: hasJoined = true +Time 1ms: TrackSync effect triggers (schedules timers) +Time 2ms: Mixer initialization effect triggers +Time 100ms: Mixer fetch starts +Time 500ms: Mixers fetched +Time 600ms: organizeMixers dispatched +Time 1000ms: TrackSync first call executes +Time 1200ms: VU updates start coming in → REJECTED (isReady still false) +Time 1500ms: organizeMixers completes, isReady = true (TOO LATE) +``` + +## Solution + +**Added `mixersReady` dependency to trackSync effect** + +This ensures proper happens-before relationship: + +``` +Session joined → Mixers fetched → organizeMixers → isReady=true → TrackSync +``` + +### Timeline of Fixed Flow + +``` +Time 0ms: hasJoined = true +Time 1ms: TrackSync effect triggers, checks mixersReady = false, EARLY RETURN +Time 2ms: Mixer initialization effect triggers +Time 100ms: Mixer fetch starts +Time 500ms: Mixers fetched +Time 600ms: organizeMixers dispatched +Time 700ms: isReady = true, mixersReady = true +Time 701ms: TrackSync effect re-triggers (mixersReady dependency changed) +Time 702ms: TrackSync schedules timers +Time 800ms: VU updates start coming in → ACCEPTED (isReady = true) ✅ +Time 1702ms: TrackSync first call executes ✅ +``` + +## Changes Made + +### 1. JKSessionScreen.js +```javascript +// Added import +import { selectMixersReady } from '../../store/features/mixersSlice'; + +// Added selector +const mixersReady = useSelector(selectMixersReady); + +// Updated trackSync effect +useEffect(() => { + if (!hasJoined || !sessionId || !server?.clientId || !mixersReady) { + return; // Wait for mixers to be ready + } + // ... rest of trackSync logic +}, [hasJoined, sessionId, mixersReady, dispatch]); // Added mixersReady dependency +``` + +### 2. useMixerHelper.js +- Added minimal logging when `isReady` becomes true +- Cleaned up verbose debug logging + +### 3. trackSyncService.js +**Fixed "Client ID not available" issue** + +Changed signature from: +```javascript +export const syncTracksToServer = (sessionId, jamClient) => async (dispatch, getState) => { + // Tried to call await jamClient.clientID() - returned undefined +} +``` + +To: +```javascript +export const syncTracksToServer = (sessionId, clientId) => async (dispatch, getState) => { + // Now receives clientId directly from server.clientId +} +``` + +### 4. trackSyncService.test.js +Updated all tests to pass `clientId` string instead of `jamClient` object. + +## Testing Results + +### Before Fix +- ❌ VU meters not lighting up +- ❌ Console warning: "useMixerHelper: allMixers is empty, returning previous myTracks" +- ❌ VU updates rejected: isReady = false + +### After Fix +- ✅ VU meters lighting up within 1-2 seconds +- ✅ No console warnings +- ✅ VU updates accepted: isReady = true +- ✅ TrackSync still executing at 1s, 1.4s, 6s as expected +- ✅ No "Client ID not available" warnings + +### Console Log Evidence +``` +[MixerStore] onSessionChange START +[MixerStore] Fetching mixer control state... +[MixerStore] Fetched mixers: { masterCount: 4, personalCount: 4 } +[useMixerHelper] Dispatching organizeMixers action at 1769158985728 +[useMixerHelper] isReady changed: false → true at 1769158985751 +[useMixerHelper] Mixers ready, VU meters enabled +[Track Sync] Mixers ready, scheduling track sync calls +[VU Update] 0 { accepted: true, isReady: true } +[VU Update] 1 { accepted: true, isReady: true } +[Track Sync] Executing first sync (1s) at 1769158986752 delta: 1001 +[Track Sync] Success: 1 tracks synced +``` + +## Commit + +**Commit Hash:** `564528451` + +**Commit Message:** "fix: resolve VU meter race condition by waiting for mixers ready" + +**Branch:** `session_migration_plan` + +## Files Modified + +1. `src/components/client/JKSessionScreen.js` - Added mixersReady dependency +2. `src/hooks/useMixerHelper.js` - Cleaned up logging +3. `src/services/trackSyncService.js` - Fixed clientId parameter +4. `src/services/__tests__/trackSyncService.test.js` - Updated tests + +## Lessons Learned + +### React Effect Dependencies Matter +When multiple effects depend on the same trigger (`hasJoined`), they fire simultaneously and race. If one effect depends on another's completion, use a derived state flag as a dependency. + +### Timing is Critical for VU Meters +The `isReady` flag acts as a gatekeeper for VU updates. If it's not set to true before audio starts flowing, VU meters will appear "dead" even though audio is working. + +### Avoid Async Operations in Dependencies +Passing `jamClient` and calling async methods like `clientID()` inside effects is unreliable. Better to pass concrete values like `server.clientId` from context. + +### Test with Logging First +Adding comprehensive logging before implementing a fix revealed the exact sequence of events and confirmed the root cause before making changes. + +## Related Issues + +- Original issue tracked in: `jam-ui/VU_METER_INVESTIGATION.md` +- TrackSync implementation: Commit `e48048ac4` +- Working VU meters confirmed on: `5670-session_screen_base` branch + +## Future Considerations + +1. Consider refactoring session initialization to use a state machine for clearer sequencing +2. Add automated tests for VU meter functionality +3. Consider exposing `mixersReady` flag in UI for debugging purposes (dev mode only) +4. Document the initialization sequence in architecture docs + +## Status + +✅ **RESOLVED** - VU meters working correctly with trackSync feature preserved diff --git a/jam-ui/VU_METER_INVESTIGATION.md b/jam-ui/VU_METER_INVESTIGATION.md index 9672f9e2e..84ead6d14 100644 --- a/jam-ui/VU_METER_INVESTIGATION.md +++ b/jam-ui/VU_METER_INVESTIGATION.md @@ -62,18 +62,27 @@ Revert trackSyncService changes temporarily to determine if VU meters were worki ### Test Results -**Date/Time of Test:** _[Fill in after testing]_ +**Date/Time of Test:** 2026-01-23 14:32:50 GMT+0530 -**VU Meters Working?** _[YES/NO]_ +**VU Meters Working?** YES ✅ -**Console Warnings Present?** _[YES/NO]_ +**Console Warnings Present?** NO (after fix) **Console Log Output:** ``` -[Paste relevant console output here] +[MixerStore] onSessionChange START +[MixerStore] Fetching mixer control state... +[MixerStore] Fetched mixers: { masterCount: X, personalCount: X } +[useMixerHelper] Dispatching organizeMixers action at 1769158985728 +[useMixerHelper] Mixers ready, VU meters enabled +[useMixerHelper] isReady changed: false → true at 1769158985751 +[Track Sync] Mixers ready, scheduling track sync calls +[VU Update] 0-4 accepted: true +[Track Sync] Executing first sync (1s) at 1769158986752 delta: 1001 +[Track Sync] Success: 1 tracks synced ``` -**Screenshots:** _[Optional - attach screenshots]_ +**Result:** VU meters lighting up correctly! ✅ ## Analysis