🔊 Add some debug logs to investigate #1609 (#1691)

packages/core/src/service/Downloader.ts

@@ -74,7 +74,7 @@ export class Downloader {
 							const deserializer = cache.deserializer ?? ((b) => b)
 							const ans = await transformer(deserializer(cachedBuffer))
 							this.logger.info(
-								`[Downloader] [${id}] Skipped downloading thanks to cache ${cacheChecksum}`,
+								`[Downloader] [${id}] Skipped downloading thanks to cache ${cacheChecksum} (${cachedBuffer.length} bytes)`,
 							)
 							return ans
 						} catch (e) {
@@ -132,7 +132,7 @@ export class Downloader {
 					this.logger.error(`[Downloader] [${id}] Caching file ${cacheUri}`, e)
 				}
 			}
-			this.logger.info(`[Downloader] [${id}] Downloaded from ${uri}`)
+			this.logger.info(`[Downloader] [${id}] Downloaded from ${uri} (${buffer.length} bytes)`)
 			return await transformer(buffer)
 		} catch (e) {
 			this.logger.error(`[Downloader] [${id}] Downloading ${uri}`, e)
@@ -141,7 +141,9 @@ export class Downloader {
 					const cachedBuffer = await fileUtil.readFile(this.externals, cacheUri)
 					const deserializer = cache.deserializer ?? ((b) => b)
 					const ans = await transformer(deserializer(cachedBuffer))
-					this.logger.warn(`[Downloader] [${id}] Fell back to cached file ${cacheUri}`)
+					this.logger.warn(
+						`[Downloader] [${id}] Fell back to cached file ${cacheUri} (${cachedBuffer.length} bytes)`,
+					)
 					return ans
 				} catch (e) {
 					this.logger.error(

packages/core/src/service/FileService.ts

@@ -340,18 +340,35 @@ export class ArchiveUriSupporter implements UriProtocolSupporter {
 					if (entries.has(archiveName)) {
 						throw new Error(`A different URI with ${archiveName} already exists`)
 					}
-
+					/// Debug message for #1609
+					logger.info(
+						`[ArchiveUriSupporter#create] Extracting archive ${archiveName} from ${uri}`,
+					)
 					const files = await externals.archive.decompressBall(
 						await externals.fs.readFile(uri),
 						{ stripLevel: typeof info?.startDepth === 'number' ? info.startDepth : 0 },
 					)
-					entries.set(archiveName, new Map(files.map((f) => [f.path.replace(/\\/g, '/'), f])))
+					const newEntries = new Map(files.map((f) => [f.path.replace(/\\/g, '/'), f]))
+					/// Debug message for #1609
+					logger.info(
+						`[ArchiveUriSupporter#create] Extracted ${files.length} files, adding ${newEntries.size} entries`,
+					)
+					for (const [path, entry] of [...newEntries.entries()].slice(0, 20)) {
+						logger.info(`[ArchiveUriSupporter#create] ${path} (${entry.data.length} bytes)`)
+					}
+					entries.set(archiveName, newEntries)
 				}
 			} catch (e) {
-				logger.error(`[SpyglassUriSupporter#create] Bad dependency ${uri}`, e)
+				logger.error(`[ArchiveUriSupporter#create] Bad dependency ${uri}`, e)
 			}
 		}
 
+		/// Debug message for #1609
+		logger.info(
+			`[ArchiveUriSupporter#create] Finalizing with ${entries.size} archives: ${[
+				...entries.keys(),
+			]}`,
+		)
 		return new ArchiveUriSupporter(externals, entries)
 	}
 }