diff --git a/package-lock.json b/package-lock.json index aa3c7c5..70b384f 100644 --- a/package-lock.json +++ b/package-lock.json @@ -1,12 +1,12 @@ { "name": "real-debrid-downloader", - "version": "1.7.7", + "version": "1.7.41", "lockfileVersion": 3, "requires": true, "packages": { "": { "name": "real-debrid-downloader", - "version": "1.7.7", + "version": "1.7.41", "license": "MIT", "dependencies": { "adm-zip": "^0.5.16", diff --git a/package.json b/package.json index e1646e7..a90e083 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "real-debrid-downloader", - "version": "1.7.40", + "version": "1.7.41", "description": "Desktop downloader", "main": "build/main/main/main.js", "author": "Sucukdeluxe", diff --git a/src/main/app-controller.ts b/src/main/app-controller.ts index 5f6a8f8..b6d9d58 100644 --- a/src/main/app-controller.ts +++ b/src/main/app-controller.ts @@ -28,6 +28,7 @@ import { configureLogger, getLogFilePath, logger } from "./logger"; import { AllDebridWebFallback } from "./all-debrid-web"; import { BestDebridWebFallback } from "./bestdebrid-web"; import { RealDebridWebFallback } from "./realdebrid-web"; +import { getPackageLogPath, initPackageLogs, shutdownPackageLogs } from "./package-log"; import { initSessionLog, getSessionLogPath, shutdownSessionLog } from "./session-log"; import { MegaWebFallback } from "./mega-web-fallback"; import { addHistoryEntry, cancelPendingAsyncSaves, clearHistory, createStoragePaths, loadHistory, loadSession, loadSettings, normalizeHistoryEntry, normalizeLoadedSession, normalizeLoadedSessionTransientFields, normalizeSettings, removeHistoryEntry, saveHistory, saveSession, saveSettings } from "./storage"; @@ -70,6 +71,7 @@ export class AppController { public constructor() { configureLogger(this.storagePaths.baseDir); initSessionLog(this.storagePaths.baseDir); + initPackageLogs(this.storagePaths.baseDir); this.settings = loadSettings(this.storagePaths); const session = loadSession(this.storagePaths); this.megaWebFallback = new MegaWebFallback(() => ({ @@ -464,6 +466,10 @@ export class AppController { return getSessionLogPath(); } + public getPackageLogPath(packageId: string): string | null { + return this.manager.getPackageLogPath(packageId) || getPackageLogPath(packageId); + } + public shutdown(): void { stopDebugServer(); abortActiveUpdateDownload(); @@ -473,6 +479,7 @@ export class AppController { this.allDebridWebFallback.dispose(); this.bestDebridWebFallback.dispose(); shutdownSessionLog(); + shutdownPackageLogs(); logger.info("App beendet"); } diff --git a/src/main/download-manager.ts b/src/main/download-manager.ts index 60ac75e..34e60b6 100644 --- a/src/main/download-manager.ts +++ b/src/main/download-manager.ts @@ -45,6 +45,7 @@ import { AllDebridWebUnrestrictor, BestDebridWebUnrestrictor, DebridService, Meg import { cleanupArchives, clearExtractResumeState, collectArchiveCleanupTargets, extractPackageArchives, findArchiveCandidates, hasAnyFilesRecursive, removeEmptyDirectoryTree, type ExtractArchiveFailureInfo } from "./extractor"; import { validateFileAgainstManifest } from "./integrity"; import { logger } from "./logger"; +import { ensurePackageLog, getPackageLogPath as getPersistedPackageLogPath, logPackageEvent as writePackageLogEvent } from "./package-log"; import { StoragePaths, saveSession, saveSessionAsync, saveSettings, saveSettingsAsync } from "./storage"; import { compactErrorText, ensureDirPath, filenameFromUrl, formatEta, humanSize, looksLikeOpaqueFilename, nowMs, sanitizeFilename, sleep } from "./utils"; @@ -1171,6 +1172,15 @@ export class DownloadManager extends EventEmitter { this.invalidateMegaSessionFn = options.invalidateMegaSession; this.onHistoryEntryCallback = options.onHistoryEntry; logger.info(`DownloadManager Init: ${Object.keys(this.session.packages).length} Pakete, ${this.itemCount} Items, cleanupPolicy=${this.settings.completedCleanupPolicy}`); + for (const pkg of Object.values(this.session.packages)) { + this.ensurePackageLogForPackage(pkg); + this.logPackageForPackage(pkg, "INFO", "Paket aus Session wiederhergestellt", { + itemCount: pkg.itemIds.length, + status: pkg.status, + enabled: pkg.enabled, + cancelled: pkg.cancelled + }); + } this.applyOnStartCleanupPolicy(); this.normalizeSessionStatuses(); void this.recoverRetryableItems("startup").catch((err) => logger.warn(`recoverRetryableItems Fehler (startup): ${compactErrorText(err)}`)); @@ -1182,6 +1192,55 @@ export class DownloadManager extends EventEmitter { void this.cleanupExistingExtractedArchives().catch((err) => logger.warn(`cleanupExistingExtractedArchives Fehler (constructor): ${compactErrorText(err)}`)); } + public getPackageLogPath(packageId: string): string | null { + const pkg = this.session.packages[packageId]; + if (pkg) { + return this.ensurePackageLogForPackage(pkg); + } + return getPersistedPackageLogPath(packageId); + } + + private ensurePackageLogForPackage(pkg: PackageEntry): string | null { + return ensurePackageLog({ + packageId: pkg.id, + name: pkg.name, + outputDir: pkg.outputDir, + extractDir: pkg.extractDir + }); + } + + private logPackage(packageId: string, level: "INFO" | "WARN" | "ERROR", message: string, fields?: Record): void { + writePackageLogEvent(packageId, level, message, fields); + } + + private logPackageForPackage(pkg: PackageEntry, level: "INFO" | "WARN" | "ERROR", message: string, fields?: Record): void { + this.ensurePackageLogForPackage(pkg); + this.logPackage(pkg.id, level, message, { + packageName: pkg.name, + ...fields + }); + } + + private logPackageForItem( + item: DownloadItem, + level: "INFO" | "WARN" | "ERROR", + message: string, + fields?: Record + ): void { + const pkg = this.session.packages[item.packageId]; + if (pkg) { + this.ensurePackageLogForPackage(pkg); + } + this.logPackage(item.packageId, level, message, { + packageName: pkg?.name || "", + itemId: item.id, + fileName: item.fileName, + status: item.status, + targetPath: item.targetPath, + ...fields + }); + } + public setSettings(next: AppSettings): void { const previous = this.settings; next.totalDownloadedAllTime = Math.max(next.totalDownloadedAllTime || 0, this.settings.totalDownloadedAllTime || 0); @@ -1373,8 +1432,13 @@ export class DownloadManager extends EventEmitter { if (!pkg) { return; } + const previousName = pkg.name; pkg.name = sanitizeFilename(newName) || pkg.name; pkg.updatedAt = nowMs(); + this.logPackageForPackage(pkg, "INFO", "Paket umbenannt", { + oldName: previousName, + newName: pkg.name + }); this.persistSoon(); this.emitState(true); } @@ -1399,6 +1463,9 @@ export class DownloadManager extends EventEmitter { if (!item) { return; } + this.logPackageForItem(item, "WARN", "Item entfernt", { + url: item.url + }); this.recordRunOutcome(itemId, "cancelled"); const active = this.activeTasks.get(itemId); const hasActiveTask = Boolean(active); @@ -1621,6 +1688,12 @@ export class DownloadManager extends EventEmitter { createdAt: nowMs(), updatedAt: nowMs() }; + this.ensurePackageLogForPackage(packageEntry); + this.logPackageForPackage(packageEntry, "INFO", "Paket angelegt", { + outputDir, + extractDir, + linkCount: links.length + }); for (let linkIdx = 0; linkIdx < links.length; linkIdx += 1) { const link = links[linkIdx]; @@ -1648,6 +1721,13 @@ export class DownloadManager extends EventEmitter { updatedAt: nowMs() }; this.assignItemTargetPath(item, path.join(outputDir, fileName)); + this.logPackageForItem(item, "INFO", "Link registriert", { + index: linkIdx + 1, + totalLinks: links.length, + url: link, + hintedName: hintName || "", + initialTargetPath: item.targetPath + }); packageEntry.itemIds.push(itemId); this.session.items[itemId] = item; this.itemCount += 1; @@ -2467,6 +2547,12 @@ export class DownloadManager extends EventEmitter { const videoFiles = await this.collectVideoFiles(extractDir); logger.info(`Auto-Rename: ${videoFiles.length} Video-Dateien gefunden in ${extractDir}`); + if (pkg) { + this.logPackageForPackage(pkg, "INFO", "Auto-Rename Scan gestartet", { + extractDir, + videoFiles: videoFiles.length + }); + } let renamed = 0; // Collect additional folder candidates from package metadata (outputDir, item filenames) @@ -2551,6 +2637,13 @@ export class DownloadManager extends EventEmitter { try { await this.renamePathWithExdevFallback(sourcePath, targetPath); + if (pkg) { + this.logPackageForPackage(pkg, "INFO", "Auto-Rename durchgeführt", { + sourcePath, + targetPath, + sourceName + }); + } logger.info(`Auto-Rename: ${sourceName} -> ${path.basename(targetPath)}`); renamed += 1; } catch (error) { @@ -2588,6 +2681,11 @@ export class DownloadManager extends EventEmitter { if (renamed > 0) { logger.info(`Auto-Rename (Scene): ${renamed} Datei(en) umbenannt`); + if (pkg) { + this.logPackageForPackage(pkg, "INFO", "Auto-Rename abgeschlossen", { + renamed + }); + } } return renamed; } @@ -2837,9 +2935,19 @@ export class DownloadManager extends EventEmitter { try { await this.moveFileWithExdevFallback(sourcePath, targetPath); moved += 1; + this.logPackageForPackage(pkg, "INFO", "MKV verschoben", { + sourcePath, + targetPath, + sourceSize + }); } catch (error) { failed += 1; logger.warn(`MKV verschieben fehlgeschlagen: ${sourcePath} -> ${targetPath} (${compactErrorText(error)})`); + this.logPackageForPackage(pkg, "WARN", "MKV verschieben fehlgeschlagen", { + sourcePath, + targetPath, + error: compactErrorText(error) + }); } } @@ -2862,6 +2970,9 @@ export class DownloadManager extends EventEmitter { if (!pkg) { return; } + this.logPackageForPackage(pkg, "WARN", "Paketabbruch angefordert", { + itemCount: pkg.itemIds.length + }); pkg.cancelled = true; pkg.updatedAt = nowMs(); const packageName = pkg.name; @@ -4511,6 +4622,12 @@ export class DownloadManager extends EventEmitter { const slotWaitMs = nowMs() - slotWaitStart; if (slotWaitMs > 100) { logger.info(`Post-Process Slot erhalten nach ${(slotWaitMs / 1000).toFixed(1)}s Wartezeit: pkg=${packageId.slice(0, 8)}`); + const pkg = this.session.packages[packageId]; + if (pkg) { + this.logPackageForPackage(pkg, "INFO", "Post-Process-Slot erhalten", { + slotWaitMs + }); + } } try { let round = 0; @@ -4526,6 +4643,15 @@ export class DownloadManager extends EventEmitter { } const roundMs = nowMs() - roundStart; logger.info(`Post-Process Runde ${round} fertig in ${(roundMs / 1000).toFixed(1)}s (requeue=${hadRequeue}, nextRequeue=${this.hybridExtractRequeue.has(packageId)}): pkg=${packageId.slice(0, 8)}`); + const pkg = this.session.packages[packageId]; + if (pkg) { + this.logPackageForPackage(pkg, "INFO", "Post-Process-Runde abgeschlossen", { + round, + roundMs, + hadRequeue, + nextRequeue: this.hybridExtractRequeue.has(packageId) + }); + } this.persistSoon(); this.emitState(); // If this round was very fast (no extraction work, just a @@ -4724,6 +4850,9 @@ export class DownloadManager extends EventEmitter { } } logger.info(`Extraktion manuell wiederholt: pkg=${pkg.name}`); + this.logPackageForPackage(pkg, "INFO", "Extraktion manuell wiederholt", { + completedItems: completedItems.length + }); this.persistSoon(); this.emitState(true); void this.runPackagePostProcessing(packageId).catch((err) => logger.warn(`runPackagePostProcessing Fehler (retryExtraction): ${compactErrorText(err)}`)); @@ -4747,6 +4876,9 @@ export class DownloadManager extends EventEmitter { item.updatedAt = nowMs(); } logger.info(`Jetzt entpacken: pkg=${pkg.name}, completed=${completedItems.length}`); + this.logPackageForPackage(pkg, "INFO", "Jetzt entpacken ausgelöst", { + completedItems: completedItems.length + }); this.persistSoon(); this.emitState(true); void this.runPackagePostProcessing(packageId).catch((err) => logger.warn(`runPackagePostProcessing Fehler (extractNow): ${compactErrorText(err)}`)); @@ -4783,6 +4915,12 @@ export class DownloadManager extends EventEmitter { private removePackageFromSession(packageId: string, itemIds: string[], reason: "completed" | "deleted" = "deleted"): void { const pkg = this.session.packages[packageId]; + if (pkg) { + this.logPackageForPackage(pkg, "INFO", "Paket aus Session entfernt", { + reason, + removedItemCount: itemIds.length + }); + } // Only create history here for deletions — completions are handled by recordPackageHistory if (pkg && this.onHistoryEntryCallback && reason === "deleted" && !this.historyRecordedPackages.has(packageId)) { const allItems = itemIds.map(id => this.session.items[id]).filter(Boolean) as DownloadItem[]; @@ -5600,6 +5738,14 @@ export class DownloadManager extends EventEmitter { genericErrorRetries: Number(active.genericErrorRetries || 0), unrestrictRetries: Number(active.unrestrictRetries || 0) }); + this.logPackageForItem(item, "WARN", "Retry eingeplant", { + delayMs: waitMs, + statusText, + stallRetries: Number(active.stallRetries || 0), + unrestrictRetries: Number(active.unrestrictRetries || 0), + genericRetries: Number(active.genericErrorRetries || 0), + freshRetryUsed: Boolean(active.freshRetryUsed) + }); // Caller returns immediately after this; startItem().finally releases the active slot, // so the retry backoff never blocks a worker. this.retryAfterByItem.set(item.id, nowMs() + waitMs); @@ -5635,6 +5781,10 @@ export class DownloadManager extends EventEmitter { item.updatedAt = nowMs(); pkg.status = "downloading"; pkg.updatedAt = nowMs(); + this.logPackageForItem(item, "INFO", "Download-Slot gestartet", { + packageId, + maxParallel: Math.max(1, Number(this.settings.maxParallel) || 1) + }); const active: ActiveTask = { itemId, @@ -5692,6 +5842,10 @@ export class DownloadManager extends EventEmitter { const maxStallRetries = maxItemRetries; while (true) { try { + this.logPackageForItem(item, "INFO", "Link-Umwandlung gestartet", { + url: item.url, + retryLimit: retryDisplayLimit + }); // Wait while paused — don't check cooldown or unrestrict while paused while (this.session.paused && this.session.running && !active.abortController.signal.aborted) { item.status = "paused"; @@ -5713,9 +5867,18 @@ export class DownloadManager extends EventEmitter { const fallback = this.findFallbackProviderNotInCooldown(item); if (fallback) { logger.info(`Provider-Cooldown: ${cooldownProvider} noch ${Math.ceil(cooldownMs / 1000)}s, wechsle zu ${fallback} für ${item.fileName || item.url}`); + this.logPackageForItem(item, "WARN", "Provider-Cooldown erkannt, Fallback gewählt", { + provider: cooldownProvider, + remainingMs: cooldownMs, + fallback + }); item.provider = null; // Continue — debrid.ts will attempt providers in order and reach the fallback } else { + this.logPackageForItem(item, "WARN", "Provider-Cooldown blockiert Unrestrict", { + provider: cooldownProvider, + remainingMs: cooldownMs + }); const delayMs = Math.min(cooldownMs + 1000, 310000); this.queueRetry(item, active, delayMs, `Provider-Cooldown (${Math.ceil(delayMs / 1000)}s)`); this.persistSoon(); @@ -5723,6 +5886,10 @@ export class DownloadManager extends EventEmitter { return; } } else { + this.logPackageForItem(item, "WARN", "Provider-Cooldown blockiert Unrestrict", { + provider: cooldownProvider, + remainingMs: cooldownMs + }); const delayMs = Math.min(cooldownMs + 1000, 310000); this.queueRetry(item, active, delayMs, `Provider-Cooldown (${Math.ceil(delayMs / 1000)}s)`); this.persistSoon(); @@ -5770,6 +5937,12 @@ export class DownloadManager extends EventEmitter { item.providerAccountLabel = unrestricted.sourceAccountLabel; item.retries += unrestricted.retriesUsed; item.fileName = sanitizeFilename(unrestricted.fileName || filenameFromUrl(item.url)); + let directHost = ""; + try { + directHost = new URL(unrestricted.directUrl).host; + } catch { + directHost = ""; + } try { fs.mkdirSync(pkg.outputDir, { recursive: true }); } catch (mkdirError) { @@ -5791,11 +5964,30 @@ export class DownloadManager extends EventEmitter { item.updatedAt = nowMs(); this.emitState(); logger.info(`Download Start: ${item.fileName} (${humanSize(unrestricted.fileSize || 0)}) via ${pLabel}, pkg=${pkg.name}`); + this.logPackageForItem(item, "INFO", "Link umgewandelt", { + provider: unrestricted.provider, + providerLabel: unrestricted.providerLabel || "", + accountId: unrestricted.sourceAccountId || "", + accountLabel: unrestricted.sourceAccountLabel || "", + sizeBytes: unrestricted.fileSize, + targetPath: item.targetPath, + directHost, + directUrl: unrestricted.directUrl, + resumableHint: unrestricted.retriesUsed >= 0 + }); const maxAttempts = maxItemAttempts; let done = false; while (!done && item.attempts < maxAttempts) { item.attempts += 1; + this.logPackageForItem(item, "INFO", "Download-Versuch startet", { + attempt: item.attempts, + maxAttempts: maxAttempts === Number.MAX_SAFE_INTEGER ? "infinite" : maxAttempts, + provider: unrestricted.provider, + targetPath: item.targetPath, + existingBytes: item.downloadedBytes, + totalBytes: item.totalBytes + }); if (item.status !== "downloading") { item.status = "downloading"; item.fullStatus = `Download läuft (${statusLabel})`; @@ -5898,6 +6090,11 @@ export class DownloadManager extends EventEmitter { pkg.updatedAt = nowMs(); this.recordRunOutcome(item.id, "completed"); logger.info(`Download fertig: ${item.fileName} (${humanSize(item.downloadedBytes)}), pkg=${pkg.name}`); + this.logPackageForItem(item, "INFO", "Download abgeschlossen", { + downloadedBytes: item.downloadedBytes, + totalBytes: item.totalBytes, + autoExtract: this.settings.autoExtract + }); if (this.session.running && !active.abortController.signal.aborted) { void this.runPackagePostProcessing(pkg.id).catch((err) => { @@ -5919,6 +6116,9 @@ export class DownloadManager extends EventEmitter { const reason = active.abortReason; const claimedTargetPath = this.claimedTargetPathByItem.get(item.id) || ""; if (reason === "cancel") { + this.logPackageForItem(item, "WARN", "Download abgebrochen durch Entfernen", { + reason + }); item.status = "cancelled"; item.fullStatus = "Entfernt"; this.recordRunOutcome(item.id, "cancelled"); @@ -5935,6 +6135,9 @@ export class DownloadManager extends EventEmitter { this.dropItemContribution(item.id); this.retryStateByItem.delete(item.id); } else if (reason === "stop") { + this.logPackageForItem(item, "WARN", "Download gestoppt", { + reason + }); // If a new start() has already re-queued this item, don't overwrite // its status with "cancelled"/"Gestoppt" — the new run owns it now. if (!this.session.running) { @@ -5950,12 +6153,18 @@ export class DownloadManager extends EventEmitter { } this.retryStateByItem.delete(item.id); } else if (reason === "shutdown") { + this.logPackageForItem(item, "WARN", "Download für Shutdown geparkt", { + reason + }); item.status = "queued"; item.speedBps = 0; const activePkg = this.session.packages[item.packageId]; item.fullStatus = activePkg && !activePkg.enabled ? "Paket gestoppt" : "Wartet"; this.retryStateByItem.delete(item.id); } else if (reason === "reconnect") { + this.logPackageForItem(item, "WARN", "Download wartet auf Reconnect", { + reason + }); item.status = "queued"; item.speedBps = 0; item.fullStatus = "Wartet auf Reconnect"; @@ -5970,6 +6179,9 @@ export class DownloadManager extends EventEmitter { // Item was reset externally by resetItems/resetPackage — state already set, do nothing this.retryStateByItem.delete(item.id); } else if (reason === "package_toggle") { + this.logPackageForItem(item, "WARN", "Download wegen Paket-Toggle pausiert", { + reason + }); item.status = "queued"; item.speedBps = 0; item.fullStatus = "Paket gestoppt"; @@ -5981,6 +6193,10 @@ export class DownloadManager extends EventEmitter { }); } else if (reason === "stall") { const stallErrorText = compactErrorText(error); + this.logPackageForItem(item, "WARN", "Stall erkannt", { + error: stallErrorText, + downloadedBytes: item.downloadedBytes + }); const isSlowThroughput = stallErrorText.includes("slow_throughput"); const wasValidating = item.status === "validating"; active.stallRetries += 1; @@ -6020,7 +6236,11 @@ export class DownloadManager extends EventEmitter { const stallStat = fs.statSync(targetFile); if (stallStat.size >= expectedMin) { fileAlreadyComplete = true; - logger.info(`Stall-Recovery: ${item.fileName} ist bereits vollständig auf Disk (${humanSize(stallStat.size)}, erwartet mind. ${humanSize(expectedMin)}), überspringe Retry`); + logger.info(`Stall-Recovery: ${item.fileName} ist bereits vollständig auf Disk (${humanSize(stallStat.size)}, erwartet mind. ${humanSize(expectedMin)}), überspringe Retry`); + this.logPackageForItem(item, "INFO", "Stall-Recovery: Datei bereits vollständig", { + fileSize: stallStat.size, + expectedMin + }); item.status = "completed"; item.fullStatus = this.settings.autoExtract ? "Entpacken - Ausstehend" @@ -6084,6 +6304,10 @@ export class DownloadManager extends EventEmitter { this.retryStateByItem.delete(item.id); } else { const errorText = compactErrorText(error); + this.logPackageForItem(item, "WARN", "Download-Fehlerpfad erreicht", { + error: errorText, + abortReason: reason || "none" + }); const shouldFreshRetry = !active.freshRetryUsed && isFetchFailure(errorText); const isHttp416 = /(^|\D)416(\D|$)/.test(errorText); if (isHttp416) { @@ -6279,6 +6503,9 @@ export class DownloadManager extends EventEmitter { if (!item) { throw new Error("Download-Item fehlt"); } + const logAttemptEvent = (level: "INFO" | "WARN" | "ERROR", message: string, fields?: Record): void => { + this.logPackageForItem(item, level, message, fields); + }; const configuredRetryLimit = normalizeRetryLimit(this.settings.retryLimit); const retryDisplayLimit = retryLimitLabel(configuredRetryLimit); @@ -6307,6 +6534,15 @@ export class DownloadManager extends EventEmitter { if (existingBytes > 0) { headers.Range = `bytes=${existingBytes}-`; } + logAttemptEvent("INFO", "HTTP-Download-Versuch vorbereitet", { + attempt, + maxAttempts: maxAttempts === Number.MAX_SAFE_INTEGER ? "infinite" : maxAttempts, + directUrl, + targetPath: effectiveTargetPath, + knownTotal, + existingBytes, + rangeHeader: headers.Range || "" + }); while (this.reconnectActive()) { if (active.abortController.signal.aborted) { @@ -6336,6 +6572,10 @@ export class DownloadManager extends EventEmitter { throw error; } lastError = compactErrorText(error); + logAttemptEvent("WARN", "HTTP-Verbindung fehlgeschlagen", { + attempt, + error: lastError + }); if (attempt < maxAttempts) { item.retries += 1; item.fullStatus = `Verbindungsfehler, retry ${attempt}/${retryDisplayLimit}`; @@ -6352,6 +6592,12 @@ export class DownloadManager extends EventEmitter { } if (!response.ok) { + logAttemptEvent(response.status >= 500 ? "WARN" : "ERROR", "HTTP-Antwort nicht erfolgreich", { + attempt, + status: response.status, + statusText: response.statusText, + existingBytes + }); if (response.status === 416 && existingBytes > 0) { await response.arrayBuffer().catch(() => undefined); const rangeTotal = parseContentRangeTotal(response.headers.get("content-range")); @@ -6362,6 +6608,10 @@ export class DownloadManager extends EventEmitter { item.progressPercent = 100; item.speedBps = 0; item.updatedAt = nowMs(); + logAttemptEvent("INFO", "HTTP 416 als vollständig behandelt", { + existingBytes, + expectedTotal + }); return { resumable: true }; } // No total available but we have substantial data - assume file is complete @@ -6373,6 +6623,9 @@ export class DownloadManager extends EventEmitter { item.progressPercent = 100; item.speedBps = 0; item.updatedAt = nowMs(); + logAttemptEvent("WARN", "HTTP 416 ohne Größeninfo als vollständig behandelt", { + existingBytes + }); return { resumable: true }; } @@ -6412,6 +6665,9 @@ export class DownloadManager extends EventEmitter { } if (this.settings.autoReconnect && [429, 503].includes(response.status)) { this.requestReconnect(`HTTP ${response.status}`); + logAttemptEvent("WARN", "Reconnect angefordert wegen HTTP-Status", { + status: response.status + }); throw new Error(lastError); } throw new Error(lastError); @@ -6433,6 +6689,10 @@ export class DownloadManager extends EventEmitter { item.targetPath = effectiveTargetPath; item.updatedAt = nowMs(); this.emitState(); + logAttemptEvent("INFO", "Dateiname aus Content-Disposition übernommen", { + headerFileName: fromHeader, + newTargetPath: effectiveTargetPath + }); } } } @@ -6445,6 +6705,10 @@ export class DownloadManager extends EventEmitter { const serverIgnoredRange = existingBytes > 0 && response.status === 200; if (serverIgnoredRange) { logger.warn(`Server ignorierte Range-Header (HTTP 200 statt 206), starte von vorne: ${item.fileName}`); + logAttemptEvent("WARN", "Server ignorierte Range-Header", { + attempt, + existingBytes + }); } const rawContentLength = Number(response.headers.get("content-length") || 0); @@ -6460,6 +6724,16 @@ export class DownloadManager extends EventEmitter { } const writeMode = existingBytes > 0 && response.status === 206 ? "a" : "w"; + logAttemptEvent("INFO", "HTTP-Antwort akzeptiert", { + attempt, + status: response.status, + acceptRanges, + resumable, + contentLength, + totalFromRange, + totalBytes: item.totalBytes, + writeMode + }); if (writeMode === "w") { // Starting fresh: subtract any previously counted bytes for this item to avoid double-counting on retry const previouslyContributed = this.itemContributedBytes.get(active.itemId) || 0; @@ -6496,6 +6770,8 @@ export class DownloadManager extends EventEmitter { written = writeMode === "a" ? existingBytes : 0; let windowBytes = 0; let windowStarted = nowMs(); + let lastPackageLogAt = 0; + let lastLoggedPercent = -1; const itemCount = this.itemCount; const uiUpdateIntervalMs = itemCount >= 1500 ? 500 @@ -6520,15 +6796,19 @@ export class DownloadManager extends EventEmitter { active.blockedOnDiskSince = nowMs(); if (item.status !== "paused" && !this.session.paused) { const nowTick = nowMs(); - if (nowTick - lastDiskBusyEmitAt >= 1200) { - item.status = "downloading"; - item.speedBps = 0; - item.fullStatus = `Warte auf Festplatte (${label})`; - item.updatedAt = nowTick; - this.emitState(); - lastDiskBusyEmitAt = nowTick; + if (nowTick - lastDiskBusyEmitAt >= 1200) { + item.status = "downloading"; + item.speedBps = 0; + item.fullStatus = `Warte auf Festplatte (${label})`; + item.updatedAt = nowTick; + this.emitState(); + lastDiskBusyEmitAt = nowTick; + logAttemptEvent("WARN", "Schreibtask wartet auf Festplatte", { + attempt, + writableLength: stream.writableLength + }); + } } - } let settled = false; let timeoutId: NodeJS.Timeout | null = setTimeout(() => { @@ -6655,6 +6935,10 @@ export class DownloadManager extends EventEmitter { item.updatedAt = nowTick; this.emitState(); lastIdleEmitAt = nowTick; + logAttemptEvent("WARN", "Download wartet auf Daten", { + attempt, + idleForMs: nowTick - lastDataAt + }); } }, idlePulseMs); const readWithTimeout = async (): Promise> => { @@ -6763,6 +7047,10 @@ export class DownloadManager extends EventEmitter { item.updatedAt = nowTick; this.emitState(); lastDiskBusyEmitAt = nowTick; + logAttemptEvent("WARN", "Festplatten-Backpressure erkannt", { + attempt, + busyMs + }); } } } else { @@ -6826,6 +7114,23 @@ export class DownloadManager extends EventEmitter { item.speedBps = Math.max(0, Math.floor(speed)); item.fullStatus = `Download läuft (${label})`; } + const progressNow = nowMs(); + const currentPercent = item.totalBytes ? Math.max(0, Math.min(100, Math.floor((written / item.totalBytes) * 100))) : 0; + const shouldLogProgress = currentPercent >= lastLoggedPercent + 10 + || progressNow - lastPackageLogAt >= 5000 + || (item.totalBytes ? written >= item.totalBytes : false); + if (shouldLogProgress) { + lastPackageLogAt = progressNow; + lastLoggedPercent = currentPercent; + logAttemptEvent("INFO", "Download-Fortschritt", { + attempt, + written, + totalBytes: item.totalBytes, + percent: currentPercent, + speedBps: item.speedBps, + diskBusy + }); + } const nowTick = nowMs(); if (nowTick - lastUiEmitAt >= uiUpdateIntervalMs) { item.updatedAt = nowTick; @@ -6846,6 +7151,10 @@ export class DownloadManager extends EventEmitter { } } catch (error) { bodyError = error; + logAttemptEvent("WARN", "Download-Body fehlgeschlagen", { + attempt, + error: compactErrorText(error) + }); throw error; } finally { // Flush remaining buffered data before closing stream @@ -6963,6 +7272,14 @@ export class DownloadManager extends EventEmitter { item.fullStatus = "Finalisierend..."; item.updatedAt = nowMs(); this.emitState(); + logAttemptEvent("INFO", "HTTP-Download-Versuch abgeschlossen", { + attempt, + resumable, + written, + finalBytes: item.downloadedBytes, + totalBytes: item.totalBytes, + targetPath: effectiveTargetPath + }); return { resumable }; } catch (error) { // Truncate pre-allocated sparse file to actual written bytes so that @@ -6976,6 +7293,11 @@ export class DownloadManager extends EventEmitter { throw error; } lastError = compactErrorText(error); + logAttemptEvent("WARN", "HTTP-Download-Versuch fehlgeschlagen", { + attempt, + error: lastError, + targetPath: effectiveTargetPath + }); if (attempt < maxAttempts) { item.retries += 1; item.fullStatus = `Downloadfehler, retry ${attempt}/${retryDisplayLimit}`; @@ -7688,6 +8010,7 @@ export class DownloadManager extends EventEmitter { hybridMode: true, maxParallel: this.settings.maxParallelExtract || 2, extractCpuPriority: "high", + onLog: (level, message) => this.logPackageForPackage(pkg, level, `Hybrid-Extractor: ${message}`), onArchiveFailure: (failure) => { const failedArchiveKey = readyArchiveKeyByName.get(String(failure.archiveName || "").toLowerCase()); if (failedArchiveKey) { @@ -7825,6 +8148,10 @@ export class DownloadManager extends EventEmitter { }); logger.info(`Hybrid-Extract Ende: pkg=${pkg.name}, extracted=${result.extracted}, failed=${result.failed}`); + this.logPackageForPackage(pkg, "INFO", "Hybrid-Extract abgeschlossen", { + extracted: result.extracted, + failed: result.failed + }); // Mark all attempted archives as tried so they are not retried in subsequent // requeue rounds of the same post-processing session (prevents infinite loop // when disk-fallback archives have no corresponding session items). @@ -8003,6 +8330,14 @@ export class DownloadManager extends EventEmitter { const cancelled = items.filter((item) => item.status === "cancelled").length; const setupMs = nowMs() - handleStart; logger.info(`Post-Processing Start: pkg=${pkg.name}, success=${success}, failed=${failed}, cancelled=${cancelled}, autoExtract=${this.settings.autoExtract}, setupMs=${setupMs}, recoveryMs=${recoveryMs}`); + this.logPackageForPackage(pkg, "INFO", "Post-Processing gestartet", { + success, + failed, + cancelled, + autoExtract: this.settings.autoExtract, + setupMs, + recoveryMs + }); const allDone = success + failed + cancelled >= items.length; @@ -8126,6 +8461,7 @@ export class DownloadManager extends EventEmitter { // All downloads finished — use NORMAL OS priority so extraction runs at // full speed (matching manual 7-Zip/WinRAR speed). extractCpuPriority: "high", + onLog: (level, message) => this.logPackageForPackage(pkg, level, `Extractor: ${message}`), onArchiveFailure: (failure) => { if (autoRecoveredArchives.has(failure.archiveName)) { return; @@ -8241,6 +8577,11 @@ export class DownloadManager extends EventEmitter { } }); logger.info(`Post-Processing Entpacken Ende: pkg=${pkg.name}, extracted=${result.extracted}, failed=${result.failed}, lastError=${result.lastError || ""}`); + this.logPackageForPackage(pkg, "INFO", "Post-Processing Entpacken Ende", { + extracted: result.extracted, + failed: result.failed, + lastError: result.lastError || "" + }); extractedCount = result.extracted; const autoRecoveredPending = completedItems.some((item) => item.status === "queued"); @@ -8364,6 +8705,13 @@ export class DownloadManager extends EventEmitter { pkg.postProcessLabel = undefined; pkg.updatedAt = nowMs(); logger.info(`Post-Processing Ende: pkg=${pkg.name}, status=${pkg.status} (deferred work wird im Hintergrund ausgeführt)`); + this.logPackageForPackage(pkg, "INFO", "Post-Processing Ende", { + status: pkg.status, + success, + failed, + extractedCount, + alreadyMarkedExtracted + }); // Deferred post-extraction: Rename, MKV-Sammlung, Cleanup laufen im Hintergrund, // damit der Post-Process-Slot sofort freigegeben wird und das nächste Pack @@ -8393,6 +8741,10 @@ export class DownloadManager extends EventEmitter { pkg.postProcessLabel = "Nested Entpacken..."; this.emitState(); logger.info(`Deferred Nested-Extraction: ${nestedCandidates.length} Archive in ${pkg.extractDir}`); + this.logPackageForPackage(pkg, "INFO", "Deferred Nested-Extraction gestartet", { + nestedCandidates: nestedCandidates.length, + extractDir: pkg.extractDir + }); const nestedResult = await extractPackageArchives({ packageDir: pkg.extractDir, targetDir: pkg.extractDir, @@ -8405,9 +8757,14 @@ export class DownloadManager extends EventEmitter { onlyArchives: new Set(nestedCandidates.map((p) => process.platform === "win32" ? path.resolve(p).toLowerCase() : path.resolve(p))), maxParallel: this.settings.maxParallelExtract || 2, extractCpuPriority: this.settings.extractCpuPriority, + onLog: (level, message) => this.logPackageForPackage(pkg, level, `Nested-Extractor: ${message}`), }); extractedCount += nestedResult.extracted; logger.info(`Deferred Nested-Extraction Ende: extracted=${nestedResult.extracted}, failed=${nestedResult.failed}`); + this.logPackageForPackage(pkg, "INFO", "Deferred Nested-Extraction Ende", { + extracted: nestedResult.extracted, + failed: nestedResult.failed + }); } } @@ -8415,6 +8772,9 @@ export class DownloadManager extends EventEmitter { if (extractedCount > 0 || alreadyMarkedExtracted) { pkg.postProcessLabel = "Renaming..."; this.emitState(); + this.logPackageForPackage(pkg, "INFO", "Deferred Auto-Rename gestartet", { + extractDir: pkg.extractDir + }); await this.autoRenameExtractedVideoFiles(pkg.extractDir, pkg); } diff --git a/src/main/extractor.ts b/src/main/extractor.ts index daee8b8..d847c94 100644 --- a/src/main/extractor.ts +++ b/src/main/extractor.ts @@ -111,6 +111,7 @@ export interface ExtractOptions { maxParallel?: number; extractCpuPriority?: string; onArchiveFailure?: (failure: ExtractArchiveFailureInfo) => void; + onLog?: (level: "INFO" | "WARN" | "ERROR", message: string) => void; } export interface ExtractProgressUpdate { @@ -128,6 +129,21 @@ export interface ExtractProgressUpdate { archiveSuccess?: boolean; } +function emitExtractLog( + onLog: ExtractOptions["onLog"] | undefined, + level: "INFO" | "WARN" | "ERROR", + message: string +): void { + if (level === "INFO") { + logger.info(message); + } else if (level === "WARN") { + logger.warn(message); + } else { + logger.error(message); + } + onLog?.(level, message); +} + export interface ExtractArchiveFailureInfo { archiveName: string; errorText: string; @@ -1828,7 +1844,8 @@ async function runExternalExtract( hybridMode = false, onPasswordAttempt?: (attempt: number, total: number) => void, forceFlatMode = false, - flatModeResult?: { needed: boolean } + flatModeResult?: { needed: boolean }, + onLog?: ExtractOptions["onLog"] ): Promise { const timeoutMs = await computeExtractTimeoutMs(archivePath); const backendMode = extractorBackendMode(); @@ -1838,6 +1855,7 @@ async function runExternalExtract( let jvmCodecError = false; let fallbackFromJvm = false; logger.info(`Extract-Backend Start: archive=${archiveName}, mode=${backendMode}, pwCandidates=${passwordCandidates.length}, timeoutMs=${timeoutMs}, hybrid=${hybridMode}`); + onLog?.("INFO", `Extract-Backend Start: archive=${archiveName}, mode=${backendMode}, pwCandidates=${passwordCandidates.length}, timeoutMs=${timeoutMs}, hybrid=${hybridMode}`); await fs.promises.mkdir(targetDir, { recursive: true }); @@ -1860,6 +1878,7 @@ async function runExternalExtract( const quotedPasswords = passwordCandidates.map((p) => p === "" ? '""' : `"${p}"`); logger.info(`JVM-Extractor aktiv (${layout.rootDir}): ${archiveName}, ${passwordCandidates.length} Passwörter: [${quotedPasswords.join(", ")}]`); const jvmStartedAt = Date.now(); + onLog?.("INFO", `JVM-Extractor vorbereitet: archive=${archiveName}, passwordCandidates=${passwordCandidates.length}, layout=${layout.rootDir}`); const jvmResult = await runJvmExtractCommand( layout, archivePath, @@ -1871,6 +1890,7 @@ async function runExternalExtract( timeoutMs ); const jvmMs = Date.now() - jvmStartedAt; + onLog?.("INFO", `JVM-Extractor Ergebnis: archive=${archiveName}, ok=${jvmResult.ok}, ms=${jvmMs}, timedOut=${jvmResult.timedOut}, aborted=${jvmResult.aborted}, backend=${jvmResult.backend || "unknown"}, usedPassword=${jvmResult.usedPassword ? "yes" : "no"}`); logger.info(`JVM-Extractor Ergebnis: archive=${archiveName}, ok=${jvmResult.ok}, ms=${jvmMs}, timedOut=${jvmResult.timedOut}, aborted=${jvmResult.aborted}, backend=${jvmResult.backend || "unknown"}, usedPassword=${jvmResult.usedPassword ? "yes" : "no"}`); if (jvmResult.ok) { @@ -1896,6 +1916,7 @@ async function runExternalExtract( const isWrongPassword = jvmFailureReason.includes("WRONG_PASSWORD") || jvmFailureLower.includes("wrong password"); const shouldFallbackToLegacy = isUnsupportedMethod || isCodecError || isWrongPassword; + onLog?.("WARN", `JVM-Extractor Fallback-Analyse: archive=${archiveName}, unsupportedMethod=${isUnsupportedMethod}, codecError=${isCodecError}, wrongPassword=${isWrongPassword}, backendMode=${backendMode}`); if (backendMode === "jvm" && !shouldFallbackToLegacy) { throw new Error(jvmFailureReason); } @@ -1933,7 +1954,8 @@ async function runExternalExtract( hybridMode, onPasswordAttempt, forceFlatMode, - flatModeResult + flatModeResult, + onLog ); } catch (primaryError) { // If the primary extractor (typically 7-Zip) fails on a RAR archive, @@ -1945,6 +1967,7 @@ async function runExternalExtract( const alt = await findAlternativeExtractor(command); if (alt) { const altName = path.basename(alt).replace(/\.exe$/i, ""); + onLog?.("INFO", `Legacy-Fallback: primary=${path.basename(command)}, alternative=${altName}, archive=${archiveName}`); logger.info(`Legacy-Fallback: ${path.basename(command)} fehlgeschlagen bei RAR, versuche ${altName}: ${archiveName}`); usedCommand = alt; password = await runExternalExtractInner( @@ -1959,7 +1982,8 @@ async function runExternalExtract( hybridMode, onPasswordAttempt, forceFlatMode, - flatModeResult + flatModeResult, + onLog ); } else { throw primaryError; @@ -1984,6 +2008,7 @@ async function runExternalExtract( logger.warn( `Legacy-Extraktion fehlgeschlagen (${legacyCategory}), Retry nach ${retryDelayMs}ms Delay: ${archiveName}` ); + onLog?.("WARN", `Legacy-Extraktion fehlgeschlagen (${legacyCategory}), Retry nach ${retryDelayMs}ms Delay: ${archiveName}`); await extractRetryDelay(retryDelayMs); if (!signal?.aborted) { try { @@ -2000,15 +2025,18 @@ async function runExternalExtract( hybridMode, onPasswordAttempt, forceFlatMode, - flatModeResult + flatModeResult, + onLog ); logger.info(`Legacy-Retry erfolgreich: ${archiveName}`); + onLog?.("INFO", `Legacy-Retry erfolgreich: ${archiveName}`); password = retryPassword; usedCommand = retryCmd; } catch (retryError) { const retryText = String((retryError as Error)?.message || retryError || ""); const retryCategory = classifyExtractionError(retryText); logger.warn(`Legacy-Retry ebenfalls fehlgeschlagen (${retryCategory}): ${archiveName}`); + onLog?.("WARN", `Legacy-Retry ebenfalls fehlgeschlagen (${retryCategory}): ${archiveName}`); const suggestRedownload = jvmCodecError && (retryCategory === "crc_error" || retryCategory === "wrong_password"); throw withExtractionErrorHints(retryError, { suggestRedownload, @@ -2034,6 +2062,7 @@ async function runExternalExtract( logger.info(`Entpackt via legacy/${extractorName}: ${archiveName}`); } logger.info(`Extract-Backend Ende: archive=${archiveName}, backend=legacy/${extractorName}, mode=${backendMode}, ms=${Date.now() - totalStartedAt}, legacyMs=${legacyMs}, fallbackFromJvm=${fallbackFromJvm}, usedPassword=${password ? "yes" : "no"}`); + onLog?.("INFO", `Extract-Backend Ende: archive=${archiveName}, backend=legacy/${extractorName}, mode=${backendMode}, ms=${Date.now() - totalStartedAt}, legacyMs=${legacyMs}, fallbackFromJvm=${fallbackFromJvm}, usedPassword=${password ? "yes" : "no"}`); return password; } finally { if (subst) removeSubstMapping(subst); @@ -2052,12 +2081,14 @@ async function runExternalExtractInner( hybridMode = false, onPasswordAttempt?: (attempt: number, total: number) => void, forceFlatMode = false, - flatModeResult?: { needed: boolean } + flatModeResult?: { needed: boolean }, + onLog?: ExtractOptions["onLog"] ): Promise { const passwords = passwordCandidates; let lastError = ""; const quotedPasswords = passwords.map((p) => p === "" ? '""' : `"${p}"`); + onLog?.("INFO", `Legacy-Extractor Start: archive=${path.basename(archivePath)}, passwordCount=${passwords.length}, forceFlatMode=${forceFlatMode}, targetDir=${targetDir}`); logger.info(`Legacy-Extractor: ${path.basename(archivePath)}, ${passwords.length} Passwörter: [${quotedPasswords.join(", ")}]${forceFlatMode ? " (flat-mode cached)" : ""}`); let announcedStart = false; @@ -2068,10 +2099,12 @@ async function runExternalExtractInner( // Skip normal extraction loop if flat mode is already known to be needed for this package if (forceFlatMode) { logger.info(`Flat-Modus direkt (gespeichert vom vorherigen Archiv): ${path.basename(archivePath)}`); + onLog?.("INFO", `Flat-Modus direkt (gespeichert vom vorherigen Archiv): ${path.basename(archivePath)}`); for (const password of passwords) { if (signal?.aborted) throw new Error("aborted:extract"); passwordAttempt += 1; const quotedPw = password === "" ? '""' : `"${password}"`; + onLog?.("INFO", `Flach-Extraktion Versuch ${passwordAttempt}/${passwords.length}: archive=${path.basename(archivePath)}, password=${quotedPw}`); logger.info(`Flach-Extraktion Versuch ${passwordAttempt}/${passwords.length} für ${path.basename(archivePath)}: ${quotedPw}`); const args = buildExternalExtractArgs(command, archivePath, targetDir, conflictMode, password, usePerformanceFlags, hybridMode, true); const result = await runExtractCommand(command, args, (chunk) => { @@ -2081,6 +2114,7 @@ async function runExternalExtractInner( if (next !== bestPercent) { bestPercent = next; onArchiveProgress?.(bestPercent); } }, signal, timeoutMs); logger.info(`Flach-Extraktion Versuch ${passwordAttempt}/${passwords.length}: ok=${result.ok}, bestPercent=${bestPercent}`); + onLog?.("INFO", `Flach-Extraktion Ergebnis ${passwordAttempt}/${passwords.length}: archive=${path.basename(archivePath)}, ok=${result.ok}, timedOut=${result.timedOut}, missingCommand=${result.missingCommand}, bestPercent=${bestPercent}`); if (result.ok) { if (flatModeResult) flatModeResult.needed = true; onArchiveProgress?.(100); return password; } if (result.aborted) throw new Error("aborted:extract"); if (result.timedOut || result.missingCommand) break; @@ -2100,6 +2134,7 @@ async function runExternalExtractInner( passwordAttempt += 1; const attemptStartedAt = Date.now(); const quotedPw = password === "" ? '""' : `"${password}"`; + onLog?.("INFO", `Legacy-Passwort-Versuch ${passwordAttempt}/${passwords.length}: archive=${path.basename(archivePath)}, password=${quotedPw}`); logger.info(`Legacy-Passwort-Versuch ${passwordAttempt}/${passwords.length} für ${path.basename(archivePath)}: ${quotedPw}`); if (passwords.length > 1) { onPasswordAttempt?.(passwordAttempt, passwords.length); @@ -2120,6 +2155,7 @@ async function runExternalExtractInner( if (!result.ok && usePerformanceFlags && isUnsupportedExtractorSwitchError(result.errorText)) { usePerformanceFlags = false; externalExtractorSupportsPerfFlags = false; + onLog?.("WARN", `Entpacker ohne Performance-Flags fortgesetzt: ${path.basename(archivePath)}`); logger.warn(`Entpacker ohne Performance-Flags fortgesetzt: ${path.basename(archivePath)}`); args = buildExternalExtractArgs(command, archivePath, targetDir, conflictMode, password, false, hybridMode); result = await runExtractCommand(command, args, (chunk) => { @@ -2139,6 +2175,7 @@ async function runExternalExtractInner( `Legacy-Passwort-Versuch Ergebnis: archive=${path.basename(archivePath)}, attempt=${passwordAttempt}/${passwords.length}, ` + `ms=${Date.now() - attemptStartedAt}, ok=${result.ok}, timedOut=${result.timedOut}, missingCommand=${result.missingCommand}, bestPercent=${bestPercent}` ); + onLog?.("INFO", `Legacy-Passwort-Versuch Ergebnis: archive=${path.basename(archivePath)}, attempt=${passwordAttempt}/${passwords.length}, ms=${Date.now() - attemptStartedAt}, ok=${result.ok}, timedOut=${result.timedOut}, missingCommand=${result.missingCommand}, bestPercent=${bestPercent}`); if (result.ok) { onArchiveProgress?.(100); @@ -2603,6 +2640,7 @@ export async function extractPackageArchives(options: ExtractOptions): Promise<{ }) : allCandidates; logger.info(`Entpacken gestartet: packageDir=${options.packageDir}, targetDir=${options.targetDir}, archives=${candidates.length}${options.onlyArchives ? ` (hybrid, gesamt=${allCandidates.length})` : ""}, cleanupMode=${options.cleanupMode}, conflictMode=${options.conflictMode}`); + options.onLog?.("INFO", `Entpacken gestartet: packageDir=${options.packageDir}, targetDir=${options.targetDir}, archives=${candidates.length}${options.onlyArchives ? ` (hybrid, gesamt=${allCandidates.length})` : ""}, cleanupMode=${options.cleanupMode}, conflictMode=${options.conflictMode}`); // Disk space pre-check if (candidates.length > 0) { @@ -2645,6 +2683,7 @@ export async function extractPackageArchives(options: ExtractOptions): Promise<{ if (cachedPackagePassword) { passwordCandidates = prioritizePassword(passwordCandidates, cachedPackagePassword); logger.info(`Passwort-Cache Treffer: ${passwordCacheLabel}, bekanntes Passwort wird zuerst getestet`); + options.onLog?.("INFO", `Passwort-Cache Treffer: ${passwordCacheLabel}, bekanntes Passwort wird zuerst getestet`); } const resumeCompleted = await readExtractResumeState(options.packageDir, options.packageId); const resumeCompletedAtStart = resumeCompleted.size; @@ -2684,6 +2723,7 @@ export async function extractPackageArchives(options: ExtractOptions): Promise<{ writeCachedPackagePassword(passwordCacheKey, normalized); if (changed) { logger.info(`Passwort-Cache Update: ${passwordCacheLabel}, neues Passwort gelernt`); + options.onLog?.("INFO", `Passwort-Cache Update: ${passwordCacheLabel}, neues Passwort gelernt`); } }; @@ -2803,12 +2843,18 @@ export async function extractPackageArchives(options: ExtractOptions): Promise<{ } logger.info(`Entpacke Archiv: ${path.basename(archivePath)} -> ${options.targetDir}${hybrid ? " (hybrid, reduced threads, low I/O)" : ""}`); + options.onLog?.("INFO", `Entpacke Archiv: ${path.basename(archivePath)} -> ${options.targetDir}${hybrid ? " (hybrid, reduced threads, low I/O)" : ""}`); + options.onLog?.("INFO", `Archiv-Passwortliste: archive=${archiveName}, candidates=[${archivePasswordCandidates.map((p) => p === "" ? '""' : `"${p}"`).join(", ")}]`); const hasManyPasswords = archivePasswordCandidates.length > 1; if (hasManyPasswords) { emitProgress(extracted + failed, archiveName, "extracting", 0, 0, { passwordAttempt: 0, passwordTotal: archivePasswordCandidates.length }); } const onPwAttempt = hasManyPasswords - ? (attempt: number, total: number) => { emitProgress(extracted + failed, archiveName, "extracting", archivePercent, Date.now() - archiveStartedAt, { passwordAttempt: attempt, passwordTotal: total }); } + ? (attempt: number, total: number) => { + emitProgress(extracted + failed, archiveName, "extracting", archivePercent, Date.now() - archiveStartedAt, { passwordAttempt: attempt, passwordTotal: total }); + const attemptedPassword = archivePasswordCandidates[Math.max(0, attempt - 1)] ?? ""; + options.onLog?.("INFO", `Passwort-Versuch ${attempt}/${total}: archive=${archiveName}, password=${attemptedPassword === "" ? '""' : `"${attemptedPassword}"`}`); + } : undefined; try { // Set module-level priority before each extract call (race-safe: spawn is synchronous) @@ -2820,7 +2866,7 @@ export async function extractPackageArchives(options: ExtractOptions): Promise<{ try { const usedPassword = await runExternalExtract(archivePath, options.targetDir, options.conflictMode, archivePasswordCandidates, (value) => { reportArchiveProgress(value); - }, options.signal, hybrid, onPwAttempt); + }, options.signal, hybrid, onPwAttempt, false, undefined, options.onLog); rememberLearnedPassword(usedPassword); } catch (error) { if (isNoExtractorError(String(error))) { @@ -2840,7 +2886,7 @@ export async function extractPackageArchives(options: ExtractOptions): Promise<{ try { const usedPassword = await runExternalExtract(archivePath, options.targetDir, options.conflictMode, archivePasswordCandidates, (value) => { reportArchiveProgress(value); - }, options.signal, hybrid, onPwAttempt); + }, options.signal, hybrid, onPwAttempt, false, undefined, options.onLog); rememberLearnedPassword(usedPassword); } catch (externalError) { if (isNoExtractorError(String(externalError)) || isUnsupportedArchiveFormatError(String(externalError))) { @@ -2854,7 +2900,7 @@ export async function extractPackageArchives(options: ExtractOptions): Promise<{ const flatResult = { needed: false }; const usedPassword = await runExternalExtract(archivePath, options.targetDir, options.conflictMode, archivePasswordCandidates, (value) => { reportArchiveProgress(value); - }, options.signal, hybrid, onPwAttempt, packageNeedsFlatMode, flatResult); + }, options.signal, hybrid, onPwAttempt, packageNeedsFlatMode, flatResult, options.onLog); rememberLearnedPassword(usedPassword); if (flatResult.needed) packageNeedsFlatMode = true; } @@ -2863,6 +2909,7 @@ export async function extractPackageArchives(options: ExtractOptions): Promise<{ resumeCompleted.add(archiveResumeKey); await writeExtractResumeState(options.packageDir, resumeCompleted, options.packageId); logger.info(`Entpacken erfolgreich: ${path.basename(archivePath)}`); + options.onLog?.("INFO", `Entpacken erfolgreich: ${path.basename(archivePath)}`); archiveOutcome = "success"; const successAt = Date.now(); const tailAfter99Ms = reached99At ? (successAt - reached99At) : -1; @@ -2891,10 +2938,12 @@ export async function extractPackageArchives(options: ExtractOptions): Promise<{ jvmFailureReason: hintedError?.jvmFailureReason }); logger.error(`Entpack-Fehler ${path.basename(archivePath)} [${errorCategory}]: ${errorText}`); + options.onLog?.("ERROR", `Entpack-Fehler ${path.basename(archivePath)} [${errorCategory}]: ${errorText}`); if (errorCategory === "wrong_password" && learnedPassword) { learnedPassword = ""; clearCachedPackagePassword(passwordCacheKey); logger.warn(`Passwort-Cache verworfen: ${passwordCacheLabel} (wrong_password)`); + options.onLog?.("WARN", `Passwort-Cache verworfen: ${passwordCacheLabel} (wrong_password)`); } const failedAt = Date.now(); const tailAfter99Ms = reached99At ? (failedAt - reached99At) : -1; @@ -2932,6 +2981,7 @@ export async function extractPackageArchives(options: ExtractOptions): Promise<{ let parallelQueue = pendingCandidates; if (passwordCandidates.length > 1 && pendingCandidates.length > 1) { logger.info(`Passwort-Discovery: Extrahiere erstes Archiv seriell (${passwordCandidates.length} Passwort-Kandidaten)...`); + options.onLog?.("INFO", `Passwort-Discovery: Extrahiere erstes Archiv seriell (${passwordCandidates.length} Passwort-Kandidaten)...`); const first = pendingCandidates[0]; try { await extractSingleArchive(first); @@ -3062,11 +3112,11 @@ export async function extractPackageArchives(options: ExtractOptions): Promise<{ nestedPercent = 100; } catch (zipErr) { if (!shouldFallbackToExternalZip(zipErr)) throw zipErr; - const usedPw = await runExternalExtract(nestedArchive, options.targetDir, options.conflictMode, passwordCandidates, (v) => { nestedPercent = Math.max(nestedPercent, v); }, options.signal, hybrid); + const usedPw = await runExternalExtract(nestedArchive, options.targetDir, options.conflictMode, passwordCandidates, (v) => { nestedPercent = Math.max(nestedPercent, v); }, options.signal, hybrid, undefined, false, undefined, options.onLog); rememberLearnedPassword(usedPw); } } else { - const usedPw = await runExternalExtract(nestedArchive, options.targetDir, options.conflictMode, passwordCandidates, (v) => { nestedPercent = Math.max(nestedPercent, v); }, options.signal, hybrid); + const usedPw = await runExternalExtract(nestedArchive, options.targetDir, options.conflictMode, passwordCandidates, (v) => { nestedPercent = Math.max(nestedPercent, v); }, options.signal, hybrid, undefined, false, undefined, options.onLog); rememberLearnedPassword(usedPw); } extracted += 1; diff --git a/src/main/main.ts b/src/main/main.ts index 1d67b10..92efb13 100644 --- a/src/main/main.ts +++ b/src/main/main.ts @@ -500,6 +500,14 @@ function registerIpcHandlers(): void { } }); + ipcMain.handle(IPC_CHANNELS.OPEN_PACKAGE_LOG, async (_event: IpcMainInvokeEvent, packageId: string) => { + validateString(packageId, "packageId"); + const logPath = controller.getPackageLogPath(packageId); + if (logPath) { + await shell.openPath(logPath); + } + }); + ipcMain.handle(IPC_CHANNELS.OPEN_REALDEBRID_LOGIN, async () => { await controller.openRealDebridLoginWindow(); }); diff --git a/src/main/package-log.ts b/src/main/package-log.ts new file mode 100644 index 0000000..2f22449 --- /dev/null +++ b/src/main/package-log.ts @@ -0,0 +1,219 @@ +import fs from "node:fs"; +import path from "node:path"; + +const PACKAGE_LOG_FLUSH_INTERVAL_MS = 200; +const PACKAGE_LOG_RETENTION_DAYS = 30; + +type PackageLogLevel = "INFO" | "WARN" | "ERROR"; + +export interface PackageLogMeta { + packageId: string; + name: string; + outputDir: string; + extractDir: string; +} + +let packageLogsDir: string | null = null; +const knownLogPaths = new Map(); +const pendingLinesByPackage = new Map(); +const initializedThisProcess = new Set(); +let flushTimer: NodeJS.Timeout | null = null; + +function normalizePackageId(packageId: string): string { + return String(packageId || "").trim(); +} + +function sanitizeFieldValue(value: unknown): string { + if (value === undefined || value === null) { + return ""; + } + if (typeof value === "string") { + return value.replace(/\r?\n/g, "\\n"); + } + if (typeof value === "number" || typeof value === "boolean") { + return String(value); + } + try { + return JSON.stringify(value).replace(/\r?\n/g, "\\n"); + } catch { + return String(value); + } +} + +function formatFields(fields?: Record): string { + if (!fields) { + return ""; + } + const parts = Object.entries(fields) + .filter(([, value]) => value !== undefined && value !== null && sanitizeFieldValue(value) !== "") + .map(([key, value]) => `${key}=${sanitizeFieldValue(value)}`); + return parts.length > 0 ? ` | ${parts.join(" | ")}` : ""; +} + +function getPackageLogFilePath(packageId: string): string | null { + const normalized = normalizePackageId(packageId); + if (!normalized || !packageLogsDir) { + return null; + } + const existing = knownLogPaths.get(normalized); + if (existing) { + return existing; + } + const logPath = path.join(packageLogsDir, `package_${normalized}.txt`); + knownLogPaths.set(normalized, logPath); + return logPath; +} + +function flushPending(): void { + for (const [packageId, lines] of pendingLinesByPackage.entries()) { + if (lines.length === 0) { + continue; + } + const logPath = getPackageLogFilePath(packageId); + if (!logPath) { + continue; + } + const chunk = lines.join(""); + pendingLinesByPackage.set(packageId, []); + try { + fs.appendFileSync(logPath, chunk, "utf8"); + } catch { + // ignore write errors + } + } +} + +function scheduleFlush(): void { + if (flushTimer) { + return; + } + flushTimer = setTimeout(() => { + flushTimer = null; + flushPending(); + }, PACKAGE_LOG_FLUSH_INTERVAL_MS); +} + +async function cleanupOldPackageLogs(dir: string): Promise { + try { + const files = await fs.promises.readdir(dir); + const cutoff = Date.now() - PACKAGE_LOG_RETENTION_DAYS * 24 * 60 * 60 * 1000; + for (const file of files) { + if (!file.startsWith("package_") || !file.endsWith(".txt")) { + continue; + } + const filePath = path.join(dir, file); + try { + const stat = await fs.promises.stat(filePath); + if (stat.mtimeMs < cutoff) { + await fs.promises.unlink(filePath); + } + } catch { + // ignore locked/missing files + } + } + } catch { + // ignore missing dir + } +} + +function appendLine(packageId: string, line: string): void { + const normalized = normalizePackageId(packageId); + if (!normalized) { + return; + } + const lines = pendingLinesByPackage.get(normalized) || []; + lines.push(line); + pendingLinesByPackage.set(normalized, lines); + scheduleFlush(); +} + +export function initPackageLogs(baseDir: string): void { + packageLogsDir = path.join(baseDir, "package-logs"); + try { + fs.mkdirSync(packageLogsDir, { recursive: true }); + } catch { + packageLogsDir = null; + return; + } + void cleanupOldPackageLogs(packageLogsDir); +} + +export function ensurePackageLog(meta: PackageLogMeta): string | null { + const packageId = normalizePackageId(meta.packageId); + const logPath = getPackageLogFilePath(packageId); + if (!logPath) { + return null; + } + try { + fs.mkdirSync(path.dirname(logPath), { recursive: true }); + if (!fs.existsSync(logPath)) { + fs.writeFileSync(logPath, "", "utf8"); + } + if (!initializedThisProcess.has(packageId)) { + initializedThisProcess.add(packageId); + const startedAt = new Date().toISOString(); + fs.appendFileSync( + logPath, + `=== Paket-Log Start: ${startedAt} | packageId=${packageId} | name=${sanitizeFieldValue(meta.name)} ===\n`, + "utf8" + ); + fs.appendFileSync( + logPath, + `${new Date().toISOString()} [INFO] Paket-Kontext initialisiert${formatFields({ + name: meta.name, + outputDir: meta.outputDir, + extractDir: meta.extractDir + })}\n`, + "utf8" + ); + } + } catch { + return null; + } + return logPath; +} + +export function logPackageEvent( + packageId: string, + level: PackageLogLevel, + message: string, + fields?: Record +): void { + const logPath = getPackageLogFilePath(packageId); + if (!logPath) { + return; + } + const line = `${new Date().toISOString()} [${level}] ${message}${formatFields(fields)}\n`; + appendLine(packageId, line); +} + +export function getPackageLogPath(packageId: string): string | null { + const logPath = getPackageLogFilePath(packageId); + if (!logPath) { + return null; + } + return fs.existsSync(logPath) ? logPath : null; +} + +export function shutdownPackageLogs(): void { + if (flushTimer) { + clearTimeout(flushTimer); + flushTimer = null; + } + flushPending(); + for (const packageId of knownLogPaths.keys()) { + const logPath = getPackageLogFilePath(packageId); + if (!logPath) { + continue; + } + try { + fs.appendFileSync(logPath, `=== Paket-Log Ende: ${new Date().toISOString()} ===\n`, "utf8"); + } catch { + // ignore + } + } + pendingLinesByPackage.clear(); + knownLogPaths.clear(); + initializedThisProcess.clear(); + packageLogsDir = null; +} diff --git a/src/preload/preload.ts b/src/preload/preload.ts index 91686f5..ccd0935 100644 --- a/src/preload/preload.ts +++ b/src/preload/preload.ts @@ -56,6 +56,7 @@ const api: ElectronApi = { importBackup: (): Promise<{ restored: boolean; message: string }> => ipcRenderer.invoke(IPC_CHANNELS.IMPORT_BACKUP), openLog: (): Promise => ipcRenderer.invoke(IPC_CHANNELS.OPEN_LOG), openSessionLog: (): Promise => ipcRenderer.invoke(IPC_CHANNELS.OPEN_SESSION_LOG), + openPackageLog: (packageId: string): Promise => ipcRenderer.invoke(IPC_CHANNELS.OPEN_PACKAGE_LOG, packageId), openRealDebridLogin: (): Promise => ipcRenderer.invoke(IPC_CHANNELS.OPEN_REALDEBRID_LOGIN), openAllDebridLogin: (): Promise => ipcRenderer.invoke(IPC_CHANNELS.OPEN_ALLDEBRID_LOGIN), importBestDebridCookies: (): Promise => ipcRenderer.invoke(IPC_CHANNELS.IMPORT_BESTDEBRID_COOKIES), diff --git a/src/renderer/App.tsx b/src/renderer/App.tsx index 7dcd0ec..81ca1d7 100644 --- a/src/renderer/App.tsx +++ b/src/renderer/App.tsx @@ -5098,6 +5098,14 @@ export function App(): ReactElement {
+ {hasPackages && !contextMenu.itemId && ( + + )}
{hasPackages && !contextMenu.itemId && (