From 84b94a62d746d832e0fff2e59db926d1d6a17bba Mon Sep 17 00:00:00 2001 From: Michael Kochell <6913320+mickmister@users.noreply.github.com> Date: Thu, 11 Sep 2025 01:13:51 -0400 Subject: [PATCH 1/4] improve midi poller memory usage. add debug logs --- .../services/node/node_midi/midi_poller.ts | 112 +++++++++-- .../core/services/node/node_midi_service.ts | 184 +++++++++++++----- 2 files changed, 234 insertions(+), 62 deletions(-) diff --git a/packages/jamtools/core/services/node/node_midi/midi_poller.ts b/packages/jamtools/core/services/node/node_midi/midi_poller.ts index 0e0b913c..26208fed 100644 --- a/packages/jamtools/core/services/node/node_midi/midi_poller.ts +++ b/packages/jamtools/core/services/node/node_midi/midi_poller.ts @@ -23,14 +23,35 @@ interface NodeMidiDevicePoller { export class NodeMidiDevicePollerService { private poller!: NodeMidiDevicePoller; + private isUsingAmidi = false; + private debugLoggingEnabled = process.env.ENABLE_MIDI_POLLER_DEBUG_LOGGING === 'true'; + + private logDebug = (message: string, ...args: any[]) => { + if (this.debugLoggingEnabled) { + console.log(message, ...args); + } + }; public initialize = async () => { + this.logDebug('[MidiPoller] Initializing NodeMidiDevicePollerService...'); const amidiSupported = await AMidiDevicePoller.isSupported(); + this.isUsingAmidi = amidiSupported; + this.logDebug(`[MidiPoller] AMidi supported: ${amidiSupported}, using ${amidiSupported ? 'AMidiDevicePoller' : 'EasyMidiDevicePoller'}`); this.poller = amidiSupported ? new AMidiDevicePoller() : new EasyMidiDevicePoller(); }; public pollForDevices = async (knownDevices: string[]): Promise => { - const polledDevices = (await this.poller.poll()).filter(d => !d.humanReadableName.startsWith('Midi Through') && !d.humanReadableName.includes('RtMidi')); + this.logDebug(`[MidiPoller] Starting poll. Known devices: ${knownDevices.length}`); + this.logDebug(`[MidiPoller] Known device names: ${JSON.stringify(knownDevices)}`); + + const startTime = Date.now(); + const allPolledDevices = await this.poller.poll(); + const pollTime = Date.now() - startTime; + this.logDebug(`[MidiPoller] Poll completed in ${pollTime}ms. Found ${allPolledDevices.length} total devices`); + + const polledDevices = allPolledDevices.filter(d => !d.humanReadableName.startsWith('Midi Through') && !d.humanReadableName.includes('RtMidi')); + this.logDebug(`[MidiPoller] After filtering: ${polledDevices.length} devices`); + const newlyConnectedDevices: DeviceMetadata[] = []; const newlyDisconnectedDevices: DeviceMetadata[] = []; @@ -55,28 +76,41 @@ export class NodeMidiDevicePollerService { } }); - if (newlyConnectedDevices.length) { + if (newlyConnectedDevices.length && !this.isUsingAmidi) { + this.logDebug('[MidiPoller] Processing newly connected devices with EasyMidi for machine-readable names...'); + // Only use easymidi for machine-readable names if not using AMidi let inputs: string[] | undefined; let outputs: string[] | undefined; for (const device of newlyConnectedDevices) { + this.logDebug(`[MidiPoller] Processing device: ${device.humanReadableName} (input: ${device.input}, output: ${device.output})`); if (device.input) { if (!inputs) { + this.logDebug('[MidiPoller] Getting EasyMidi inputs...'); + const startTime = Date.now(); inputs = easymidi.getInputs(); + this.logDebug(`[MidiPoller] EasyMidi.getInputs() took ${Date.now() - startTime}ms`); + this.logDebug(`[MidiPoller] EasyMidi inputs: ${JSON.stringify(inputs)}`); } const foundInput = inputs.find(deviceName => deviceName.startsWith(device.humanReadableName)); if (foundInput) { + this.logDebug(`[MidiPoller] Found machine-readable name for input: ${foundInput}`); device.machineReadableName = foundInput; continue; } } if (device.output) { if (!outputs) { + this.logDebug('[MidiPoller] Getting EasyMidi outputs...'); + const startTime = Date.now(); outputs = easymidi.getOutputs(); + this.logDebug(`[MidiPoller] EasyMidi.getOutputs() took ${Date.now() - startTime}ms`); + this.logDebug(`[MidiPoller] EasyMidi outputs: ${JSON.stringify(outputs)}`); } const foundOutput = outputs.find(deviceName => deviceName.startsWith(device.humanReadableName)); if (foundOutput) { + this.logDebug(`[MidiPoller] Found machine-readable name for output: ${foundOutput}`); device.machineReadableName = foundOutput; continue; } @@ -84,14 +118,30 @@ export class NodeMidiDevicePollerService { } } + this.logDebug(`[MidiPoller] Poll complete. Newly connected: ${newlyConnectedDevices.length}, Newly disconnected: ${newlyDisconnectedDevices.length}`); + if (newlyConnectedDevices.length > 0) { + this.logDebug('[MidiPoller] Newly connected devices:', JSON.stringify(newlyConnectedDevices, null, 2)); + } + if (newlyDisconnectedDevices.length > 0) { + this.logDebug('[MidiPoller] Newly disconnected devices:', JSON.stringify(newlyDisconnectedDevices, null, 2)); + } return {newlyConnectedDevices, newlyDisconnectedDevices}; }; } class EasyMidiDevicePoller implements NodeMidiDevicePoller { public async poll(): Promise { + console.log('[EasyMidiPoller] Starting poll...'); + const inputStartTime = Date.now(); const inputs = easymidi.getInputs(); + const inputTime = Date.now() - inputStartTime; + console.log(`[EasyMidiPoller] getInputs() took ${inputTime}ms, found ${inputs.length} inputs`); + + const outputStartTime = Date.now(); const outputs = easymidi.getOutputs(); + const outputTime = Date.now() - outputStartTime; + console.log(`[EasyMidiPoller] getOutputs() took ${outputTime}ms, found ${outputs.length} outputs`); + const devices: DeviceMetadata[] = []; const allDeviceNames = Array.from(new Set(inputs.concat(outputs))); @@ -113,11 +163,29 @@ class EasyMidiDevicePoller implements NodeMidiDevicePoller { } class AMidiDevicePoller implements NodeMidiDevicePoller { + private debugLoggingEnabled = process.env.ENABLE_MIDI_POLLER_DEBUG_LOGGING === 'true'; + + private logDebug = (message: string, ...args: any[]) => { + if (this.debugLoggingEnabled) { + console.log(message, ...args); + } + }; + static async isSupported(): Promise { + const debugLoggingEnabled = process.env.ENABLE_MIDI_POLLER_DEBUG_LOGGING === 'true'; try { + if (debugLoggingEnabled) { + console.log('[AMidiPoller] Checking if amidi is available...'); + } await execPromise('amidi -l'); + if (debugLoggingEnabled) { + console.log('[AMidiPoller] amidi is supported on this system'); + } return true; - } catch { + } catch (error) { + if (debugLoggingEnabled) { + console.log('[AMidiPoller] amidi is not available:', error instanceof Error ? error.message : 'Unknown error'); + } return false; } } @@ -129,10 +197,16 @@ class AMidiDevicePoller implements NodeMidiDevicePoller { // if (this.forceNoMidiDevices) { // return []; // } + this.logDebug('[AMidiPoller] Starting poll...'); try { + const amidiStartTime = Date.now(); const amidiOutput = await this.getAmidiDevices(); + this.logDebug(`[AMidiPoller] getAmidiDevices() took ${Date.now() - amidiStartTime}ms`); + + const aseqStartTime = Date.now(); const aseqOutput = await this.getAseqHumanReadableNames(); + this.logDebug(`[AMidiPoller] getAseqHumanReadableNames() took ${Date.now() - aseqStartTime}ms`); for (const device of amidiOutput) { const humanReadableName = aseqOutput.get(device.machineReadableName); @@ -141,41 +215,54 @@ class AMidiDevicePoller implements NodeMidiDevicePoller { } } + this.logDebug(`[AMidiPoller] Poll complete. Found ${amidiOutput.length} devices`); return amidiOutput; } catch (err) { - console.error('Failed to poll MIDI devices using amidi and aseqdump', err); + console.error('[AMidiPoller] Failed to poll MIDI devices using amidi and aseqdump', err); return []; } }; private getAmidiDevices = async (): Promise => { + this.logDebug('[AMidiPoller] Executing: amidi -l'); const {stdout} = await execPromise('amidi -l'); + this.logDebug('[AMidiPoller] Raw amidi output:', stdout); const devices: DeviceMetadata[] = []; const lines = stdout.split('\n').filter(line => line.trim() !== '').slice(1); + this.logDebug(`[AMidiPoller] Processing ${lines.length} device lines...`); lines.forEach(line => { - const [dir, _portName, ...clientNameParts] = line.split(' ').filter(Boolean); - const name = clientNameParts.join(' '); - - if (devices.find(d => d.machineReadableName === name)) { + const [dir, portName, ...clientNameParts] = line.split(' ').filter(Boolean); + const clientName = clientNameParts.join(' '); + + // Use the full name (e.g., "hw:1,0,0 USB Midi Cable") as machine-readable + // This matches what easymidi would return + const fullName = `${portName} ${clientName}`; + + if (devices.find(d => d.machineReadableName === fullName)) { return; } - devices.push({ - humanReadableName: name, - machineReadableName: name, + const device = { + humanReadableName: clientName, + machineReadableName: fullName, input: dir.includes('I'), output: dir.includes('O'), - }); + }; + this.logDebug(`[AMidiPoller] Adding device: ${JSON.stringify(device)}`); + devices.push(device); }); return devices; }; private getAseqHumanReadableNames = async (): Promise> => { + this.logDebug('[AMidiPoller] Executing: aseqdump -l'); const {stdout} = await execPromise('aseqdump -l'); + this.logDebug('[AMidiPoller] Raw aseqdump output:', stdout); const humanReadableMap = new Map(); const lines = stdout.split('\n').filter(line => line.trim() !== '').slice(1); + this.logDebug(`[AMidiPoller] Processing ${lines.length} aseqdump lines...`); lines.forEach((line) => { if (line.trim() === '' || line.includes('Client name')) { @@ -187,6 +274,7 @@ class AMidiDevicePoller implements NodeMidiDevicePoller { const portNamePart = line.slice(37).trim(); humanReadableMap.set(portNamePart.trim(), clientPart.trim()); + this.logDebug(`[AMidiPoller] Mapped: '${portNamePart.trim()}' -> '${clientPart.trim()}'`); }); return humanReadableMap; diff --git a/packages/jamtools/core/services/node/node_midi_service.ts b/packages/jamtools/core/services/node/node_midi_service.ts index a5eb1b4a..76783822 100644 --- a/packages/jamtools/core/services/node/node_midi_service.ts +++ b/packages/jamtools/core/services/node/node_midi_service.ts @@ -16,9 +16,21 @@ export class NodeMidiService implements MidiService { public onInputEvent = new Subject(); private initialized = false; + private consecutiveErrors = 0; + private basePollInterval = 10000; // 10 seconds + private maxPollInterval = 60000; // 60 seconds maximum + private debugLoggingEnabled = process.env.ENABLE_MIDI_POLLER_DEBUG_LOGGING === 'true'; + + private logDebug = (message: string, ...args: any[]) => { + if (this.debugLoggingEnabled) { + console.log(message, ...args); + } + }; public initialize = async () => { + this.logDebug('[NodeMidiService] Initializing...'); await this.pollService.initialize(); + this.logDebug('[NodeMidiService] Starting device polling...'); await this.pollForConnectedDevices(); }; @@ -32,7 +44,9 @@ export class NodeMidiService implements MidiService { private initializeMidiInputDevice = (inputName: string) => { inputName = inputName.trim(); + this.logDebug(`[NodeMidiService] Attempting to initialize MIDI input: ${inputName}`); if (this.errorDevices.includes(inputName)) { + this.logDebug(`[NodeMidiService] Skipping ${inputName} - previously failed`); return; } @@ -45,7 +59,11 @@ export class NodeMidiService implements MidiService { this.inputs = [...this.inputs.slice(0, existingInputIndex), ...this.inputs.slice(existingInputIndex + 1)]; } + this.logDebug(`[NodeMidiService] Creating easymidi.Input for ${inputName}...`); + const startTime = Date.now(); const input = new easymidi.Input(inputName); + const createTime = Date.now() - startTime; + this.logDebug(`[NodeMidiService] Created input in ${createTime}ms`); const publishMidiEvent = (event: MidiEvent) => { const fullEvent: MidiEventFull = { @@ -99,17 +117,26 @@ export class NodeMidiService implements MidiService { }); this.inputs.push(input); - // console.log('initialized midi input:', input.name); + this.logDebug(`[NodeMidiService] Successfully initialized MIDI input: ${input.name}. Total inputs: ${this.inputs.length}`); } catch (e) { - console.error('failed to initialize midi input device', inputName); + const error = e as Error; + console.error('failed to initialize midi input device', inputName, error.message); + + // Check if it's a memory allocation error specifically + if (error.message.includes('Cannot allocate memory') || error.message.includes('Failed to initialise RtMidi')) { + console.warn('Memory allocation failed for MIDI device. Consider reducing polling frequency or restarting service.'); + } + this.errorDevices.push(inputName); } }; private initializeMidiOutputDevice = (outputName: string) => { outputName = outputName.trim(); + this.logDebug(`[NodeMidiService] Attempting to initialize MIDI output: ${outputName}`); if (this.errorDevices.includes(outputName)) { + this.logDebug(`[NodeMidiService] Skipping ${outputName} - previously failed`); return; } @@ -122,11 +149,23 @@ export class NodeMidiService implements MidiService { this.outputs = [...this.outputs.slice(0, existingOutputIndex), ...this.outputs.slice(existingOutputIndex + 1)]; } + this.logDebug(`[NodeMidiService] Creating easymidi.Output for ${outputName}...`); + const startTime = Date.now(); const output = new easymidi.Output(outputName); + const createTime = Date.now() - startTime; + this.logDebug(`[NodeMidiService] Created output in ${createTime}ms`); + this.outputs.push(output); - // console.log('initialized midi output:', output.name); + this.logDebug(`[NodeMidiService] Successfully initialized MIDI output: ${output.name}. Total outputs: ${this.outputs.length}`); } catch (e) { - console.error('failed to initialize midi output device', outputName); + const error = e as Error; + console.error('failed to initialize midi output device', outputName, error.message); + + // Check if it's a memory allocation error specifically + if (error.message.includes('Cannot allocate memory') || error.message.includes('Failed to initialise RtMidi')) { + console.warn('Memory allocation failed for MIDI device. Consider reducing polling frequency or restarting service.'); + } + this.errorDevices.push(outputName); } }; @@ -170,61 +209,106 @@ export class NodeMidiService implements MidiService { } }; - private pollForConnectedDevices = async () => { - const knownDevices = Array.from(new Set(this.inputs.map(i => i.name).concat(this.outputs.map(o => o.name)))); - const result = await this.pollService.pollForDevices(knownDevices); - - for (const device of result.newlyConnectedDevices) { - if (device.input) { - this.initializeMidiInputDevice(device.machineReadableName); - } - if (device.output) { - this.initializeMidiOutputDevice(device.machineReadableName); - } - } + private getMemoryUsage = (): number => { + const usage = process.memoryUsage(); + return usage.heapUsed / 1024 / 1024; // MB + }; - for (const device of result.newlyDisconnectedDevices) { - if (device.input) { - const index = this.inputs.findIndex(d => d.name === device.machineReadableName); - if (index !== -1) { - this.inputs[index].close(); - this.inputs = [...this.inputs.slice(0, index), ...this.inputs.slice(index + 1)]; + private pollForConnectedDevices = async () => { + this.logDebug('[NodeMidiService] === Starting device poll cycle ==='); + try { + const memoryBefore = this.getMemoryUsage(); + console.log(`[NodeMidiService] Memory before polling: ${memoryBefore.toFixed(1)} MB`); + + const knownDevices = Array.from(new Set(this.inputs.map(i => i.name).concat(this.outputs.map(o => o.name)))); + this.logDebug(`[NodeMidiService] Current known devices: ${knownDevices.length}`); + + const pollStartTime = Date.now(); + const result = await this.pollService.pollForDevices(knownDevices); + const pollDuration = Date.now() - pollStartTime; + this.logDebug(`[NodeMidiService] Poll completed in ${pollDuration}ms`); + + const memoryAfter = this.getMemoryUsage(); + console.log(`[NodeMidiService] Memory after polling: ${memoryAfter.toFixed(1)} MB (delta: ${(memoryAfter - memoryBefore).toFixed(1)} MB)`); + + this.logDebug(`[NodeMidiService] Processing ${result.newlyConnectedDevices.length} newly connected devices...`); + for (const device of result.newlyConnectedDevices) { + this.logDebug(`[NodeMidiService] New device: ${device.humanReadableName} (machine: ${device.machineReadableName})`); + if (device.input) { + this.initializeMidiInputDevice(device.machineReadableName); } - } - if (device.output) { - const index = this.outputs.findIndex(d => d.name === device.machineReadableName); - if (index !== -1) { - this.outputs[index].close(); - this.outputs = [...this.outputs.slice(0, index), ...this.outputs.slice(index + 1)]; + if (device.output) { + this.initializeMidiOutputDevice(device.machineReadableName); } } - } - if (result.newlyConnectedDevices.length || result.newlyDisconnectedDevices.length) { - if (this.initialized) { - for (const device of result.newlyConnectedDevices) { - this.onDeviceStatusChange.next({ - manufacturer: '', - name: device.humanReadableName, - status: 'connected', - subtype: 'midi_input', - type: 'midi', - }); + this.logDebug(`[NodeMidiService] Processing ${result.newlyDisconnectedDevices.length} disconnected devices...`); + for (const device of result.newlyDisconnectedDevices) { + this.logDebug(`[NodeMidiService] Disconnected device: ${device.humanReadableName}`); + if (device.input) { + const index = this.inputs.findIndex(d => d.name === device.machineReadableName); + if (index !== -1) { + this.logDebug(`[NodeMidiService] Closing input: ${this.inputs[index].name}`); + this.inputs[index].close(); + this.inputs = [...this.inputs.slice(0, index), ...this.inputs.slice(index + 1)]; + } } - for (const device of result.newlyDisconnectedDevices) { - this.onDeviceStatusChange.next({ - manufacturer: '', - name: device.humanReadableName, - status: 'disconnected', - subtype: 'midi_input', - type: 'midi', - }); + if (device.output) { + const index = this.outputs.findIndex(d => d.name === device.machineReadableName); + if (index !== -1) { + this.logDebug(`[NodeMidiService] Closing output: ${this.outputs[index].name}`); + this.outputs[index].close(); + this.outputs = [...this.outputs.slice(0, index), ...this.outputs.slice(index + 1)]; + } } } - } - this.initialized = true; + if (result.newlyConnectedDevices.length || result.newlyDisconnectedDevices.length) { + if (this.initialized) { + for (const device of result.newlyConnectedDevices) { + this.onDeviceStatusChange.next({ + manufacturer: '', + name: device.humanReadableName, + status: 'connected', + subtype: 'midi_input', + type: 'midi', + }); + } + for (const device of result.newlyDisconnectedDevices) { + this.onDeviceStatusChange.next({ + manufacturer: '', + name: device.humanReadableName, + status: 'disconnected', + subtype: 'midi_input', + type: 'midi', + }); + } + } + } - setTimeout(this.pollForConnectedDevices, 10000); + this.initialized = true; + this.consecutiveErrors = 0; // Reset error count on successful poll + this.logDebug(`[NodeMidiService] Poll cycle completed successfully. Active inputs: ${this.inputs.length}, Active outputs: ${this.outputs.length}`); + + } catch (error) { + this.consecutiveErrors++; + const errorMsg = error instanceof Error ? error.message : 'Unknown error'; + console.error(`[NodeMidiService] Polling error (${this.consecutiveErrors} consecutive): ${errorMsg}`); + this.logDebug('[NodeMidiService] Full error:', error); + + if (errorMsg.includes('Cannot allocate memory')) { + console.warn('[NodeMidiService] Memory allocation failure detected. Increasing poll interval.'); + this.logDebug(`[NodeMidiService] Current memory usage: ${this.getMemoryUsage().toFixed(1)} MB`); + this.logDebug(`[NodeMidiService] Error devices list: ${this.errorDevices.join(', ')}`); + } + } finally { + // Calculate next poll interval with exponential backoff + const backoffMultiplier = Math.min(Math.pow(2, this.consecutiveErrors), 8); // Cap at 8x + const nextPollInterval = Math.min(this.basePollInterval * backoffMultiplier, this.maxPollInterval); + + this.logDebug(`[NodeMidiService] Next poll in ${nextPollInterval / 1000} seconds (errors: ${this.consecutiveErrors})`); + this.logDebug('[NodeMidiService] === Poll cycle ended ===\n'); + setTimeout(this.pollForConnectedDevices, nextPollInterval); + } }; } From bb148078e6ae4232072dccf89b22eb8771c7e999 Mon Sep 17 00:00:00 2001 From: Michael Kochell <6913320+mickmister@users.noreply.github.com> Date: Sat, 20 Sep 2025 20:00:58 -0400 Subject: [PATCH 2/4] add debug logging --- .../services/node/node_midi/midi_poller.ts | 44 ++++++++++-- .../core/services/node/node_midi_service.ts | 70 +++++++++++++++---- 2 files changed, 98 insertions(+), 16 deletions(-) diff --git a/packages/jamtools/core/services/node/node_midi/midi_poller.ts b/packages/jamtools/core/services/node/node_midi/midi_poller.ts index 26208fed..8e256116 100644 --- a/packages/jamtools/core/services/node/node_midi/midi_poller.ts +++ b/packages/jamtools/core/services/node/node_midi/midi_poller.ts @@ -41,32 +41,48 @@ export class NodeMidiDevicePollerService { }; public pollForDevices = async (knownDevices: string[]): Promise => { + console.log('[DEBUG] === POLLING FOR DEVICES START ==='); this.logDebug(`[MidiPoller] Starting poll. Known devices: ${knownDevices.length}`); this.logDebug(`[MidiPoller] Known device names: ${JSON.stringify(knownDevices)}`); - + + console.log(`[DEBUG] Using ${this.isUsingAmidi ? 'AMidiDevicePoller' : 'EasyMidiDevicePoller'}`); + const startTime = Date.now(); const allPolledDevices = await this.poller.poll(); const pollTime = Date.now() - startTime; + console.log(`[DEBUG] Raw poll results (${allPolledDevices.length} devices):`, JSON.stringify(allPolledDevices, null, 2)); this.logDebug(`[MidiPoller] Poll completed in ${pollTime}ms. Found ${allPolledDevices.length} total devices`); - + const polledDevices = allPolledDevices.filter(d => !d.humanReadableName.startsWith('Midi Through') && !d.humanReadableName.includes('RtMidi')); + console.log(`[DEBUG] After filtering out system devices (${polledDevices.length} devices):`, JSON.stringify(polledDevices, null, 2)); this.logDebug(`[MidiPoller] After filtering: ${polledDevices.length} devices`); const newlyConnectedDevices: DeviceMetadata[] = []; const newlyDisconnectedDevices: DeviceMetadata[] = []; const currentDeviceNames = polledDevices.map(device => device.humanReadableName); + console.log(`[DEBUG] Current device names from poll: ${JSON.stringify(currentDeviceNames)}`); + console.log('[DEBUG] === IDENTIFYING NEWLY CONNECTED DEVICES ==='); // Identify newly connected devices polledDevices.forEach(device => { - if (!knownDevices.find(name => name.startsWith(device.humanReadableName))) { + const isKnown = knownDevices.find(name => name.startsWith(device.humanReadableName)); + console.log(`[DEBUG] Checking device "${device.humanReadableName}": known=${!!isKnown}, knownName="${isKnown || 'none'}"`); + + if (!isKnown) { + console.log(`[DEBUG] NEWLY CONNECTED: ${device.humanReadableName} (machine: ${device.machineReadableName})`); newlyConnectedDevices.push(device); } }); + console.log('[DEBUG] === IDENTIFYING DISCONNECTED DEVICES ==='); // Identify disconnected devices knownDevices.forEach(knownDevice => { - if (!currentDeviceNames.find(name => knownDevice.startsWith(name))) { + const stillConnected = currentDeviceNames.find(name => knownDevice.startsWith(name)); + console.log(`[DEBUG] Checking known device "${knownDevice}": stillConnected=${!!stillConnected}, currentName="${stillConnected || 'none'}"`); + + if (!stillConnected) { + console.log(`[DEBUG] DISCONNECTED: ${knownDevice}`); newlyDisconnectedDevices.push({ humanReadableName: knownDevice, machineReadableName: knownDevice, @@ -77,23 +93,31 @@ export class NodeMidiDevicePollerService { }); if (newlyConnectedDevices.length && !this.isUsingAmidi) { + console.log('[DEBUG] === PROCESSING DEVICE NAMES WITH EASYMIDI ==='); this.logDebug('[MidiPoller] Processing newly connected devices with EasyMidi for machine-readable names...'); // Only use easymidi for machine-readable names if not using AMidi let inputs: string[] | undefined; let outputs: string[] | undefined; for (const device of newlyConnectedDevices) { + console.log(`[DEBUG] Processing device: "${device.humanReadableName}" (input: ${device.input}, output: ${device.output})`); + console.log(`[DEBUG] Original machine name: "${device.machineReadableName}"`); this.logDebug(`[MidiPoller] Processing device: ${device.humanReadableName} (input: ${device.input}, output: ${device.output})`); + if (device.input) { if (!inputs) { + console.log('[DEBUG] Getting EasyMidi inputs list...'); this.logDebug('[MidiPoller] Getting EasyMidi inputs...'); const startTime = Date.now(); inputs = easymidi.getInputs(); this.logDebug(`[MidiPoller] EasyMidi.getInputs() took ${Date.now() - startTime}ms`); + console.log(`[DEBUG] EasyMidi inputs: ${JSON.stringify(inputs)}`); this.logDebug(`[MidiPoller] EasyMidi inputs: ${JSON.stringify(inputs)}`); } const foundInput = inputs.find(deviceName => deviceName.startsWith(device.humanReadableName)); + console.log(`[DEBUG] Looking for input matching "${device.humanReadableName}": found="${foundInput || 'none'}"`); if (foundInput) { + console.log(`[DEBUG] Updating machine name from "${device.machineReadableName}" to "${foundInput}"`); this.logDebug(`[MidiPoller] Found machine-readable name for input: ${foundInput}`); device.machineReadableName = foundInput; continue; @@ -101,30 +125,42 @@ export class NodeMidiDevicePollerService { } if (device.output) { if (!outputs) { + console.log('[DEBUG] Getting EasyMidi outputs list...'); this.logDebug('[MidiPoller] Getting EasyMidi outputs...'); const startTime = Date.now(); outputs = easymidi.getOutputs(); this.logDebug(`[MidiPoller] EasyMidi.getOutputs() took ${Date.now() - startTime}ms`); + console.log(`[DEBUG] EasyMidi outputs: ${JSON.stringify(outputs)}`); this.logDebug(`[MidiPoller] EasyMidi outputs: ${JSON.stringify(outputs)}`); } const foundOutput = outputs.find(deviceName => deviceName.startsWith(device.humanReadableName)); + console.log(`[DEBUG] Looking for output matching "${device.humanReadableName}": found="${foundOutput || 'none'}"`); if (foundOutput) { + console.log(`[DEBUG] Updating machine name from "${device.machineReadableName}" to "${foundOutput}"`); this.logDebug(`[MidiPoller] Found machine-readable name for output: ${foundOutput}`); device.machineReadableName = foundOutput; continue; } } + console.log(`[DEBUG] No EasyMidi name match found for "${device.humanReadableName}", keeping "${device.machineReadableName}"`); } } + console.log('[DEBUG] === POLLING RESULTS SUMMARY ==='); + console.log(`[DEBUG] Newly connected: ${newlyConnectedDevices.length}, Newly disconnected: ${newlyDisconnectedDevices.length}`); + this.logDebug(`[MidiPoller] Poll complete. Newly connected: ${newlyConnectedDevices.length}, Newly disconnected: ${newlyDisconnectedDevices.length}`); if (newlyConnectedDevices.length > 0) { + console.log('[DEBUG] Final newly connected devices:', JSON.stringify(newlyConnectedDevices, null, 2)); this.logDebug('[MidiPoller] Newly connected devices:', JSON.stringify(newlyConnectedDevices, null, 2)); } if (newlyDisconnectedDevices.length > 0) { + console.log('[DEBUG] Final newly disconnected devices:', JSON.stringify(newlyDisconnectedDevices, null, 2)); this.logDebug('[MidiPoller] Newly disconnected devices:', JSON.stringify(newlyDisconnectedDevices, null, 2)); } + + console.log('[DEBUG] === POLLING FOR DEVICES END ===\n'); return {newlyConnectedDevices, newlyDisconnectedDevices}; }; } diff --git a/packages/jamtools/core/services/node/node_midi_service.ts b/packages/jamtools/core/services/node/node_midi_service.ts index 76783822..3f846126 100644 --- a/packages/jamtools/core/services/node/node_midi_service.ts +++ b/packages/jamtools/core/services/node/node_midi_service.ts @@ -28,10 +28,21 @@ export class NodeMidiService implements MidiService { }; public initialize = async () => { + console.log('[NodeMidiService] === INITIALIZATION START ==='); this.logDebug('[NodeMidiService] Initializing...'); + + // Check system MIDI capabilities - DEBUG ONLY (will remove after fixing) + console.log('[DEBUG] === SYSTEM MIDI CAPABILITIES CHECK ==='); + const systemInputs = easymidi.getInputs(); + const systemOutputs = easymidi.getOutputs(); + console.log('[DEBUG] System MIDI inputs from easymidi.getInputs():', JSON.stringify(systemInputs)); + console.log('[DEBUG] System MIDI outputs from easymidi.getOutputs():', JSON.stringify(systemOutputs)); + console.log(`[DEBUG] Total inputs: ${systemInputs.length}, Total outputs: ${systemOutputs.length}`); + await this.pollService.initialize(); this.logDebug('[NodeMidiService] Starting device polling...'); await this.pollForConnectedDevices(); + console.log('[NodeMidiService] === INITIALIZATION COMPLETE ==='); }; public getInputs = () => { @@ -44,25 +55,45 @@ export class NodeMidiService implements MidiService { private initializeMidiInputDevice = (inputName: string) => { inputName = inputName.trim(); + console.log(`[DEBUG] === INITIALIZING INPUT DEVICE: "${inputName}" ===`); this.logDebug(`[NodeMidiService] Attempting to initialize MIDI input: ${inputName}`); + + console.log(`[DEBUG] Current error devices list: ${JSON.stringify(this.errorDevices)}`); + console.log(`[DEBUG] Is device in error list? ${this.errorDevices.includes(inputName)}`); + if (this.errorDevices.includes(inputName)) { + console.log(`[DEBUG] SKIPPING - Device "${inputName}" is in error list`); this.logDebug(`[NodeMidiService] Skipping ${inputName} - previously failed`); return; } try { + console.log(`[DEBUG] Checking for existing input with name "${inputName}"`); const existingInputIndex = this.inputs.findIndex(i => i.name === inputName); + console.log(`[DEBUG] Existing input index: ${existingInputIndex}`); if (existingInputIndex !== -1) { + console.log(`[DEBUG] Found existing input, closing it first`); const existingInput = this.inputs[existingInputIndex]; existingInput?.close(); this.inputs = [...this.inputs.slice(0, existingInputIndex), ...this.inputs.slice(existingInputIndex + 1)]; + console.log(`[DEBUG] Closed existing input, new inputs length: ${this.inputs.length}`); } + // Debug: Show what easymidi actually sees vs what we're trying to open + const availableInputs = easymidi.getInputs(); + console.log(`[DEBUG] === DEVICE NAME COMPARISON ===`); + console.log(`[DEBUG] Available easymidi inputs: ${JSON.stringify(availableInputs)}`); + console.log(`[DEBUG] Trying to open: "${inputName}"`); + console.log(`[DEBUG] Exact match found: ${availableInputs.includes(inputName)}`); + console.log(`[DEBUG] Partial matches:`, availableInputs.filter(name => name.includes('Digital Piano') || inputName.includes(name))); + + console.log(`[DEBUG] About to call new easymidi.Input("${inputName}")`); this.logDebug(`[NodeMidiService] Creating easymidi.Input for ${inputName}...`); const startTime = Date.now(); const input = new easymidi.Input(inputName); const createTime = Date.now() - startTime; + console.log(`[DEBUG] SUCCESS: Created easymidi.Input in ${createTime}ms`); this.logDebug(`[NodeMidiService] Created input in ${createTime}ms`); const publishMidiEvent = (event: MidiEvent) => { @@ -122,12 +153,14 @@ export class NodeMidiService implements MidiService { } catch (e) { const error = e as Error; console.error('failed to initialize midi input device', inputName, error.message); - + console.error('Full error object:', error); + console.error('Error stack:', error.stack); + // Check if it's a memory allocation error specifically if (error.message.includes('Cannot allocate memory') || error.message.includes('Failed to initialise RtMidi')) { console.warn('Memory allocation failed for MIDI device. Consider reducing polling frequency or restarting service.'); } - + this.errorDevices.push(inputName); } }; @@ -149,23 +182,30 @@ export class NodeMidiService implements MidiService { this.outputs = [...this.outputs.slice(0, existingOutputIndex), ...this.outputs.slice(existingOutputIndex + 1)]; } + // Debug: Show what easymidi actually sees vs what we're trying to open + const availableOutputs = easymidi.getOutputs(); + console.log(`[DEBUG] Available easymidi outputs: ${JSON.stringify(availableOutputs)}`); + console.log(`[DEBUG] Trying to open: "${outputName}"`); + this.logDebug(`[NodeMidiService] Creating easymidi.Output for ${outputName}...`); const startTime = Date.now(); const output = new easymidi.Output(outputName); const createTime = Date.now() - startTime; this.logDebug(`[NodeMidiService] Created output in ${createTime}ms`); - + this.outputs.push(output); this.logDebug(`[NodeMidiService] Successfully initialized MIDI output: ${output.name}. Total outputs: ${this.outputs.length}`); } catch (e) { const error = e as Error; console.error('failed to initialize midi output device', outputName, error.message); - + console.error('Full error object:', error); + console.error('Error stack:', error.stack); + // Check if it's a memory allocation error specifically if (error.message.includes('Cannot allocate memory') || error.message.includes('Failed to initialise RtMidi')) { console.warn('Memory allocation failed for MIDI device. Consider reducing polling frequency or restarting service.'); } - + this.errorDevices.push(outputName); } }; @@ -218,18 +258,24 @@ export class NodeMidiService implements MidiService { this.logDebug('[NodeMidiService] === Starting device poll cycle ==='); try { const memoryBefore = this.getMemoryUsage(); - console.log(`[NodeMidiService] Memory before polling: ${memoryBefore.toFixed(1)} MB`); + this.logDebug(`[NodeMidiService] Memory before polling: ${memoryBefore.toFixed(1)} MB`); + + const knownDevices = Array.from(new Set( + this.inputs.map(i => i.name) + .concat(this.outputs.map(o => o.name)) + .concat(this.errorDevices) // Include error devices so they don't get re-detected as "newly connected" + )); + this.logDebug(`[NodeMidiService] Current known devices: ${knownDevices.length} (inputs: ${this.inputs.length}, outputs: ${this.outputs.length}, errors: ${this.errorDevices.length})`); + this.logDebug(`[NodeMidiService] Known device names: ${JSON.stringify(knownDevices)}`); + this.logDebug(`[NodeMidiService] Error devices: ${JSON.stringify(this.errorDevices)}`); - const knownDevices = Array.from(new Set(this.inputs.map(i => i.name).concat(this.outputs.map(o => o.name)))); - this.logDebug(`[NodeMidiService] Current known devices: ${knownDevices.length}`); - const pollStartTime = Date.now(); const result = await this.pollService.pollForDevices(knownDevices); const pollDuration = Date.now() - pollStartTime; this.logDebug(`[NodeMidiService] Poll completed in ${pollDuration}ms`); const memoryAfter = this.getMemoryUsage(); - console.log(`[NodeMidiService] Memory after polling: ${memoryAfter.toFixed(1)} MB (delta: ${(memoryAfter - memoryBefore).toFixed(1)} MB)`); + this.logDebug(`[NodeMidiService] Memory after polling: ${memoryAfter.toFixed(1)} MB (delta: ${(memoryAfter - memoryBefore).toFixed(1)} MB)`); this.logDebug(`[NodeMidiService] Processing ${result.newlyConnectedDevices.length} newly connected devices...`); for (const device of result.newlyConnectedDevices) { @@ -295,7 +341,7 @@ export class NodeMidiService implements MidiService { const errorMsg = error instanceof Error ? error.message : 'Unknown error'; console.error(`[NodeMidiService] Polling error (${this.consecutiveErrors} consecutive): ${errorMsg}`); this.logDebug('[NodeMidiService] Full error:', error); - + if (errorMsg.includes('Cannot allocate memory')) { console.warn('[NodeMidiService] Memory allocation failure detected. Increasing poll interval.'); this.logDebug(`[NodeMidiService] Current memory usage: ${this.getMemoryUsage().toFixed(1)} MB`); @@ -305,7 +351,7 @@ export class NodeMidiService implements MidiService { // Calculate next poll interval with exponential backoff const backoffMultiplier = Math.min(Math.pow(2, this.consecutiveErrors), 8); // Cap at 8x const nextPollInterval = Math.min(this.basePollInterval * backoffMultiplier, this.maxPollInterval); - + this.logDebug(`[NodeMidiService] Next poll in ${nextPollInterval / 1000} seconds (errors: ${this.consecutiveErrors})`); this.logDebug('[NodeMidiService] === Poll cycle ended ===\n'); setTimeout(this.pollForConnectedDevices, nextPollInterval); From ab64dde474e7eabae74a672113b408097a3697d1 Mon Sep 17 00:00:00 2001 From: Michael Kochell <6913320+mickmister@users.noreply.github.com> Date: Sat, 20 Sep 2025 21:31:10 -0400 Subject: [PATCH 3/4] use human readable name for midi device --- .../jamtools/core/services/node/node_midi_service.ts | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-) diff --git a/packages/jamtools/core/services/node/node_midi_service.ts b/packages/jamtools/core/services/node/node_midi_service.ts index 3f846126..741681c1 100644 --- a/packages/jamtools/core/services/node/node_midi_service.ts +++ b/packages/jamtools/core/services/node/node_midi_service.ts @@ -39,6 +39,10 @@ export class NodeMidiService implements MidiService { console.log('[DEBUG] System MIDI outputs from easymidi.getOutputs():', JSON.stringify(systemOutputs)); console.log(`[DEBUG] Total inputs: ${systemInputs.length}, Total outputs: ${systemOutputs.length}`); + // TEMPORARY: Clear error devices list to see the actual error + console.log('[DEBUG] CLEARING ERROR DEVICES LIST FOR DEBUGGING'); + this.errorDevices = []; + await this.pollService.initialize(); this.logDebug('[NodeMidiService] Starting device polling...'); await this.pollForConnectedDevices(); @@ -280,11 +284,12 @@ export class NodeMidiService implements MidiService { this.logDebug(`[NodeMidiService] Processing ${result.newlyConnectedDevices.length} newly connected devices...`); for (const device of result.newlyConnectedDevices) { this.logDebug(`[NodeMidiService] New device: ${device.humanReadableName} (machine: ${device.machineReadableName})`); + console.log(`[DEBUG] TRYING HUMAN READABLE NAME: "${device.humanReadableName}" instead of machine name: "${device.machineReadableName}"`); if (device.input) { - this.initializeMidiInputDevice(device.machineReadableName); + this.initializeMidiInputDevice(device.humanReadableName); } if (device.output) { - this.initializeMidiOutputDevice(device.machineReadableName); + this.initializeMidiOutputDevice(device.humanReadableName); } } From 5cfa852467c54c2af60e50841ac21030abad3313 Mon Sep 17 00:00:00 2001 From: Michael Kochell <6913320+mickmister@users.noreply.github.com> Date: Sun, 21 Sep 2025 23:39:42 -0400 Subject: [PATCH 4/4] try to fix midi memory again --- .../services/node/node_midi/midi_poller.ts | 11 +++-- .../core/services/node/node_midi_service.ts | 43 +++++++++++++------ 2 files changed, 38 insertions(+), 16 deletions(-) diff --git a/packages/jamtools/core/services/node/node_midi/midi_poller.ts b/packages/jamtools/core/services/node/node_midi/midi_poller.ts index 8e256116..e74af0b9 100644 --- a/packages/jamtools/core/services/node/node_midi/midi_poller.ts +++ b/packages/jamtools/core/services/node/node_midi/midi_poller.ts @@ -245,9 +245,14 @@ class AMidiDevicePoller implements NodeMidiDevicePoller { this.logDebug(`[AMidiPoller] getAseqHumanReadableNames() took ${Date.now() - aseqStartTime}ms`); for (const device of amidiOutput) { - const humanReadableName = aseqOutput.get(device.machineReadableName); - if (humanReadableName) { - device.humanReadableName = humanReadableName; + // Try to find mapping using the client name part (after the hw: prefix) + const deviceClientName = device.humanReadableName; // e.g., "Digital Piano MIDI 1" + const betterHumanName = aseqOutput.get(deviceClientName); + if (betterHumanName) { + console.log(`[DEBUG] Mapped "${deviceClientName}" -> "${betterHumanName}"`); + device.humanReadableName = betterHumanName; + } else { + console.log(`[DEBUG] No aseq mapping found for "${deviceClientName}", keeping original`); } } diff --git a/packages/jamtools/core/services/node/node_midi_service.ts b/packages/jamtools/core/services/node/node_midi_service.ts index 741681c1..88369bc1 100644 --- a/packages/jamtools/core/services/node/node_midi_service.ts +++ b/packages/jamtools/core/services/node/node_midi_service.ts @@ -77,25 +77,32 @@ export class NodeMidiService implements MidiService { console.log(`[DEBUG] Existing input index: ${existingInputIndex}`); if (existingInputIndex !== -1) { - console.log(`[DEBUG] Found existing input, closing it first`); + console.log('[DEBUG] Found existing input, closing it first'); const existingInput = this.inputs[existingInputIndex]; existingInput?.close(); this.inputs = [...this.inputs.slice(0, existingInputIndex), ...this.inputs.slice(existingInputIndex + 1)]; console.log(`[DEBUG] Closed existing input, new inputs length: ${this.inputs.length}`); } - // Debug: Show what easymidi actually sees vs what we're trying to open + // Find the correct easymidi port name that matches our device const availableInputs = easymidi.getInputs(); - console.log(`[DEBUG] === DEVICE NAME COMPARISON ===`); console.log(`[DEBUG] Available easymidi inputs: ${JSON.stringify(availableInputs)}`); - console.log(`[DEBUG] Trying to open: "${inputName}"`); - console.log(`[DEBUG] Exact match found: ${availableInputs.includes(inputName)}`); - console.log(`[DEBUG] Partial matches:`, availableInputs.filter(name => name.includes('Digital Piano') || inputName.includes(name))); + console.log(`[DEBUG] Looking for match with: "${inputName}"`); - console.log(`[DEBUG] About to call new easymidi.Input("${inputName}")`); - this.logDebug(`[NodeMidiService] Creating easymidi.Input for ${inputName}...`); + // Find input that contains our device name + const matchingInput = availableInputs.find(portName => + portName.includes(inputName) || inputName.includes(portName.split(':')[1]?.trim() || '') + ); + + if (!matchingInput) { + throw new Error(`No matching easymidi input found for "${inputName}". Available: ${availableInputs.join(', ')}`); + } + + console.log(`[DEBUG] Using easymidi port name: "${matchingInput}"`); + console.log(`[DEBUG] About to call new easymidi.Input("${matchingInput}")`); + this.logDebug(`[NodeMidiService] Creating easymidi.Input for ${matchingInput}...`); const startTime = Date.now(); - const input = new easymidi.Input(inputName); + const input = new easymidi.Input(matchingInput); const createTime = Date.now() - startTime; console.log(`[DEBUG] SUCCESS: Created easymidi.Input in ${createTime}ms`); this.logDebug(`[NodeMidiService] Created input in ${createTime}ms`); @@ -186,14 +193,24 @@ export class NodeMidiService implements MidiService { this.outputs = [...this.outputs.slice(0, existingOutputIndex), ...this.outputs.slice(existingOutputIndex + 1)]; } - // Debug: Show what easymidi actually sees vs what we're trying to open + // Find the correct easymidi port name that matches our device const availableOutputs = easymidi.getOutputs(); console.log(`[DEBUG] Available easymidi outputs: ${JSON.stringify(availableOutputs)}`); - console.log(`[DEBUG] Trying to open: "${outputName}"`); + console.log(`[DEBUG] Looking for match with: "${outputName}"`); + + // Find output that contains our device name + const matchingOutput = availableOutputs.find(portName => + portName.includes(outputName) || outputName.includes(portName.split(':')[1]?.trim() || '') + ); + + if (!matchingOutput) { + throw new Error(`No matching easymidi output found for "${outputName}". Available: ${availableOutputs.join(', ')}`); + } - this.logDebug(`[NodeMidiService] Creating easymidi.Output for ${outputName}...`); + console.log(`[DEBUG] Using easymidi port name: "${matchingOutput}"`); + this.logDebug(`[NodeMidiService] Creating easymidi.Output for ${matchingOutput}...`); const startTime = Date.now(); - const output = new easymidi.Output(outputName); + const output = new easymidi.Output(matchingOutput); const createTime = Date.now() - startTime; this.logDebug(`[NodeMidiService] Created output in ${createTime}ms`);