Feature: more verbose logging (#86)

src/console/singleBarFormatted.ts

@@ -43,6 +43,7 @@ export default class SingleBarFormatted {
   }
 
   private calculateEta(remaining: number): void {
+    // TODO(cemmer): find a better way to calculate rate
     // cli-progress/lib/ETA.calculate()
     const currentBufferSize = this.valueBuffer.length;
     const buffer = Math.min(SingleBarFormatted.ETA_BUFFER_LENGTH, currentBufferSize);

src/modules/argumentsParser.ts

@@ -6,6 +6,11 @@ import Constants from '../constants.js';
 import Options from '../types/options.js';
 import ReleaseCandidate from '../types/releaseCandidate.js';
 
+/**
+ * Parse a CLI argv string[] into {@link Options}.
+ *
+ * This class will not be run concurrently with any other class.
+ */
 export default class ArgumentsParser {
   private readonly logger: Logger;
 

src/modules/candidateFilter.ts

@@ -28,13 +28,15 @@ export default class CandidateFilter {
     const output = new Map<Parent, ReleaseCandidate[]>();
 
     if (!parentsToCandidates.size) {
+      await this.progressBar.logDebug(`${dat.getName()}: No parents, so no candidates to filter`);
       return output;
     }
 
     // Return early if there aren't any candidates
     const totalReleaseCandidates = [...parentsToCandidates.values()]
       .reduce((sum, rcs) => sum + rcs.length, 0);
     if (!totalReleaseCandidates) {
+      await this.progressBar.logDebug(`${dat.getName()}: No parent has candidates`);
       return output;
     }
 
@@ -45,11 +47,13 @@ export default class CandidateFilter {
     for (let i = 0; i < [...parentsToCandidates.entries()].length; i += 1) {
       const [parent, releaseCandidates] = [...parentsToCandidates.entries()][i];
       await this.progressBar.increment();
+      await this.progressBar.logDebug(`${dat.getName()}: Filtering ${parent.getName()}: ${releaseCandidates.length} candidates before`);
 
       const filteredReleaseCandidates = releaseCandidates
         .filter((rc) => this.preFilter(rc))
         .sort((a, b) => this.sort(a, b))
         .filter((rc, idx) => this.postFilter(idx));
+      await this.progressBar.logDebug(`${dat.getName()}: Filtering ${parent.getName()}: ${filteredReleaseCandidates.length} candidates after`);
       output.set(parent, filteredReleaseCandidates);
     }
 

src/modules/candidateGenerator.ts

@@ -31,6 +31,7 @@ export default class CandidateGenerator {
 
     const output = new Map<Parent, ReleaseCandidate[]>();
     if (!inputRomFiles.length) {
+      await this.progressBar.logDebug(`${dat.getName()}: No input ROMs to make candidates from`);
       return output;
     }
 
@@ -40,7 +41,7 @@ export default class CandidateGenerator {
     // TODO(cemmer): only do this once globally, not per DAT
     // TODO(cemmer): ability to index files by some other property such as name
     const hashCodeToInputFiles = await CandidateGenerator.indexFilesByHashCode(inputRomFiles);
-    await this.progressBar.logInfo(`${dat.getName()}: ${hashCodeToInputFiles.size} unique ROM CRC32s found`);
+    await this.progressBar.logInfo(`${dat.getName()}: ${hashCodeToInputFiles.size} unique ROMs found`);
 
     // TODO(cemmer): ability to work without DATs, generating a parent/game/release per file
     // For each parent, try to generate a parent candidate
@@ -71,6 +72,7 @@ export default class CandidateGenerator {
         }
       }
 
+      await this.progressBar.logInfo(`${dat.getName()}: Found ${releaseCandidates.length} candidates for ${parent}`);
       output.set(parent, releaseCandidates);
     }
 
@@ -124,9 +126,10 @@ export default class CandidateGenerator {
       .map(([rom]) => rom);
 
     // Ignore the Game if not every File is present
-    const missingRomFiles = game.getRoms().length - foundRomFiles.length;
-    if (missingRomFiles > 0) {
-      await this.logMissingRomFiles(game, release, missingRoms);
+    if (missingRoms.length > 0) {
+      if (foundRomFiles.length > 0) {
+        await this.logMissingRomFiles(game, release, missingRoms);
+      }
       return undefined;
     }
 
@@ -138,11 +141,7 @@ export default class CandidateGenerator {
     release: Release | undefined,
     missingRoms: ROM[],
   ): Promise<void> {
-    if (!missingRoms.length) {
-      return;
-    }
-
-    let message = `Missing ${missingRoms.toLocaleString()} file${missingRoms.length !== 1 ? 's' : ''} for: ${game.getName()}`;
+    let message = `Missing ${missingRoms.length.toLocaleString()} file${missingRoms.length !== 1 ? 's' : ''} for: ${game.getName()}`;
     if (release?.getRegion()) {
       message += ` (${release?.getRegion()})`;
     }

src/modules/datScanner.ts

@@ -40,6 +40,7 @@ export default class DATScanner extends Scanner {
 
   // Scan files on disk for DATs (archives may yield more than one DAT)
   private async getDatFiles(datFilePaths: string[]): Promise<File[]> {
+    await this.progressBar.logDebug('Enumerating DAT archives');
     return (await async.mapLimit(
       datFilePaths,
       Constants.DAT_SCANNER_THREADS,
@@ -53,6 +54,7 @@ export default class DATScanner extends Scanner {
 
   // Parse each file into a DAT
   private async parseDatFiles(datFiles: File[]): Promise<DAT[]> {
+    await this.progressBar.logDebug('Parsing DAT files');
     const results = (await async.mapLimit(
       datFiles,
       Constants.DAT_SCANNER_THREADS,

src/modules/headerProcessor.ts

@@ -6,7 +6,12 @@ import File from '../types/files/file.js';
 import FileHeader from '../types/files/fileHeader.js';
 import Options from '../types/options.js';
 
-// TODO(cemmer): put debug statements in here
+/**
+ * For every input ROM file found, attempt to find a matching header and resolve its
+ * header-less checksum.
+ *
+ * This class will not be run concurrently with any other class.
+ */
 export default class HeaderProcessor {
   private readonly options: Options;
 
@@ -29,14 +34,10 @@ export default class HeaderProcessor {
       async (inputFile, callback: AsyncResultCallback<File, Error>) => {
         await this.progressBar.increment();
 
-        // Don't do anything if the file already has a header
-        if (inputFile.getFileHeader()) {
-          return callback(null, inputFile);
-        }
-
         // Can get FileHeader from extension, use that
         const headerForExtension = FileHeader.getForFilename(inputFile.getExtractedFilePath());
         if (headerForExtension) {
+          await this.progressBar.logDebug(`${inputFile.toString()}: found header by extension: ${headerForExtension}`);
           const fileWithHeader = await (
             await inputFile.withFileHeader(headerForExtension)
           ).resolve();
@@ -48,6 +49,7 @@ export default class HeaderProcessor {
           const headerForFile = await inputFile
             .extractToStream((stream) => FileHeader.getForFileStream(stream));
           if (headerForFile) {
+            await this.progressBar.logDebug(`${inputFile.toString()}: found header by contents: ${headerForExtension}`);
             const fileWithHeader = await (
               await inputFile.withFileHeader(headerForFile)
             ).resolve();
@@ -57,6 +59,7 @@ export default class HeaderProcessor {
         }
 
         // Should not get FileHeader
+        await this.progressBar.logDebug(`${inputFile.toString()}: no header found`);
         return callback(null, inputFile);
       },
     );

src/modules/outputCleaner.ts

@@ -24,20 +24,24 @@ export default class OutputCleaner {
   }
 
   async clean(writtenFilesToExclude: File[]): Promise<number> {
+    await this.progressBar.logInfo('Cleaning files in output');
+
     // If nothing was written, then don't clean anything
-    const outputFilePathsToExclude = writtenFilesToExclude
-      .map((file) => file.getFilePath());
-    if (!outputFilePathsToExclude.length) {
+    if (!writtenFilesToExclude.length) {
+      await this.progressBar.logInfo('No files were written, not cleaning output');
       return 0;
     }
 
     const outputDir = this.options.getOutput();
+    const outputFilePathsToExclude = writtenFilesToExclude
+      .map((file) => file.getFilePath());
 
     // If there is nothing to clean, then don't do anything
     const filesToClean = (await fg(`${outputDir}/**`.replace(/\\/g, '/')))
       .map((pathLike) => pathLike.replace(/[\\/]/g, path.sep))
       .filter((file) => outputFilePathsToExclude.indexOf(file) === -1);
     if (!filesToClean.length) {
+      await this.progressBar.logInfo('No files to clean');
       return 0;
     }
 

src/modules/reportGenerator.ts

@@ -22,6 +22,8 @@ export default class ReportGenerator {
   }
 
   async generate(datsStatuses: DATStatus[]): Promise<void> {
+    await this.progressBar.logInfo('Generating report');
+
     const report = this.options.getOutputReport();
     const append = (message: string): void => fs.appendFileSync(report, `${message.trimEnd()}\n`);
 

src/modules/romScanner.ts

@@ -13,10 +13,11 @@ import Scanner from './scanner.js';
  */
 export default class ROMScanner extends Scanner {
   async scan(): Promise<File[]> {
+    await this.progressBar.logInfo('Scanning ROM files');
+
     await this.progressBar.setSymbol(Symbols.SEARCHING);
     await this.progressBar.reset(0);
 
-    await this.progressBar.logInfo('Scanning ROM files');
     const romFilePaths = await this.options.scanInputFilesWithoutExclusions();
     await this.progressBar.reset(romFilePaths.length);
     await this.progressBar.logInfo(`Found ${romFilePaths.length} ROM file${romFilePaths.length !== 1 ? 's' : ''}`);

src/modules/statusGenerator.ts

@@ -24,6 +24,8 @@ export default class StatusGenerator {
     dat: DAT,
     parentsToReleaseCandidates: Map<Parent, ReleaseCandidate[]>,
   ): Promise<DATStatus> {
+    await this.progressBar.logInfo('Generating report');
+
     const datStatus = new DATStatus(dat, parentsToReleaseCandidates);
 
     await this.progressBar.done(datStatus.toString(this.options));