feat(sync): enhance sync engine with logging and routing logic for improved operation tracking

Author: ErcinDedeoglu

src/plugin/plugin.ts

@@ -217,18 +217,25 @@ function performInitialSync(pathConfig: PathConfig): void {
   void (async () => {
     try {
       log('Running initial sync in background...');
-      const { categories } = await loadLocalData(pathConfig, config.sync);
+      const loadStart = Date.now();
+      const { categories, errors } = await loadLocalData(pathConfig, config.sync);
+      log(`Loaded ${String(categories.length)} categories in ${String(Date.now() - loadStart)}ms`);
+      if (errors.length > 0) log(`Load errors: ${String(errors.length)}`);
+
+      const syncStart = Date.now();
       const result = await engine.sync(categories);
+      const dur = Date.now() - syncStart;
 
       if (result.success && result.action !== 'error') {
         await persistLocalState(pathConfig);
-        log(`Initial sync complete: ${result.message}`);
+        log(`Initial sync complete in ${String(dur)}ms: ${result.message}`);
       } else {
-        log(`Sync completed: ${result.message}`);
+        log(`Sync completed in ${String(dur)}ms: ${result.message}`);
       }
     } catch (error) {
       const errMsg = error instanceof Error ? error.message : String(error);
       log(`WARNING: Initial sync failed: ${errMsg}`);
+      if (error instanceof Error && error.stack) log(`Stack: ${error.stack}`);
     }
   })();
 }

src/storage/repo/fetch.ts

@@ -4,26 +4,37 @@
 
 import { RepoApiError, RepoRateLimitError } from './errors.js';
 
+/** Default timeout for API requests (30 seconds) */
+const DEFAULT_TIMEOUT_MS = 30000;
+
 /**
- * Fetch with exponential backoff retry.
+ * Fetch with exponential backoff retry and timeout.
+ * Handles rate limits by waiting until reset time.
  */
 export async function fetchWithRetry(
   url: string,
   options: RequestInit,
   maxRetries: number,
-  retryDelayMs: number
+  retryDelayMs: number,
+  timeoutMs: number = DEFAULT_TIMEOUT_MS
 ): Promise<Response> {
   let lastError: Error | undefined;
 
   for (let attempt = 0; attempt <= maxRetries; attempt++) {
-    const result = await attemptFetch(url, options);
+    const result = await attemptFetch(url, options, timeoutMs);
     if (result.response) return result.response;
     if (result.shouldThrow && result.error) throw result.error;
     lastError = result.error;
 
     if (attempt < maxRetries) {
-      const delay = retryDelayMs * Math.pow(2, attempt);
-      await sleep(delay);
+      // For rate limit errors, wait until reset time (max 60s)
+      if (lastError instanceof RepoRateLimitError) {
+        const waitTime = Math.min(lastError.resetTimestamp * 1000 - Date.now(), 60000);
+        if (waitTime > 0) await sleep(waitTime);
+      } else {
+        const delay = retryDelayMs * Math.pow(2, attempt);
+        await sleep(delay);
+      }
     }
   }
 
@@ -36,32 +47,72 @@ interface FetchResult {
   shouldThrow?: boolean;
 }
 
-async function attemptFetch(url: string, options: RequestInit): Promise<FetchResult> {
+async function attemptFetch(
+  url: string,
+  options: RequestInit,
+  timeoutMs: number
+): Promise<FetchResult> {
   try {
-    const response = await fetch(url, options);
-    checkRateLimit(response);
+    const controller = new AbortController();
+    const timeoutId = setTimeout(() => {
+      controller.abort();
+    }, timeoutMs);
 
-    if (!response.ok) {
-      const error = await createApiError(response);
-      return { error, shouldThrow: isNonRetryableError(error) };
-    }
+    try {
+      const response = await fetch(url, { ...options, signal: controller.signal });
+      clearTimeout(timeoutId);
+      checkRateLimit(response);
+
+      if (!response.ok) {
+        const error = await createApiError(response);
+        return { error, shouldThrow: isNonRetryableError(error) };
+      }
 
-    return { response };
+      return { response };
+    } finally {
+      clearTimeout(timeoutId);
+    }
   } catch (error) {
     const err = error as Error;
+    // Convert abort errors to timeout errors
+    if (err.name === 'AbortError') {
+      return {
+        error: new Error(`Request timeout after ${String(timeoutMs)}ms`),
+        shouldThrow: false,
+      };
+    }
     return { error: err, shouldThrow: isNonRetryableError(err) };
   }
 }
 
 function checkRateLimit(response: Response): void {
-  if (response.status !== 403) return;
+  // Handle 429 Too Many Requests
+  if (response.status === 429) {
+    const retryAfter = response.headers.get('Retry-After');
+    const resetTimestamp = retryAfter
+      ? Date.now() / 1000 + parseInt(retryAfter, 10)
+      : Date.now() / 1000 + 60;
+    throw new RepoRateLimitError(resetTimestamp);
+  }
+
+  // Handle 403 with rate limit or abuse detection
+  if (response.status === 403) {
+    const remaining = response.headers.get('X-RateLimit-Remaining');
+    const retryAfter = response.headers.get('Retry-After');
 
-  const remaining = response.headers.get('X-RateLimit-Remaining');
-  if (remaining !== '0') return;
+    // Secondary rate limit (abuse detection) includes Retry-After
+    if (retryAfter) {
+      const resetTimestamp = Date.now() / 1000 + parseInt(retryAfter, 10);
+      throw new RepoRateLimitError(resetTimestamp);
+    }
 
-  const resetTime = response.headers.get('X-RateLimit-Reset');
-  const resetTimestamp = resetTime ? parseInt(resetTime, 10) : Date.now() / 1000 + 60;
-  throw new RepoRateLimitError(resetTimestamp);
+    // Primary rate limit
+    if (remaining === '0') {
+      const resetTime = response.headers.get('X-RateLimit-Reset');
+      const resetTimestamp = resetTime ? parseInt(resetTime, 10) : Date.now() / 1000 + 60;
+      throw new RepoRateLimitError(resetTimestamp);
+    }
+  }
 }
 
 async function createApiError(response: Response): Promise<RepoApiError> {

src/storage/repo/repo-client.ts

@@ -126,25 +126,51 @@ export class RepoStorageBackend implements StorageBackend {
   }
 
   public async updateFiles(files: Record<string, string | null>): Promise<void> {
+    const fileCount = Object.keys(files).length;
+    const startTime = Date.now();
+
     // Get current HEAD commit SHA
     const headSha = await this.getHeadSha();
 
     // Get current tree
     const currentTree = await this.getTree(headSha);
 
-    // Build new tree entries
+    // Build new tree entries (includes blob creation)
+    const blobStart = Date.now();
     const treeEntries = await this.buildTreeEntries(files, currentTree);
+    const blobDuration = Date.now() - blobStart;
+    this.logProgress(`Created ${String(treeEntries.length)} blobs in ${String(blobDuration)}ms`);
 
     // Create new tree
     const newTreeSha = await this.createTree(treeEntries, currentTree.sha);
 
     // Create commit
-    const fileCount = String(Object.keys(files).length);
-    const message = `Sync update: ${fileCount} files`;
+    const message = `Sync update: ${String(fileCount)} files`;
     const commitSha = await this.createCommit(message, newTreeSha, headSha);
 
     // Update HEAD ref
     await this.updateRef(commitSha);
+
+    const totalDuration = Date.now() - startTime;
+    this.logProgress(`Upload complete: ${String(fileCount)} files in ${String(totalDuration)}ms`);
+  }
+
+  /** Log progress for debugging */
+  private logProgress(message: string): void {
+    try {
+      // Use dynamic require to avoid module resolution issues
+      /* eslint-disable @typescript-eslint/no-require-imports */
+      const os = require('node:os') as { homedir: () => string };
+      const fs = require('node:fs') as { appendFileSync: (path: string, data: string) => void };
+      const path = require('node:path') as { join: (...parts: string[]) => string };
+      /* eslint-enable @typescript-eslint/no-require-imports */
+      const logDir = path.join(os.homedir(), '.local/share/opencode/log');
+      const logFile = path.join(logDir, 'opencode-sync.log');
+      const timestamp = new Date().toISOString();
+      fs.appendFileSync(logFile, `${timestamp} [opencode-sync] [REPO] ${message}\n`);
+    } catch {
+      // Ignore logging errors
+    }
   }
 
   public async listFiles(): Promise<StorageFile[]> {
@@ -329,28 +355,68 @@ export class RepoStorageBackend implements StorageBackend {
       .filter((e) => !updatedPaths.has(e.path))
       .map((e) => ({ path: e.path, mode: e.mode, type: e.type, sha: e.sha }));
 
-    // Add new/updated files
+    // Collect files that need blob creation
+    const filesToUpload: { path: string; content: string }[] = [];
     for (const [path, content] of Object.entries(files)) {
-      const fullPath = `${SYNC_DIR}/${path}`;
-
-      if (content === null) {
-        // File deletion - already excluded from entries
-        continue;
+      if (content !== null) {
+        filesToUpload.push({ path: `${SYNC_DIR}/${path}`, content });
       }
+    }
 
-      // Create blob for new content
-      const blobSha = await this.createBlob(content);
+    // Create blobs in small parallel batches with delays to avoid secondary rate limits
+    const BATCH_SIZE = 5;
+    const blobResults = await this.createBlobsInBatches(filesToUpload, BATCH_SIZE);
+
+    // Add new entries from batch results
+    for (const result of blobResults) {
       entries.push({
-        path: fullPath,
+        path: result.path,
         mode: '100644',
         type: 'blob',
-        sha: blobSha,
+        sha: result.sha,
       });
     }
 
     return entries;
   }
 
+  /**
+   * Create blobs in parallel batches with rate limit protection.
+   * Uses small batches with delays to avoid GitHub's secondary rate limits.
+   */
+  private async createBlobsInBatches(
+    files: { path: string; content: string }[],
+    batchSize: number
+  ): Promise<{ path: string; sha: string }[]> {
+    const results: { path: string; sha: string }[] = [];
+    const totalBatches = Math.ceil(files.length / batchSize);
+
+    for (let i = 0; i < files.length; i += batchSize) {
+      const batchNum = Math.floor(i / batchSize) + 1;
+      const batch = files.slice(i, i + batchSize);
+
+      if (files.length > batchSize) {
+        this.logProgress(
+          `Batch ${String(batchNum)}/${String(totalBatches)} (${String(batch.length)} files)`
+        );
+      }
+
+      const batchPromises = batch.map(async (file) => {
+        const sha = await this.createBlob(file.content);
+        return { path: file.path, sha };
+      });
+      const batchResults = await Promise.all(batchPromises);
+      results.push(...batchResults);
+
+      // Add delay between batches to avoid secondary rate limits
+      if (i + batchSize < files.length) {
+        await new Promise((r) => setTimeout(r, 100));
+      }
+    }
+
+    return results;
+  }
+
   private async createBlob(content: string): Promise<string> {
     const body = JSON.stringify({
       content: Buffer.from(content).toString('base64'),

src/sync/engine/index.ts

@@ -18,4 +18,6 @@ export {
   buildNoChangeResult,
   handleSyncError,
 } from './result.js';
+export { syncLog, startOperation } from './logger.js';
 export { checkMaxRetries, calculateBackoff, sleep, MAX_CONFLICT_RETRIES } from './retry.js';
+export { determineAction, executeRoute } from './routing.js';

src/sync/engine/logger.ts

@@ -0,0 +1,50 @@
+/**
+ * Sync Engine Logger
+ *
+ * Provides logging for sync operations with timestamps.
+ * Uses file-based logging for persistence across sessions.
+ */
+
+import { homedir } from 'node:os';
+import { appendFileSync } from 'node:fs';
+import { join } from 'node:path';
+
+const LOG_PREFIX = '[opencode-sync]';
+
+/**
+ * Log a sync message to the log file.
+ */
+export function syncLog(message: string): void {
+  const timestamp = new Date().toISOString();
+  const logMessage = `${timestamp} ${LOG_PREFIX} ${message}`;
+
+  try {
+    const logDir = join(homedir(), '.local/share/opencode/log');
+    const logFile = join(logDir, 'opencode-sync.log');
+    appendFileSync(logFile, logMessage + '\n');
+  } catch {
+    // Fallback to console if file write fails
+    console.error(logMessage);
+  }
+}
+
+/**
+ * Log a sync operation with timing.
+ * Returns a function to call when the operation completes.
+ */
+export function startOperation(name: string): (result?: string) => void {
+  const start = Date.now();
+  syncLog(`[SYNC] Starting: ${name}`);
+  return (result?: string) => {
+    const duration = Date.now() - start;
+    const suffix = result ? ` - ${result}` : '';
+    syncLog(`[SYNC] Completed: ${name} (${String(duration)}ms)${suffix}`);
+  };
+}
+
+/**
+ * Log detailed debug information.
+ */
+export function syncDebug(message: string): void {
+  syncLog(`[DEBUG] ${message}`);
+}