Fixed windows update installation.

public/winappupdate.js

@@ -1,82 +1,408 @@
 import { spawn } from 'child_process'
+import { promises as fs } from 'fs'
+import os from 'os'
+import path from 'path'
 import process from 'process'
 
-const buildWindowsInstallCommand = (installerPath) => ({
+const MSI_OLE_HEADER = Buffer.from([0xd0, 0xcf, 0x11, 0xe0, 0xa1, 0xb1, 0x1a, 0xe1])
-  command: 'cmd.exe',
+const DEBUG_PREFIX = '[app-update][win-progress]'
-  args: [
-    '/d',
-    '/s',
-    '/c',
-    `timeout /t 2 /nobreak >NUL && msiexec.exe /i "${installerPath}" /qn /norestart`
-  ]
-})
 
-export const launchWindowsInstaller = (
+const sleep = (ms) => new Promise((resolve) => setTimeout(resolve, ms))
+
+const debugLog = (message, details) => {
+  if (details === undefined) {
+    console.log(`${DEBUG_PREFIX} ${message}`)
+    return
+  }
+
+  console.log(`${DEBUG_PREFIX} ${message}`, details)
+}
+
+const decodeMsiLogBuffer = (buffer) => {
+  if (!buffer?.length) return ''
+
+  if (buffer.length >= 2 && buffer[0] === 0xff && buffer[1] === 0xfe) {
+    debugLog('decoded MSI log as UTF-16 LE (BOM)')
+    return buffer.subarray(2).toString('utf16le')
+  }
+
+  const sample = buffer.subarray(0, Math.min(buffer.length, 64))
+  const looksUtf16 =
+    sample.length >= 4 &&
+    sample.filter((byte) => byte === 0).length > sample.length / 4
+
+  if (looksUtf16) {
+    debugLog('decoded MSI log as UTF-16 LE (heuristic)')
+    return buffer.toString('utf16le')
+  }
+
+  debugLog('decoded MSI log as UTF-8')
+  return buffer.toString('utf8')
+}
+
+const formatMsiActionName = (actionName) => {
+  const humanized = String(actionName)
+    .replace(/([a-z])([A-Z])/g, '$1 $2')
+    .replace(/_/g, ' ')
+    .toLowerCase()
+    .trim()
+
+  if (!humanized) return 'Installing update...'
+
+  return `${humanized.charAt(0).toUpperCase()}${humanized.slice(1)}...`
+}
+
+const parseWindowsInstallerProgress = (output) => {
+  const lines = String(output || '').split(/\r?\n/)
+  let percent = null
+  let message = 'Installing update...'
+  let totalTicks = 0
+  let currentTicks = 0
+  let actionStarts = 0
+  let actionEnds = 0
+  const matchedLines = []
+
+  for (const line of lines) {
+    const actionStart = line.match(/^Action start \d{2}:\d{2}:\d{2}: (.+?)\./)
+    if (actionStart) {
+      actionStarts += 1
+      message = formatMsiActionName(actionStart[1])
+      matchedLines.push(`action-start:${actionStart[1]}`)
+    }
+
+    const doingAction = line.match(/Doing action:\s*(.+)$/)
+    if (doingAction && !actionStart) {
+      message = formatMsiActionName(doingAction[1])
+      matchedLines.push(`doing-action:${doingAction[1]}`)
+    }
+
+    if (/^Action ended \d{2}:\d{2}:\d{2}: .+?\. Return value \d+\./.test(line)) {
+      actionEnds += 1
+      matchedLines.push('action-ended')
+    }
+
+    const progressReset = line.match(/^\s*0\s+(\d+)\s+0(?:\s+\d+)?\s*$/)
+    if (progressReset) {
+      totalTicks = Number.parseInt(progressReset[1], 10) || 0
+      currentTicks = 0
+      matchedLines.push(`progress-reset:${totalTicks}`)
+    }
+
+    const progressIncrement = line.match(/^\s*2\s+(\d+)\s*$/)
+    if (progressIncrement) {
+      currentTicks += Number.parseInt(progressIncrement[1], 10) || 0
+      matchedLines.push(`progress-increment:${progressIncrement[1]}`)
+    }
+
+    const progressAddition = line.match(/^\s*3\s+(\d+)\s*$/)
+    if (progressAddition) {
+      totalTicks += Number.parseInt(progressAddition[1], 10) || 0
+      matchedLines.push(`progress-addition:${progressAddition[1]}`)
+    }
+
+    if (/Installation success or error status:\s*0\b/.test(line)) {
+      percent = 100
+      message = 'Installation complete. Restarting Farm Control...'
+      matchedLines.push('install-success')
+    }
+  }
+
+  if (percent !== 100) {
+    if (totalTicks > 0) {
+      percent = Math.min(99, Math.round((currentTicks / totalTicks) * 100))
+    } else if (actionStarts > 0) {
+      percent = Math.min(
+        95,
+        Math.max(5, Math.round((actionEnds / actionStarts) * 90))
+      )
+    }
+  }
+
+  return {
+    percent,
+    message,
+    stats: {
+      lineCount: lines.length,
+      actionStarts,
+      actionEnds,
+      totalTicks,
+      currentTicks,
+      matchedLines: matchedLines.slice(-8)
+    }
+  }
+}
+
+const isWindowsInstallSuccessful = (output) =>
+  /Installation success or error status:\s*0\b/.test(output) ||
+  /MainEngineThread is returning 0\b/.test(output)
+
+const isWindowsInstallFailed = (output) =>
+  /Installation success or error status:\s*[1-9]\d*\b/.test(output) ||
+  /MainEngineThread is returning [1-9]\d*\b/.test(output)
+
+const isValidMsiPackage = async (filePath) => {
+  const handle = await fs.open(filePath, 'r')
+  try {
+    const header = Buffer.alloc(MSI_OLE_HEADER.length)
+    await handle.read(header, 0, header.length, 0)
+    return header.equals(MSI_OLE_HEADER)
+  } finally {
+    await handle.close()
+  }
+}
+
+const prepareInstallerPath = async (installerPath) => {
+  const fileName = path.basename(installerPath)
+  const updateDir = path.join(
+    process.env.LOCALAPPDATA || path.join(os.homedir(), 'AppData', 'Local'),
+    'FarmControl',
+    'Updates'
+  )
+  await fs.mkdir(updateDir, { recursive: true })
+
+  const stablePath = path.join(updateDir, fileName)
+  await fs.copyFile(installerPath, stablePath)
+
+  // Resolve to a canonical long path. Short 8.3 paths (e.g. ADMINI~1) break msiexec.
+  const resolvedPath = await fs.realpath(stablePath)
+  const stats = await fs.stat(resolvedPath)
+
+  if (!stats.isFile() || stats.size === 0) {
+    throw new Error('Update installer file is missing or empty.')
+  }
+
+  if (!(await isValidMsiPackage(resolvedPath))) {
+    throw new Error(
+      'Downloaded update is not a valid Windows Installer package. The file may be corrupted or incomplete.'
+    )
+  }
+
+  return resolvedPath
+}
+
+const startWindowsInstallerProgressWatch = (
+  logPath,
+  webContents,
+  sendProgress
+) => {
+  let installerOutput = ''
+  let lastLogSize = 0
+  let lastPercent = null
+  let lastMessage = null
+  let pollCount = 0
+
+  const poll = async () => {
+    pollCount += 1
+
+    try {
+      const stat = await fs.stat(logPath)
+      if (stat.size === 0) {
+        debugLog(`poll #${pollCount}: log exists but is empty`, { logPath })
+        return
+      }
+
+      if (stat.size === lastLogSize) {
+        debugLog(`poll #${pollCount}: no new log data`, {
+          logPath,
+          size: stat.size
+        })
+        return
+      }
+
+      const buffer = Buffer.alloc(stat.size)
+      const handle = await fs.open(logPath, 'r')
+      try {
+        await handle.read(buffer, 0, stat.size, 0)
+      } finally {
+        await handle.close()
+      }
+
+      lastLogSize = stat.size
+      installerOutput = decodeMsiLogBuffer(buffer)
+
+      const { percent, message, stats } =
+        parseWindowsInstallerProgress(installerOutput)
+      const resolvedPercent = percent ?? lastPercent ?? 0
+      const resolvedMessage = message || 'Installing update...'
+
+      debugLog(`poll #${pollCount}: parsed installer log`, {
+        logPath,
+        size: stat.size,
+        textLength: installerOutput.length,
+        preview: installerOutput.slice(0, 240).replace(/\s+/g, ' '),
+        parsed: stats,
+        resolvedPercent,
+        resolvedMessage
+      })
+
+      if (
+        resolvedPercent !== lastPercent ||
+        resolvedMessage !== lastMessage
+      ) {
+        debugLog(`poll #${pollCount}: sending progress update`, {
+          percent: resolvedPercent,
+          message: resolvedMessage
+        })
+
+        lastPercent = resolvedPercent
+        lastMessage = resolvedMessage
+        sendProgress(webContents, {
+          phase: 'installing',
+          percent: resolvedPercent,
+          message: resolvedMessage
+        })
+      } else {
+        debugLog(`poll #${pollCount}: progress unchanged, skipping UI update`, {
+          percent: resolvedPercent,
+          message: resolvedMessage
+        })
+      }
+    } catch (error) {
+      if (error?.code === 'ENOENT') {
+        debugLog(`poll #${pollCount}: log file not created yet`, { logPath })
+        return
+      }
+
+      console.error(`${DEBUG_PREFIX} installer log poll error:`, error)
+    }
+  }
+
+  const intervalId = setInterval(() => {
+    poll().catch((error) => {
+      console.error(`${DEBUG_PREFIX} installer log poll error:`, error)
+    })
+  }, 300)
+
+  return async () => {
+    clearInterval(intervalId)
+    await poll()
+    debugLog('stopped progress watch', {
+      logPath,
+      finalSize: lastLogSize,
+      textLength: installerOutput.length,
+      pollCount
+    })
+    return installerOutput
+  }
+}
+
+export const launchWindowsInstaller = async (
   app,
   installerPath,
   webContents,
   { sendProgress, getInstallErrorMessage }
 ) => {
-  const { command, args } = buildWindowsInstallCommand(installerPath)
+  const resolvedPath = await prepareInstallerPath(installerPath)
+  const logPath = path.join(path.dirname(resolvedPath), 'install.log')
 
-  console.log('[app-update] launching installer:', {
+  debugLog('prepared installer', {
     installerPath,
-    command,
+    resolvedPath,
-    args,
+    logPath
-    shellCommand: args.join(' '),
-    platform: process.platform
   })
 
   sendProgress(webContents, {
     phase: 'installing',
-    percent: 100,
+    percent: 0,
-    message: 'Installing update. Farm Control will restart automatically.'
+    message: 'Installing update...'
   })
 
-  return new Promise((resolve, reject) => {
+  await fs.unlink(logPath).catch(() => {})
-    let installerOutput = ''
 
-    const installerProcess = spawn(command, args, {
+  // Allow file handles from the download/copy to settle before msiexec opens the MSI.
-      detached: true,
+  await sleep(2000)
+
+  const stopProgressWatch = startWindowsInstallerProgressWatch(
+    logPath,
+    webContents,
+    sendProgress
+  )
+
+  return new Promise((resolve, reject) => {
+    let processOutput = ''
+    const startedAt = Date.now()
+
+    const installerArgs = [
+      '/i',
+      resolvedPath,
+      '/qn',
+      '/norestart',
+      '/L*v!',
+      logPath
+    ]
+
+    debugLog('spawning msiexec', {
+      args: installerArgs,
+      elapsedMs: Date.now() - startedAt
+    })
+
+    const installerProcess = spawn('msiexec.exe', installerArgs, {
       stdio: ['ignore', 'pipe', 'pipe'],
       windowsHide: true
     })
 
     installerProcess.stdout?.on('data', (data) => {
-      const text = data.toString()
+      const text = data.toString('utf16le')
-      installerOutput += text
+      processOutput += text
-      console.log('[app-update] installer stdout:', text)
+      debugLog('msiexec stdout chunk', {
+        length: text.length,
+        preview: text.slice(0, 200)
+      })
     })
 
     installerProcess.stderr?.on('data', (data) => {
-      const text = data.toString()
+      const text = data.toString('utf16le')
-      installerOutput += text
+      processOutput += text
-      console.error('[app-update] installer stderr:', text)
+      debugLog('msiexec stderr chunk', {
+        length: text.length,
+        preview: text.slice(0, 200)
+      })
     })
 
     installerProcess.on('spawn', () => {
-      console.log('[app-update] installer spawned, pid:', installerProcess.pid)
+      debugLog('msiexec spawned', {
+        pid: installerProcess.pid,
+        elapsedMs: Date.now() - startedAt
+      })
     })
 
-    installerProcess.on('error', (error) => {
+    installerProcess.on('error', async (error) => {
-      console.error('[app-update] installer spawn error:', error)
+      console.error(`${DEBUG_PREFIX} installer spawn error:`, error)
+      const watchedOutput = await stopProgressWatch()
+
+      debugLog('installer spawn failed', {
+        watchedOutputLength: watchedOutput.length,
+        processOutputLength: processOutput.length
+      })
+
+      const message = error?.message || 'Failed to start update installer.'
       sendProgress(webContents, {
         phase: 'error',
         percent: null,
-        message: error?.message || 'Failed to start update installer.'
+        message
       })
       reject(error)
     })
 
-    installerProcess.on('exit', (code, signal) => {
+    installerProcess.on('exit', async (code, signal) => {
-      console.log('[app-update] installer exited:', {
+      const watchedOutput = await stopProgressWatch()
+      const output = watchedOutput || processOutput
+      const finalParse = parseWindowsInstallerProgress(output)
+
+      debugLog('msiexec exited', {
         code,
         signal,
-        output: installerOutput
+        elapsedMs: Date.now() - startedAt,
+        watchedOutputLength: watchedOutput.length,
+        processOutputLength: processOutput.length,
+        parsed: finalParse.stats,
+        outputPreview: output.slice(0, 500).replace(/\s+/g, ' ')
       })
 
+      debugLog('keeping install log', { logPath })
+
       if (code !== 0) {
-        const message = getInstallErrorMessage(null, installerOutput)
+        const message = getInstallErrorMessage(null, output)
         sendProgress(webContents, {
           phase: 'error',
           percent: null,
@@ -86,14 +412,38 @@ export const launchWindowsInstaller = (
         return
       }
 
-      sendProgress(webContents, {
+      const succeeded =
-        phase: 'installing',
+        isWindowsInstallSuccessful(output) ||
-        percent: 100,
+        (code === 0 && !isWindowsInstallFailed(output))
-        message: 'Installation complete. Restarting Farm Control...'
+
-      })
+      debugLog('install success evaluation', {
-      resolve()
+        succeeded,
+        isSuccessful: isWindowsInstallSuccessful(output),
+        isFailed: isWindowsInstallFailed(output),
+        exitCode: code
       })
 
-    installerProcess.unref()
+      if (!succeeded) {
+        const message = getInstallErrorMessage(null, output)
+        sendProgress(webContents, {
+          phase: 'error',
+          percent: null,
+          message
+        })
+        reject(new Error(message))
+        return
+      }
+
+      const { percent, message } = finalParse
+
+      sendProgress(webContents, {
+        phase: 'installing',
+        percent: percent ?? 100,
+        message: message || 'Installation complete. Restarting Farm Control...'
+      })
+
+      debugLog('installer completed successfully')
+      resolve()
+    })
   })
 }