Add more logging and analytics to updater processes (#6208)

This commit is contained in:
Zane
2026-01-05 09:35:05 -08:00
committed by GitHub
parent 85aee9c5b7
commit 901cac9441
3 changed files with 446 additions and 57 deletions
+71 -4
View File
@@ -32,20 +32,32 @@ export class GitHubUpdater {
private readonly apiUrl = `https://api.github.com/repos/${this.owner}/${this.repo}/releases/latest`;
async checkForUpdates(): Promise<UpdateCheckResult> {
const startTime = Date.now();
try {
log.info('GitHubUpdater: Checking for updates via GitHub API...');
log.info('=== GitHubUpdater: STARTING UPDATE CHECK ===');
log.info(`GitHubUpdater: API URL: ${this.apiUrl}`);
log.info(`GitHubUpdater: Current app version: ${app.getVersion()}`);
log.info(`GitHubUpdater: Timestamp: ${new Date().toISOString()}`);
log.info('GitHubUpdater: Initiating fetch request...');
const controller = new AbortController();
const timeoutId = setTimeout(() => {
log.error('GitHubUpdater: Fetch request timed out after 30 seconds');
controller.abort();
}, 30000);
const response = await fetch(this.apiUrl, {
headers: {
Accept: 'application/vnd.github.v3+json',
'User-Agent': `Goose-Desktop/${app.getVersion()}`,
},
signal: controller.signal,
});
clearTimeout(timeoutId);
const fetchDuration = Date.now() - startTime;
log.info(
`GitHubUpdater: GitHub API response status: ${response.status} ${response.statusText}`
`GitHubUpdater: GitHub API response status: ${response.status} ${response.statusText} (took ${fetchDuration}ms)`
);
if (!response.ok) {
@@ -150,10 +162,20 @@ export class GitHubUpdater {
latestVersion: string,
onProgress?: (percent: number) => void
): Promise<{ success: boolean; downloadPath?: string; extractedPath?: string; error?: string }> {
const downloadStartTime = Date.now();
try {
log.info(`GitHubUpdater: Downloading update from ${downloadUrl}`);
log.info('=== GitHubUpdater: STARTING DOWNLOAD ===');
log.info(`GitHubUpdater: Download URL: ${downloadUrl}`);
log.info(`GitHubUpdater: Version: ${latestVersion}`);
log.info(`GitHubUpdater: Timestamp: ${new Date().toISOString()}`);
log.info('GitHubUpdater: Initiating download fetch request...');
const response = await fetch(downloadUrl);
const fetchDuration = Date.now() - downloadStartTime;
log.info(
`GitHubUpdater: Download response received in ${fetchDuration}ms - Status: ${response.status} ${response.statusText}`
);
if (!response.ok) {
throw new Error(`Download failed: ${response.status} ${response.statusText}`);
}
@@ -161,16 +183,22 @@ export class GitHubUpdater {
// Get total size from headers
const contentLength = response.headers.get('content-length');
const totalSize = contentLength ? parseInt(contentLength, 10) : 0;
log.info(
`GitHubUpdater: Content-Length: ${totalSize} bytes (${(totalSize / 1024 / 1024).toFixed(2)} MB)`
);
if (!response.body) {
throw new Error('Response body is null');
}
let lastReportedPercent = -1; // Track last reported percentage to throttle updates
let lastLoggedPercent = -1; // Track for logging at 10% intervals
// Read the response stream
log.info('GitHubUpdater: Starting to read response stream...');
const reader = response.body.getReader();
const chunks: Uint8Array[] = [];
let downloadedSize = 0;
let lastProgressTime = Date.now();
while (true) {
const { done, value } = await reader.read();
@@ -187,27 +215,66 @@ export class GitHubUpdater {
if (percent !== lastReportedPercent) {
onProgress(percent);
lastReportedPercent = percent;
// Log at 10% intervals for debugging
if (percent % 10 === 0 && percent !== lastLoggedPercent) {
const elapsed = Date.now() - downloadStartTime;
const speed = downloadedSize / (elapsed / 1000) / 1024; // KB/s
log.info(
`GitHubUpdater: Download progress ${percent}% (${(downloadedSize / 1024 / 1024).toFixed(2)}/${(totalSize / 1024 / 1024).toFixed(2)} MB) @ ${speed.toFixed(0)} KB/s`
);
lastLoggedPercent = percent;
}
}
}
// Warn if no progress for 30 seconds
const now = Date.now();
if (now - lastProgressTime > 30000) {
log.warn(
`GitHubUpdater: Download appears slow - no significant progress in 30 seconds (${downloadedSize}/${totalSize} bytes)`
);
lastProgressTime = now;
} else if (value.length > 0) {
lastProgressTime = now;
}
}
const downloadDuration = Date.now() - downloadStartTime;
const avgSpeed = downloadedSize / (downloadDuration / 1000) / 1024;
log.info(
`GitHubUpdater: Download stream complete - ${downloadedSize} bytes in ${downloadDuration}ms (avg ${avgSpeed.toFixed(0)} KB/s)`
);
// Combine chunks into a single buffer
log.info('GitHubUpdater: Combining chunks into buffer...');
// eslint-disable-next-line no-undef
const buffer = Buffer.concat(chunks.map((chunk) => Buffer.from(chunk)));
log.info(`GitHubUpdater: Buffer created - ${buffer.length} bytes`);
// Save to Downloads directory
const downloadsDir = path.join(os.homedir(), 'Downloads');
const fileName = `goose-${latestVersion}.zip`;
const downloadPath = path.join(downloadsDir, fileName);
log.info(`GitHubUpdater: Writing file to ${downloadPath}...`);
await fs.writeFile(downloadPath, buffer);
log.info(`GitHubUpdater: Update downloaded to ${downloadPath}`);
const totalDuration = Date.now() - downloadStartTime;
log.info(`=== GitHubUpdater: DOWNLOAD COMPLETE in ${totalDuration}ms ===`);
log.info(`GitHubUpdater: File saved to ${downloadPath}`);
// Return success - user will handle extraction manually
return { success: true, downloadPath, extractedPath: downloadsDir };
} catch (error) {
const duration = Date.now() - downloadStartTime;
log.error(`=== GitHubUpdater: DOWNLOAD FAILED after ${duration}ms ===`);
log.error('GitHubUpdater: Error downloading update:', error);
log.error('GitHubUpdater: Download error details:', {
message: error instanceof Error ? error.message : 'Unknown error',
stack: error instanceof Error ? error.stack : 'No stack',
name: error instanceof Error ? error.name : 'Unknown',
});
return {
success: false,
error: error instanceof Error ? error.message : 'Unknown error',