diff --git a/README.md b/README.md index 921cf3722..94b10b8d0 100644 --- a/README.md +++ b/README.md @@ -66,12 +66,19 @@ Options: -p, --preprocessed output FSH produced by preprocessing steps -r, --require-latest exit with error if this is not the latest version of SUSHI (default: false) -s, --snapshot generate snapshot in Structure Definition output (default: false) + --incremental reuse unchanged results from the previous build to rebuild faster (or set SUSHI_INCREMENTAL=1) -c, --config override elements in sushi-config.yaml (supported: 'version', 'status', 'releaselabel') (eg: --config status:draft) -h, --help display help for command ``` See the [SUSHI documentation](https://fshschool.org/docs/sushi/) for detailed information on using SUSHI. +### Incremental Builds + +With `--incremental`, SUSHI keeps what it imported from each FSH file and reuses it in the next build when the file and everything it used from other files are unchanged. The output and messages are the same as a normal build's. This is useful for tools that run SUSHI on every edit: setting the `SUSHI_INCREMENTAL` environment variable to `1` turns it on for every build, for example when the IG Publisher runs SUSHI. + +The cache is kept in a `.sushi-cache` folder in the project (it contains its own `.gitignore`), or in the folder named by the `SUSHI_CACHE_DIR` environment variable. It can be deleted at any time. Incremental builds are not used with `--preprocessed`. + ## IG Generation SUSHI supports publishing implementation guides via the new template-based IG Publisher. The template-based publisher is still being developed by the FHIR community. See the [Guidance for HL7 IG Creation](https://build.fhir.org/ig/FHIR/ig-guidance/) for more details. diff --git a/src/app.ts b/src/app.ts index f9e7ae08c..c9f2225f7 100644 --- a/src/app.ts +++ b/src/app.ts @@ -12,6 +12,7 @@ import { exportFHIR, Package } from './export'; import { IGExporter, loadPredefinedResources } from './ig'; import { createFHIRDefinitions } from './fhirdefs'; import { Configuration } from './fshtypes'; +import { IncrementalBuild } from './incremental/IncrementalBuild'; import { logger, stats, @@ -74,6 +75,10 @@ async function app() { false ) .option('-s, --snapshot', 'generate snapshot in Structure Definition output', false) + .option( + '--incremental', + 'reuse unchanged results from the previous build to rebuild faster (or set SUSHI_INCREMENTAL=1)' + ) .option( '-c, --config ', "override elements in sushi-config.yaml (supported: 'version', 'status', 'releaselabel') (eg: --config status:draft)", @@ -190,6 +195,10 @@ async function runBuild(input: string, program: OptionValues, helpText: string) if (program.config) { Object.entries(program.config).forEach(([k, v]) => logger.info(` --config ${k}:${v}`)); } + const incrementalRequested = program.incremental || process.env.SUSHI_INCREMENTAL === '1'; + if (incrementalRequested) { + logger.info(' --incremental'); + } logger.info(` ${path.resolve(input || '.')}`); // The version check hits the network, so only wait on it where the result is needed @@ -240,6 +249,14 @@ async function runBuild(input: string, program: OptionValues, helpText: string) let tank: FSHTank; let config: Configuration; + // Incremental builds cannot reproduce the preprocessed FSH output, so they are not used with it + if (incrementalRequested && program.preprocessed) { + logger.info('Incremental build: not used, as it cannot produce preprocessed FSH.'); + } + const incremental = + incrementalRequested && !program.preprocessed + ? new IncrementalBuild(path.resolve(originalInput), getLocalSushiVersion()) + : null; try { let rawFSH: RawFSH[]; @@ -263,7 +280,7 @@ async function runBuild(input: string, program: OptionValues, helpText: string) } config = readConfig(originalInput); updateConfig(config, program); - tank = fillTank(rawFSH, config); + tank = incremental ? incremental.importFSH(rawFSH, config) : fillTank(rawFSH, config); tank.checkDuplicateNameEntities(); } catch (e) { // If no errors have been logged yet, log this exception so the user knows why we're exiting @@ -313,9 +330,19 @@ async function runBuild(input: string, program: OptionValues, helpText: string) // } logger.info('Converting FSH to FHIR resources...'); - const outPackage = exportFHIR(tank, defs); + let outPackage: Package; + if (incremental) { + // the cache is reusable whether it was turned on by the option or the environment variable + const buildOptions = { ...program }; + delete buildOptions.incremental; + outPackage = incremental.exportFHIR(tank, defs, buildOptions, config); + incremental.logSummary(); + } else { + outPackage = exportFHIR(tank, defs); + } const { skippedResources } = writeFHIRResources(outDir, outPackage, defs, program.snapshot); writeFSHIndex(outDir, outPackage, input, skippedResources); + incremental?.finish(); if (program.preprocessed) { logger.info('Writing preprocessed FSH...'); diff --git a/src/export/CodeSystemExporter.ts b/src/export/CodeSystemExporter.ts index 2f6394a50..37ab507b9 100644 --- a/src/export/CodeSystemExporter.ts +++ b/src/export/CodeSystemExporter.ts @@ -20,6 +20,7 @@ import { MasterFisher, assembleFSHPath, resolveSoftIndexing } from '../utils'; import { InstanceExporter, Package } from '.'; import { CannotResolvePathError, MismatchedTypeError } from '../errors'; import { isEqual } from 'lodash'; +import { incrementalHooks } from '../incremental/hooks'; // The position of each concept within its list of concepts, by code. setConcepts never adds a second concept // with a code that is already present, and only ever appends concepts, so a position stays correct once it @@ -393,6 +394,15 @@ export class CodeSystemExporter { if (this.pkg.codeSystems.some(cs => cs.name === fshDefinition.name)) { return; } + if (incrementalHooks.session != null) { + return incrementalHooks.session.exportEntity('cs', this, fshDefinition, () => + this.exportNewCodeSystem(fshDefinition) + ); + } + return this.exportNewCodeSystem(fshDefinition); + } + + private exportNewCodeSystem(fshDefinition: FshCodeSystem): CodeSystem { const codeSystem = new CodeSystem(); const codeSystemSD = codeSystem.getOwnStructureDefinition(this.fisher); this.setMetadata(codeSystem, fshDefinition); @@ -402,13 +412,10 @@ export class CodeSystemExporter { ); this.setCaretPathRules(codeSystem, fshDefinition, codeSystemSD, conceptIndex); - // check for another code system with the same id - // see https://www.hl7.org/fhir/resource.html#id - if (this.pkg.codeSystems.some(cs => codeSystem.id === cs.id)) { - logger.error( - `Multiple code systems with id ${codeSystem.id}. Each code system must have a unique id.`, - fshDefinition.sourceInfo - ); + if (incrementalHooks.session != null) { + incrementalHooks.session.check(() => this.checkForDuplicateId(codeSystem, fshDefinition)); + } else { + this.checkForDuplicateId(codeSystem, fshDefinition); } cleanResource(codeSystem, (prop: string) => ['_sliceName', '_primitive'].includes(prop)); @@ -423,6 +430,19 @@ export class CodeSystemExporter { return codeSystem; } + /** + * Checks for another code system with the same id. + * See https://www.hl7.org/fhir/resource.html#id + */ + checkForDuplicateId(codeSystem: CodeSystem, fshDefinition: FshCodeSystem): void { + if (this.pkg.codeSystems.some(cs => codeSystem.id === cs.id)) { + logger.error( + `Multiple code systems with id ${codeSystem.id}. Each code system must have a unique id.`, + fshDefinition.sourceInfo + ); + } + } + export(): Package { const codeSystems = this.tank.getAllCodeSystems(); for (const cs of codeSystems) { diff --git a/src/export/FHIRExporter.ts b/src/export/FHIRExporter.ts index 372d58213..9c721a1b6 100644 --- a/src/export/FHIRExporter.ts +++ b/src/export/FHIRExporter.ts @@ -8,6 +8,7 @@ import { MappingExporter } from '.'; import { MasterFisher } from '../utils'; +import { incrementalHooks } from '../incremental/hooks'; /** * FHIRExporter handles the processing of FSH documents, storing the FSH types within them as FHIR types. * FHIRExporter takes the Profiles and Extensions within the FSHDocuments of a FSHTank and returns them @@ -42,12 +43,24 @@ export class FHIRExporter { this.instanceExporter.applyInsertRules(); this.mappingExporter.applyInsertRules(); + incrementalHooks.session?.beginExport({ + tank: this.tank, + pkg: this.pkg, + fisher: this.fisher, + structureDefinitionExporter: this.structureDefinitionExporter, + codeSystemExporter: this.codeSystemExporter, + valueSetExporter: this.valueSetExporter, + instanceExporter: this.instanceExporter + }); + this.structureDefinitionExporter.export(); this.codeSystemExporter.export(); this.valueSetExporter.export(); this.instanceExporter.export(); + incrementalHooks.session?.enterPostExport(); this.structureDefinitionExporter.applyDeferredRules(); this.mappingExporter.export(); + incrementalHooks.session?.endExport(); return this.pkg; } diff --git a/src/export/InstanceExporter.ts b/src/export/InstanceExporter.ts index f30db1674..f516792ed 100644 --- a/src/export/InstanceExporter.ts +++ b/src/export/InstanceExporter.ts @@ -51,6 +51,7 @@ import { } from 'lodash'; import { AssignmentRule, AssignmentValueType, PathRule } from '../fshtypes/rules'; import chalk from 'chalk'; +import { incrementalHooks } from '../incremental/hooks'; export class InstanceExporter implements Fishable { sdCache: Map = new Map(); @@ -58,7 +59,9 @@ export class InstanceExporter implements Fishable { private readonly tank: FSHTank, private readonly pkg: Package, private readonly fisher: MasterFisher - ) {} + ) { + incrementalHooks.session?.noteNewInstanceExporter(this); + } /** * Checks if there exist Instances of Custom Resources, which are not supported @@ -809,7 +812,15 @@ export class InstanceExporter implements Fishable { if (this.pkg.instances.some(i => i._instanceMeta.name === fshDefinition.name)) { return; } + if (incrementalHooks.session != null) { + return incrementalHooks.session.exportEntity('inst', this, fshDefinition, () => + this.exportNewInstance(fshDefinition) + ); + } + return this.exportNewInstance(fshDefinition); + } + private exportNewInstance(fshDefinition: Instance): InstanceDefinition { let isResource = true; const json = this.fisher.fishForFHIR( fshDefinition.instanceOf, @@ -857,9 +868,11 @@ export class InstanceExporter implements Fishable { let instanceOfStructureDefinition: StructureDefinition; if (this.sdCache.has(json.url)) { instanceOfStructureDefinition = this.sdCache.get(json.url); + incrementalHooks.session?.noteSdCache(this, json.url, false); } else { instanceOfStructureDefinition = StructureDefinition.fromJSON(json); this.sdCache.set(instanceOfStructureDefinition.url, instanceOfStructureDefinition); + incrementalHooks.session?.noteSdCache(this, instanceOfStructureDefinition.url, true); } let instanceDef = new InstanceDefinition(); @@ -1014,10 +1027,22 @@ export class InstanceExporter implements Fishable { } } - // check for another instance of the same type with the same id - // see https://www.hl7.org/fhir/resource.html#id - // instanceDef has already been added to the package, so it's fine if it matches itself - // inline instances are not written to their own files, so those can be skipped in this + if (incrementalHooks.session != null) { + incrementalHooks.session.check(() => this.checkForDuplicateId(instanceDef, fshDefinition)); + } else { + this.checkForDuplicateId(instanceDef, fshDefinition); + } + + return instanceDef; + } + + /** + * Checks for another instance of the same type with the same id. + * See https://www.hl7.org/fhir/resource.html#id + * instanceDef has already been added to the package, so it's fine if it matches itself. + * Inline instances are not written to their own files, so those can be skipped in this check. + */ + checkForDuplicateId(instanceDef: InstanceDefinition, fshDefinition: Instance): void { if ( instanceDef._instanceMeta.usage !== 'Inline' && this.pkg.instances.some( @@ -1036,8 +1061,6 @@ export class InstanceExporter implements Fishable { fshDefinition.sourceInfo ); } - - return instanceDef; } /** diff --git a/src/export/Package.ts b/src/export/Package.ts index 28bd7891e..57a385671 100644 --- a/src/export/Package.ts +++ b/src/export/Package.ts @@ -7,6 +7,9 @@ import { StructureDefinition, InstanceDefinition, ValueSet, CodeSystem } from '. import { Configuration, SourceInfo } from '../fshtypes'; import { Fishable, Type, Metadata } from '../utils/Fishable'; +type PackageDefinition = StructureDefinition | ValueSet | CodeSystem | InstanceDefinition; +type FishCandidates = [PackageDefinition[], (def: PackageDefinition) => boolean][]; + export class Package implements Fishable { public readonly profiles: StructureDefinition[] = []; public readonly extensions: StructureDefinition[] = []; @@ -35,13 +38,50 @@ export class Package implements Fishable { return this.internalFish(item, types, false); } + /** + * Finds every definition in the package that matches the item, for each of the requested types, + * in the order that fish and fishAll consider them. fish returns the first of these, and fishAll + * returns the first match for each type. Incremental builds use the full list to tell whether a + * lookup would still give the same answer. + */ + findAllMatches(item: string, ...types: Type[]): PackageDefinition[] { + const results: PackageDefinition[] = []; + for (const candidates of this.getCandidates(item, types)) { + for (const [list, matches] of candidates) { + results.push(...list.filter(matches)); + } + } + return results; + } + private internalFish( item: string, types: Type[], stopOnFirstMatch: boolean ): (StructureDefinition | ValueSet | CodeSystem | InstanceDefinition)[] { const results: (StructureDefinition | ValueSet | CodeSystem | InstanceDefinition)[] = []; + for (const candidates of this.getCandidates(item, types)) { + let def: PackageDefinition; + for (const [list, matches] of candidates) { + def = list.find(matches); + if (def) { + break; + } + } + if (def) { + if (stopOnFirstMatch) { + return [def]; + } + results.push(def); + } + } + return results; + } + /** + * For each type to fish for, the lists to search (in order) and how to recognize a match in each + */ + private getCandidates(item: string, types: Type[]): FishCandidates[] { // No types passed in means to search ALL supported types if (types.length === 0) { types = [ @@ -59,132 +99,142 @@ export class Package implements Fishable { const [base, ...versionParts] = item?.split('|') ?? ['', '']; const version = versionParts.join('|') || null; - for (const type of types) { - let def; + return types.map(type => { + let candidates: FishCandidates; switch (type) { case Type.Profile: - def = this.profiles.find( - p => - (p.id === base || p.name === base || p.url === base) && - (version == null || p.version === version) - ); - if (!def) { - def = this.instances.find( - i => + candidates = [ + [ + this.profiles, + (p: StructureDefinition) => + (p.id === base || p.name === base || p.url === base) && + (version == null || p.version === version) + ], + [ + this.instances, + (i: InstanceDefinition) => i._instanceMeta.usage === 'Definition' && i.resourceType === 'StructureDefinition' && i.derivation === 'constraint' && i.type !== 'Extension' && (i.id === base || i._instanceMeta.name === base || i.url === base) && (version == null || i.version === version) - ); - } + ] + ]; break; case Type.Extension: - def = this.extensions.find( - e => - (e.id === base || e.name === base || e.url === base) && - (version == null || e.version === version) - ); - if (!def) { - def = this.instances.find( - i => + candidates = [ + [ + this.extensions, + (e: StructureDefinition) => + (e.id === base || e.name === base || e.url === base) && + (version == null || e.version === version) + ], + [ + this.instances, + (i: InstanceDefinition) => i._instanceMeta.usage === 'Definition' && i.resourceType === 'StructureDefinition' && i.derivation === 'constraint' && i.type === 'Extension' && (i.id === base || i._instanceMeta.name === base || i.url === base) && (version == null || i.version === version) - ); - } + ] + ]; break; case Type.Logical: - def = this.logicals.find( - l => - (l.id === base || l.name === base || l.url === base) && - (version == null || l.version === version) - ); - if (!def) { - def = this.instances.find( - i => + candidates = [ + [ + this.logicals, + (l: StructureDefinition) => + (l.id === base || l.name === base || l.url === base) && + (version == null || l.version === version) + ], + [ + this.instances, + (i: InstanceDefinition) => i._instanceMeta.usage === 'Definition' && i.resourceType === 'StructureDefinition' && i.derivation === 'specialization' && i.kind === 'logical' && (i.id === base || i._instanceMeta.name === base || i.url === base) && (version == null || i.version === version) - ); - } + ] + ]; break; case Type.Resource: - def = this.resources.find( - r => - (r.id === base || r.name === base || r.url === base) && - (version == null || r.version === version) - ); - if (!def) { - def = this.instances.find( - i => + candidates = [ + [ + this.resources, + (r: StructureDefinition) => + (r.id === base || r.name === base || r.url === base) && + (version == null || r.version === version) + ], + [ + this.instances, + (i: InstanceDefinition) => i._instanceMeta.usage === 'Definition' && i.resourceType === 'StructureDefinition' && i.derivation === 'specialization' && i.kind === 'resource' && (i.id === base || i._instanceMeta.name === base || i.url === base) && (version == null || i.version === version) - ); - } + ] + ]; break; case Type.ValueSet: - def = this.valueSets.find( - vs => - (vs.id === base || vs.name === base || vs.url === base) && - (version == null || vs.version === version) - ); - if (!def) { - def = this.instances.find( - i => + candidates = [ + [ + this.valueSets, + (vs: ValueSet) => + (vs.id === base || vs.name === base || vs.url === base) && + (version == null || vs.version === version) + ], + [ + this.instances, + (i: InstanceDefinition) => i._instanceMeta.usage === 'Definition' && i.resourceType === 'ValueSet' && (i.id === base || i._instanceMeta.name === base || i.url === base) && (version == null || i.version === version) - ); - } + ] + ]; break; case Type.CodeSystem: - def = this.codeSystems.find( - cs => - (cs.id === base || cs.name === base || cs.url === base) && - (version == null || cs.version === version) - ); - if (!def) { - def = this.instances.find( - i => + candidates = [ + [ + this.codeSystems, + (cs: CodeSystem) => + (cs.id === base || cs.name === base || cs.url === base) && + (version == null || cs.version === version) + ], + [ + this.instances, + (i: InstanceDefinition) => i._instanceMeta.usage === 'Definition' && i.resourceType === 'CodeSystem' && (i.id === base || i._instanceMeta.name === base || i.url === base) && (version == null || i.version === version) - ); - } + ] + ]; break; case Type.Instance: - def = this.instances.find( - i => - (i.id === base || i._instanceMeta.name === base) && - (version == null || i.version === version) - ); + candidates = [ + [ + this.instances, + (i: InstanceDefinition) => + (i.id === base || i._instanceMeta.name === base) && + (version == null || i.version === version) + ] + ]; break; case Type.Type: // Package doesn't currently support types default: + candidates = []; break; } - if (def) { - if (stopOnFirstMatch) { - return [def]; - } - results.push(def); - } - } - return results; + return candidates; + }); } fishForFHIR(item: string, ...types: Type[]): any | undefined { diff --git a/src/export/StructureDefinitionExporter.ts b/src/export/StructureDefinitionExporter.ts index a2a972480..150327264 100644 --- a/src/export/StructureDefinitionExporter.ts +++ b/src/export/StructureDefinitionExporter.ts @@ -75,6 +75,7 @@ import { Package } from './Package'; import { isUri } from 'valid-url'; import chalk from 'chalk'; import { getValueFromRules, findAssignmentByPath } from '../fshtypes/common'; +import { incrementalHooks } from '../incremental/hooks'; // Extensions that should not be inherited by derived profiles. // See: https://jira.hl7.org/browse/FHIR-28441 @@ -1481,7 +1482,17 @@ export class StructureDefinitionExporter implements Fishable { ) { return; } + if (incrementalHooks.session != null) { + return incrementalHooks.session.exportEntity('sd', this, fshDefinition, () => + this.exportNewStructDef(fshDefinition) + ); + } + return this.exportNewStructDef(fshDefinition); + } + private exportNewStructDef( + fshDefinition: Profile | Extension | Logical | Resource + ): StructureDefinition { const structDef = this.getStructureDefinition(fshDefinition); if (structDef.inProgress) { @@ -1546,9 +1557,24 @@ export class StructureDefinitionExporter implements Fishable { structDef.getOwnStructureDefinition(this.fisher) ); - // check for another structure definition with the same id - // see https://www.hl7.org/fhir/resource.html#id - // the structure definition has already been added to the package, so it's fine if it matches itself + if (incrementalHooks.session != null) { + incrementalHooks.session.check(() => this.checkForDuplicateId(structDef, fshDefinition)); + } else { + this.checkForDuplicateId(structDef, fshDefinition); + } + + return structDef; + } + + /** + * Checks for another structure definition with the same id. + * See https://www.hl7.org/fhir/resource.html#id + * The structure definition has already been added to the package, so it's fine if it matches itself. + */ + checkForDuplicateId( + structDef: StructureDefinition, + fshDefinition: Profile | Extension | Logical | Resource + ): void { if ( this.pkg.profiles.some(prof => structDef.id === prof.id && structDef !== prof) || this.pkg.extensions.some(extn => structDef.id === extn.id && structDef !== extn) || @@ -1560,8 +1586,6 @@ export class StructureDefinitionExporter implements Fishable { fshDefinition.sourceInfo ); } - - return structDef; } /** diff --git a/src/export/ValueSetExporter.ts b/src/export/ValueSetExporter.ts index 884bc11f0..df768ab25 100644 --- a/src/export/ValueSetExporter.ts +++ b/src/export/ValueSetExporter.ts @@ -36,6 +36,7 @@ import { } from '../fhirtypes/common'; import { isUri } from 'valid-url'; import { flatMap, partition, xor } from 'lodash'; +import { incrementalHooks } from '../incremental/hooks'; export class ValueSetExporter { constructor( @@ -583,6 +584,15 @@ export class ValueSetExporter { if (this.pkg.valueSets.some(vs => vs.name === fshDefinition.name)) { return; } + if (incrementalHooks.session != null) { + return incrementalHooks.session.exportEntity('vs', this, fshDefinition, () => + this.exportNewValueSet(fshDefinition) + ); + } + return this.exportNewValueSet(fshDefinition); + } + + private exportNewValueSet(fshDefinition: FshValueSet): ValueSet { const vs = new ValueSet(); const valueSetSD = vs.getOwnStructureDefinition(this.fisher); this.setMetadata(vs, fshDefinition); @@ -605,13 +615,10 @@ export class ValueSetExporter { throw new ValueSetComposeError(fshDefinition.name); } - // check for another value set with the same id - // see https://www.hl7.org/fhir/resource.html#id - if (this.pkg.valueSets.some(valueSet => vs.id === valueSet.id)) { - logger.error( - `Multiple value sets with id ${vs.id}. Each value set must have a unique id.`, - fshDefinition.sourceInfo - ); + if (incrementalHooks.session != null) { + incrementalHooks.session.check(() => this.checkForDuplicateId(vs, fshDefinition)); + } else { + this.checkForDuplicateId(vs, fshDefinition); } cleanResource(vs, (prop: string) => ['_sliceName', '_primitive'].includes(prop)); @@ -624,4 +631,17 @@ export class ValueSetExporter { }); return vs; } + + /** + * Checks for another value set with the same id. + * See https://www.hl7.org/fhir/resource.html#id + */ + checkForDuplicateId(vs: ValueSet, fshDefinition: FshValueSet): void { + if (this.pkg.valueSets.some(valueSet => vs.id === valueSet.id)) { + logger.error( + `Multiple value sets with id ${vs.id}. Each value set must have a unique id.`, + fshDefinition.sourceInfo + ); + } + } } diff --git a/src/import/FSHImporter.ts b/src/import/FSHImporter.ts index 56f9339b6..43df3c719 100644 --- a/src/import/FSHImporter.ts +++ b/src/import/FSHImporter.ts @@ -138,6 +138,119 @@ function unescapeUnicode(match: string, p1: string): string { return JSON.parse(`"\\${p1}"`); } +type PreprocessedAlias = { alias: string; value: string; location: TextLocation }; +type PreprocessedRuleSet = { + ruleSet: string; + params: string[]; + contents: string; + location: TextLocation; +}; +export type PreprocessedItem = PreprocessedAlias | PreprocessedRuleSet; + +type DocumentCollection = + | 'profiles' + | 'extensions' + | 'resources' + | 'logicals' + | 'instances' + | 'valueSets' + | 'codeSystems' + | 'invariants' + | 'ruleSets' + | 'mappings'; + +/** + * Something a document's import used that comes from outside the document itself: whether an + * alias exists and what it is, a parameterized RuleSet (by hash), or whether an entity with the + * same name was already imported from another document. + */ +export type ImportDependency = + | ['aliasHas', string, boolean] + | ['aliasGet', string, string | null] + | ['ruleSet', string, string] + | ['duplicate', DocumentCollection, string, boolean]; + +/** What importing one file produced, for reuse by a later incremental build. */ +export interface CachedImport { + parseLogs: any[]; + items: PreprocessedItem[]; + dependencies: ImportDependency[]; + visitLogs: any[]; + doc: any; +} + +/** + * Lets FSHImporter reuse the results of importing unchanged files. Logs are captured as copies, + * so they can be written again exactly as they were. + */ +export interface ImportCache { + lookup(file: string, content: string): CachedImport | null; + keep(file: string): void; + store(file: string, content: string, entry: CachedImport): void; + capture(fn: () => T, mute: boolean): { result: T; logs: any[] | null }; + emit(logs: any[]): void; + hash(value: any): string; + encodeDoc(doc: FSHDocument): any; + /** Decodes a cached document, or returns null (having noted the failure) if it can't be */ + decodeDoc(encoded: any): FSHDocument | null; + /** Notes an unexpected failure to use (or, if writing, to make) a cached import */ + failed(during: string, e: any, writing?: boolean): void; + /** Notes why a file's import is not cached, when that is not a failure */ + skipped(file: string, why: string): void; +} + +class DependencyRecorder { + readonly list: ImportDependency[] = []; + private readonly seen = new Set(); + failed = false; + + constructor( + private readonly hash: (value: any) => string, + private readonly onError: (during: string, e: any) => void + ) {} + + note(dependency: ImportDependency) { + const key = JSON.stringify(dependency.slice(0, -1)); + if (!this.seen.has(key)) { + this.seen.add(key); + this.list.push(dependency); + } + } + + noteRuleSet(name: string, ruleSet: ParamRuleSet) { + const key = JSON.stringify(['ruleSet', name]); + if (!this.seen.has(key)) { + try { + this.note(['ruleSet', name, this.hash(ruleSet ?? null)]); + } catch (e) { + // the document is not cached, which is reported once + if (!this.failed) { + this.onError(`hashing the RuleSet ${name}`, e); + } + this.failed = true; + } + } + } +} + +/** A Map that reports reads of it, so the importer can tell what a document depended on. */ +class ObservedMap extends Map { + onHas: (key: string, result: boolean) => void = null; + onGet: (key: string, result: V) => void = null; + + has(key: string): boolean { + const result = super.has(key); + this.onHas?.(key, result); + return result; + } + + get(key: string): V { + const result = super.get(key); + this.onGet?.(key, result); + return result; + } +} + /** * FSHImporter handles the parsing of FSH documents, constructing the data into FSH types. * FSHImporter uses a visitor pattern approach with some accomodations due to the ANTLR4 @@ -147,6 +260,9 @@ function unescapeUnicode(match: string, p1: string): string { */ export class FSHImporter extends FSHVisitor { private docs: FSHDocument[] = []; + private caughtRangeError = false; + private dependencies: DependencyRecorder = null; + private visitingDoc: FSHDocument = null; private currentFile: string; private currentDoc: FSHDocument; private allAliases: Map; @@ -160,7 +276,10 @@ export class FSHImporter extends FSHVisitor { this.topLevelParse = true; } - import(rawFSHes: RawFSH[]): FSHDocument[] { + import(rawFSHes: RawFSH[], cache?: ImportCache): FSHDocument[] { + if (cache != null) { + return this.importWithCache(rawFSHes, cache); + } this.allAliases = new Map(); const contexts: pc.DocContext[] = []; @@ -183,44 +302,7 @@ export class FSHImporter extends FSHVisitor { contexts.push(ctx); // Collect the aliases and store in global map - ctx.entity().forEach(e => { - if (e.alias()) { - const name = e.alias().name().getText(); - let value = e.alias().SEQUENCE()?.getText(); - // When the url contains a fragment (http://example.org#fragment), the grammar will read it as a - // CODE, so we also accept that for the value here - if (!value && e.alias().CODE()) { - value = e.alias().CODE().getText(); - } - if (name.includes('|')) { - logger.error( - `Alias ${name} cannot include "|" since the "|" character is reserved for indicating a version`, - { file: doc.file ?? '', location: this.extractStartStop(e.alias()) } - ); - return; - } else if (!aliasRegex.test(name)) { - logger.warn( - `Alias ${name} includes unsupported characters. Alias names can only contain letters, numbers, underscores ("_"), hyphens ("-"), and dots (".").`, - { file: doc.file ?? '', location: this.extractStartStop(e.alias()) } - ); - } - if (this.allAliases.has(name) && this.allAliases.get(name) !== value) { - logger.error( - `Alias ${name} cannot be redefined to ${value}; it is already defined as ${this.allAliases.get( - name - )}.`, - { file: doc.file ?? '', location: this.extractStartStop(e.alias()) } - ); - // don't set it -- just keep the original definition - } else { - this.allAliases.set(name, value); - doc.aliases.set(name, value); - } - } - if (e.paramRuleSet()) { - this.visitParamRuleSet(e.paramRuleSet()); - } - }); + this.applyPreprocessedItems(doc, this.extractPreprocessedItems(ctx)); this.currentDoc = null; this.currentFile = null; }); @@ -251,11 +333,258 @@ export class FSHImporter extends FSHVisitor { return this.docs; } + /** + * Imports like import, but reuses what was imported from each unchanged file, as long as + * everything that file's import used from other files is also unchanged. The documents and the + * log messages are the same as import's. + */ + private importWithCache(rawFSHes: RawFSH[], cache: ImportCache): FSHDocument[] { + const aliases = new ObservedMap(); + const paramRuleSets = new ObservedMap(); + this.allAliases = aliases; + this.paramRuleSets = paramRuleSets; + aliases.onHas = (key, result) => this.dependencies?.note(['aliasHas', key, result]); + aliases.onGet = (key, result) => this.dependencies?.note(['aliasGet', key, result ?? null]); + paramRuleSets.onGet = (key, result) => this.dependencies?.noteRuleSet(key, result); + const files: { + rawFSH: RawFSH; + content: string; + cached: CachedImport | null; + ctx: pc.DocContext | null; + parseLogs: any[] | null; + items: PreprocessedItem[]; + }[] = []; + + rawFSHes.forEach(rawFSH => { + const doc = new FSHDocument(rawFSH.path); + this.docs.push(doc); + this.currentDoc = doc; + this.currentFile = this.currentDoc.file ?? ''; + // See import for why the newline is added + const content = rawFSH.content.endsWith('\n') ? rawFSH.content : rawFSH.content + '\n'; + const cached = cache.lookup(rawFSH.path, content); + let ctx: pc.DocContext = null; + let parseLogs: any[] = null; + let items: PreprocessedItem[]; + if (cached != null) { + cache.emit(cached.parseLogs); + parseLogs = cached.parseLogs; + items = cached.items; + } else { + const parsed = cache.capture(() => this.parseDoc(content, rawFSH.path), false); + ctx = parsed.result; + parseLogs = parsed.logs; + items = this.extractPreprocessedItems(ctx); + } + this.applyPreprocessedItems(doc, items); + files.push({ rawFSH, content, cached, ctx, parseLogs, items }); + this.currentDoc = null; + this.currentFile = null; + }); + logger.info(`Preprocessed ${this.docs.length} documents with ${this.allAliases.size} aliases.`); + + files.forEach((file, index) => { + const liveDoc = this.docs[index]; + if (file.cached != null && this.dependenciesHold(file.cached.dependencies, liveDoc, cache)) { + const doc = cache.decodeDoc(file.cached.doc); + if (doc != null) { + // aliases are collected during preprocessing, which already ran for this build + doc.aliases.clear(); + liveDoc.aliases.forEach((value, name) => doc.aliases.set(name, value)); + this.docs[index] = doc; + cache.emit(file.cached.visitLogs); + cache.keep(file.rawFSH.path); + return; + } + } + let ctx = file.ctx; + if (ctx == null) { + // its parse messages were already written, during preprocessing + ctx = cache.capture(() => this.parseDoc(file.content, file.rawFSH.path), true).result; + } + this.currentDoc = liveDoc; + this.currentFile = this.currentDoc.file ?? ''; + this.visitingDoc = liveDoc; + const dependencies = new DependencyRecorder( + value => cache.hash(value), + (during, e) => cache.failed(`${during} for ${file.rawFSH.path}`, e, true) + ); + this.dependencies = dependencies; + let visited: { logs: any[] | null }; + this.caughtRangeError = false; + try { + visited = cache.capture(() => this.visitDoc(ctx), false); + } finally { + this.dependencies = null; + this.visitingDoc = null; + this.currentDoc = null; + this.currentFile = null; + } + if (file.parseLogs == null || visited.logs == null) { + cache.skipped(file.rawFSH.path, 'a message it logs could not be copied'); + } else if (this.caughtRangeError) { + // e.g. running out of stack space, where what is logged depends on how deep the stack was + cache.skipped(file.rawFSH.path, 'importing it caught a RangeError'); + } else if (!dependencies.failed) { + let encoded: any = null; + try { + encoded = cache.encodeDoc(liveDoc); + } catch (e) { + encoded = null; + cache.failed(`encoding the import of ${file.rawFSH.path}`, e, true); + } + if (encoded != null) { + cache.store(file.rawFSH.path, file.content, { + parseLogs: file.parseLogs, + items: file.items, + dependencies: dependencies.list, + visitLogs: visited.logs, + doc: encoded + }); + } + } + }); + + let [definitions, instances] = [0, 0]; + this.docs.forEach(doc => { + definitions += + doc.codeSystems.size + + doc.extensions.size + + doc.profiles.size + + doc.valueSets.size + + doc.logicals.size + + doc.resources.size; + instances += doc.instances.size; + }); + logger.info(`Imported ${definitions} definitions and ${instances} instances.`); + + return this.docs; + } + + /** Whether everything a document's import used from outside it is the same as it was then. */ + private dependenciesHold( + dependencies: ImportDependency[], + doc: FSHDocument, + cache: ImportCache + ): boolean { + try { + return dependencies.every(dependency => { + switch (dependency[0]) { + case 'aliasHas': + return Map.prototype.has.call(this.allAliases, dependency[1]) === dependency[2]; + case 'aliasGet': + return ( + (Map.prototype.get.call(this.allAliases, dependency[1]) ?? null) === dependency[2] + ); + case 'ruleSet': + return ( + cache.hash(Map.prototype.get.call(this.paramRuleSets, dependency[1]) ?? null) === + dependency[2] + ); + case 'duplicate': + return ( + this.docs.some( + d => d !== doc && (d[dependency[1]] as Map)?.has(dependency[2]) + ) === dependency[3] + ); + default: + return false; + } + }); + } catch (e) { + cache.failed(`checking what the cached import of ${doc.file} used`, e); + return false; + } + } + + /** + * Finds the aliases and parameterized RuleSets in a parsed document. These are collected from + * every document before any document is visited, since any document may use them. + */ + private extractPreprocessedItems(ctx: pc.DocContext): PreprocessedItem[] { + const items: PreprocessedItem[] = []; + ctx.entity().forEach(e => { + if (e.alias()) { + const name = e.alias().name().getText(); + let value = e.alias().SEQUENCE()?.getText(); + // When the url contains a fragment (http://example.org#fragment), the grammar will read it as a + // CODE, so we also accept that for the value here + if (!value && e.alias().CODE()) { + value = e.alias().CODE().getText(); + } + items.push({ alias: name, value, location: this.extractStartStop(e.alias()) }); + } + if (e.paramRuleSet()) { + const ruleSetCtx = e.paramRuleSet(); + const { name, params } = this.parseRuleSetReference(ruleSetCtx.paramRuleSetRef()); + items.push({ + ruleSet: name, + params, + contents: this.visitParamRuleSetContent(ruleSetCtx.paramRuleSetContent()), + location: this.extractStartStop(ruleSetCtx) + }); + } + }); + return items; + } + + private applyPreprocessedItems(doc: FSHDocument, items: PreprocessedItem[]): void { + items.forEach(item => { + if ('alias' in item) { + this.applyAlias(doc, item); + } else { + this.applyParamRuleSet(item); + } + }); + } + + private applyAlias(doc: FSHDocument, item: PreprocessedAlias): void { + const name = item.alias; + const value = item.value; + if (name.includes('|')) { + logger.error( + `Alias ${name} cannot include "|" since the "|" character is reserved for indicating a version`, + { file: doc.file ?? '', location: { ...item.location } } + ); + return; + } else if (!aliasRegex.test(name)) { + logger.warn( + `Alias ${name} includes unsupported characters. Alias names can only contain letters, numbers, underscores ("_"), hyphens ("-"), and dots (".").`, + { file: doc.file ?? '', location: { ...item.location } } + ); + } + if (this.allAliases.has(name) && this.allAliases.get(name) !== value) { + logger.error( + `Alias ${name} cannot be redefined to ${value}; it is already defined as ${this.allAliases.get( + name + )}.`, + { file: doc.file ?? '', location: { ...item.location } } + ); + // don't set it -- just keep the original definition + } else { + this.allAliases.set(name, value); + doc.aliases.set(name, value); + } + } + + private isDuplicate(collection: DocumentCollection, name: string): boolean { + if (this.dependencies != null) { + const elsewhere = this.docs.some( + doc => doc !== this.visitingDoc && (doc[collection] as Map).has(name) + ); + this.dependencies.note(['duplicate', collection, name, elsewhere]); + } + return this.docs.some(doc => (doc[collection] as Map).has(name)); + } + visitDoc(ctx: pc.DocContext): void { ctx.entity().forEach(e => { try { this.visitEntity(e); } catch (err) { + if (err instanceof RangeError) { + this.caughtRangeError = true; + } const sourceInfo = { location: this.extractStartStop(e), file: this.currentFile }; logger.error(`Error in parsing: ${err.message}`, sourceInfo); if (err.stack) { @@ -296,7 +625,7 @@ export class FSHImporter extends FSHVisitor { const profile = new Profile(ctx.name().getText()) .withLocation(this.extractStartStop(ctx)) .withFile(this.currentFile); - if (this.docs.some(doc => doc.profiles.has(profile.name))) { + if (this.isDuplicate('profiles', profile.name)) { logger.error(`Skipping Profile: a Profile named ${profile.name} already exists.`, { file: this.currentFile, location: this.extractStartStop(ctx) @@ -311,7 +640,7 @@ export class FSHImporter extends FSHVisitor { const extension = new Extension(ctx.name().getText()) .withLocation(this.extractStartStop(ctx)) .withFile(this.currentFile); - if (this.docs.some(doc => doc.extensions.has(extension.name))) { + if (this.isDuplicate('extensions', extension.name)) { logger.error(`Skipping Extension: an Extension named ${extension.name} already exists.`, { file: this.currentFile, location: this.extractStartStop(ctx) @@ -370,7 +699,7 @@ export class FSHImporter extends FSHVisitor { const resource = new Resource(ctx.name().getText()) .withLocation(this.extractStartStop(ctx)) .withFile(this.currentFile); - if (this.docs.some(doc => doc.resources.has(resource.name))) { + if (this.isDuplicate('resources', resource.name)) { logger.error(`Skipping Resource: a Resource named ${resource.name} already exists.`, { file: this.currentFile, location: this.extractStartStop(ctx) @@ -385,7 +714,7 @@ export class FSHImporter extends FSHVisitor { const logical = new Logical(ctx.name().getText()) .withLocation(this.extractStartStop(ctx)) .withFile(this.currentFile); - if (this.docs.some(doc => doc.logicals.has(logical.name))) { + if (this.isDuplicate('logicals', logical.name)) { logger.error( `Skipping Logical Model: a Logical Model named ${logical.name} already exists.`, { @@ -448,7 +777,7 @@ export class FSHImporter extends FSHVisitor { const instance = new Instance(ctx.name().getText()) .withLocation(location) .withFile(this.currentFile); - if (this.docs.some(doc => doc.instances.has(instance.name))) { + if (this.isDuplicate('instances', instance.name)) { logger.error(`Skipping Instance: an Instance named ${instance.name} already exists.`, { file: this.currentFile, location @@ -526,7 +855,7 @@ export class FSHImporter extends FSHVisitor { const valueSet = new FshValueSet(ctx.name().getText()) .withLocation(this.extractStartStop(ctx)) .withFile(this.currentFile); - if (this.docs.some(doc => doc.valueSets.has(valueSet.name))) { + if (this.isDuplicate('valueSets', valueSet.name)) { logger.error(`Skipping ValueSet: a ValueSet named ${valueSet.name} already exists.`, { file: this.currentFile, location: this.extractStartStop(ctx) @@ -595,7 +924,7 @@ export class FSHImporter extends FSHVisitor { const codeSystem = new FshCodeSystem(ctx.name().getText()) .withLocation(this.extractStartStop(ctx)) .withFile(this.currentFile); - if (this.docs.some(doc => doc.codeSystems.has(codeSystem.name))) { + if (this.isDuplicate('codeSystems', codeSystem.name)) { logger.error(`Skipping code system: a code system named ${codeSystem.name} already exists.`, { file: this.currentFile, location: this.extractStartStop(ctx) @@ -646,7 +975,7 @@ export class FSHImporter extends FSHVisitor { const invariant = new Invariant(ctx.name().getText()) .withLocation(this.extractStartStop(ctx)) .withFile(this.currentFile); - if (this.docs.some(doc => doc.invariants.has(invariant.name))) { + if (this.isDuplicate('invariants', invariant.name)) { logger.error(`Skipping Invariant: an Invariant named ${invariant.name} already exists.`, { file: this.currentFile, location: this.extractStartStop(ctx) @@ -701,7 +1030,7 @@ export class FSHImporter extends FSHVisitor { const ruleSet = new RuleSet(ctx.RULESET_REFERENCE().getText().trim()) .withLocation(this.extractStartStop(ctx)) .withFile(this.currentFile); - if (this.docs.some(doc => doc.ruleSets.has(ruleSet.name))) { + if (this.isDuplicate('ruleSets', ruleSet.name)) { logger.error(`Skipping RuleSet: a RuleSet named ${ruleSet.name} already exists.`, { file: this.currentFile, location: this.extractStartStop(ctx) @@ -732,19 +1061,18 @@ export class FSHImporter extends FSHVisitor { }); } - visitParamRuleSet(ctx: pc.ParamRuleSetContext): void { - const { name, params } = this.parseRuleSetReference(ctx.paramRuleSetRef()); - const paramRuleSet = new ParamRuleSet(name) - .withLocation(this.extractStartStop(ctx)) + private applyParamRuleSet(item: PreprocessedRuleSet): void { + const paramRuleSet = new ParamRuleSet(item.ruleSet) + .withLocation({ ...item.location }) .withFile(this.currentFile); if (this.paramRuleSets.has(paramRuleSet.name)) { logger.error(`Skipping RuleSet: a RuleSet named ${paramRuleSet.name} already exists.`, { file: this.currentFile, - location: this.extractStartStop(ctx) + location: { ...item.location } }); } else { - paramRuleSet.parameters = params; - paramRuleSet.contents = this.visitParamRuleSetContent(ctx.paramRuleSetContent()); + paramRuleSet.parameters = item.params; + paramRuleSet.contents = item.contents; const unusedParameters = paramRuleSet.getUnusedParameters(); if (unusedParameters.length > 0) { logger.warn( @@ -766,7 +1094,7 @@ export class FSHImporter extends FSHVisitor { const mapping = new Mapping(ctx.name().getText()) .withLocation(this.extractStartStop(ctx)) .withFile(this.currentFile); - if (this.docs.some(doc => doc.mappings.has(mapping.name))) { + if (this.isDuplicate('mappings', mapping.name)) { logger.error(`Skipping Mapping: a Mapping named ${mapping.name} already exists.`, { file: this.currentFile, location: this.extractStartStop(ctx) diff --git a/src/incremental/CacheStore.ts b/src/incremental/CacheStore.ts new file mode 100644 index 000000000..7a8ab665b --- /dev/null +++ b/src/incremental/CacheStore.ts @@ -0,0 +1,243 @@ +import fs from 'fs'; +import path from 'path'; +import zlib from 'zlib'; +import { hashString } from './serialize'; + +export const CACHE_FORMAT = 1; + +const HOUR = 60 * 60 * 1000; +const DAY = 24 * HOUR; + +/** Stores content-addressed payloads, which are found again by the reference putPayload returns */ +export interface PayloadStore { + putPayload(json: string): string; + getPayload(ref: string): any; + /** Notes that a cached result could not be used */ + readFailed(e: any): void; + /** Notes that a result could not be cached */ + writeFailed(e: any): void; +} + +export interface Manifest { + format: number; + globalKey: string; + parseKey: string; + export?: any; + parse?: any; +} + +/** + * The on-disk cache of an incremental build: one manifest, plus content-addressed payloads that + * the manifest refers to. Every read is checked, and every write goes to a temporary file that is + * renamed into place, so an interrupted or concurrent build can leave unused files behind but can + * never leave a payload or manifest that is read back wrong. + */ +export class CacheStore implements PayloadStore { + private readonly payloadDir: string; + private readonly known = new Set(); + // Files changed after this may belong to another build running at the same time (with some + // slack, as file times can lag the clock slightly) + private readonly startedAt = Date.now() - 1000; + /** Why the manifest could not be used, if there was one */ + manifestProblem: string = null; + /** The first failure to write to the cache, if any */ + writeError: string = null; + /** How many payloads were found corrupt (and removed) */ + corruptPayloads = 0; + /** How many cached results could not be used, and the first reason */ + readFailures = 0; + readError: string = null; + /** The first unexpected failure to clean up the cache, if any */ + cleanupError: string = null; + + constructor(readonly dir: string) { + this.payloadDir = path.join(dir, 'p'); + } + + static forProject(projectDir: string): CacheStore { + const dir = process.env.SUSHI_CACHE_DIR || path.join(projectDir, '.sushi-cache'); + return new CacheStore(path.resolve(dir)); + } + + /** Reads the manifest, or returns null if there is no usable one. */ + readManifest(): Manifest | null { + const file = path.join(this.dir, 'manifest.json.gz'); + if (!fs.existsSync(file)) { + return null; + } + try { + const manifest = JSON.parse(this.readGz(file)); + if (manifest?.format !== CACHE_FORMAT) { + this.manifestProblem = 'the cache was made by a different version of SUSHI'; + return null; + } + return manifest; + } catch (e) { + this.manifestProblem = `the cache could not be read (${e.message})`; + return null; + } + } + + open() { + fs.mkdirSync(this.payloadDir, { recursive: true }); + const ignore = path.join(this.dir, '.gitignore'); + if (!fs.existsSync(ignore)) { + fs.writeFileSync(ignore, '# SUSHI incremental build cache\n*\n'); + } + for (const file of fs.readdirSync(this.payloadDir)) { + if (file.endsWith('.json.gz')) { + this.known.add(file.slice(0, -'.json.gz'.length)); + } + } + } + + putPayload(json: string): string { + const ref = hashString(json); + // A payload that went missing since the build started is written again + if (!this.known.has(ref) || !this.touch(ref)) { + try { + this.writeGz(path.join(this.payloadDir, `${ref}.json.gz`), json); + } catch (e) { + this.writeError = this.writeError ?? e.message; + throw e; + } + this.known.add(ref); + } + return ref; + } + + getPayload(ref: string): any { + if (!/^[A-Za-z0-9_-]+$/.test(ref)) { + throw new Error('Invalid payload reference'); + } + const file = path.join(this.payloadDir, `${ref}.json.gz`); + // Failing to read the file (it is missing, or the system refused) says nothing about its + // content, but content that does not unzip, match its hash or parse is corrupt + let data: Buffer; + try { + data = fs.readFileSync(file); + } catch (e) { + // So it is written again if this build produces it + this.known.delete(ref); + throw e; + } + try { + const json = zlib.gunzipSync(data).toString('utf8'); + if (hashString(json) !== ref) { + throw new Error(`Corrupt cache payload ${ref}`); + } + const value = JSON.parse(json); + this.touch(ref); + return value; + } catch (e) { + // Remove it, so it is written again if this build produces it + this.known.delete(ref); + try { + fs.unlinkSync(file); + this.corruptPayloads++; + } catch (err) { + this.cleanupFailed(err); + } + throw e; + } + } + + /** Notes that a result could not be cached. */ + writeFailed(e: any) { + this.writeError = this.writeError ?? e?.message ?? String(e); + } + + /** Notes a failure to remove a file, unless another build already removed it. */ + private cleanupFailed(e: any) { + if (e?.code !== 'ENOENT') { + this.cleanupError = this.cleanupError ?? e?.message ?? String(e); + } + } + + /** Notes that a cached result could not be used (whether reading or decoding it failed). */ + readFailed(e: any) { + this.readFailures++; + this.readError = this.readError ?? e?.message ?? String(e); + } + + /** + * Marks a payload as in use, so a concurrent build does not collect it. Returns false if it is + * missing. + */ + private touch(ref: string): boolean { + try { + const now = new Date(); + fs.utimesSync(path.join(this.payloadDir, `${ref}.json.gz`), now, now); + } catch (e) { + if (e?.code === 'ENOENT') { + this.known.delete(ref); + return false; + } + // otherwise it is only a hint + } + return true; + } + + writeManifest(manifest: Manifest) { + try { + this.writeGz(path.join(this.dir, 'manifest.json.gz'), JSON.stringify(manifest)); + } catch (e) { + this.writeError = this.writeError ?? e.message; + throw e; + } + } + + /** + * Deletes the payloads that are no longer referenced. Payloads used or written in the last hour + * (or since this build started), and temporary files less than a day old, may be in use by + * another build, so they are kept. + */ + collectGarbage(referenced: Set) { + let files: string[]; + try { + files = fs.readdirSync(this.payloadDir); + } catch (e) { + this.cleanupFailed(e); + return; + } + for (const file of files) { + const ref = file.endsWith('.json.gz') ? file.slice(0, -'.json.gz'.length) : null; + if (ref != null && referenced.has(ref)) { + continue; + } + const full = path.join(this.payloadDir, file); + try { + const changed = fs.statSync(full).mtimeMs; + const keepAfter = + ref == null ? Date.now() - DAY : Math.min(this.startedAt, Date.now() - HOUR); + if (changed >= keepAfter) { + continue; + } + fs.unlinkSync(full); + this.known.delete(ref); + } catch (e) { + // another build may have removed it already + this.cleanupFailed(e); + } + } + } + + private readGz(file: string): string { + return zlib.gunzipSync(fs.readFileSync(file)).toString('utf8'); + } + + private writeGz(file: string, text: string) { + const temp = `${file}.${process.pid}.${Math.random().toString(36).slice(2)}.tmp`; + try { + fs.writeFileSync(temp, zlib.gzipSync(Buffer.from(text, 'utf8'), { level: 1 })); + fs.renameSync(temp, file); + } catch (e) { + try { + fs.unlinkSync(temp); + } catch { + // nothing to clean up + } + throw e; + } + } +} diff --git a/src/incremental/ExportSession.ts b/src/incremental/ExportSession.ts new file mode 100644 index 000000000..0163f0d63 --- /dev/null +++ b/src/incremental/ExportSession.ts @@ -0,0 +1,1717 @@ +import cloneDeep from 'lodash/cloneDeep'; +import { logger } from '../utils/FSHLogger'; +import { Type } from '../utils/Fishable'; +import { StructureDefinition } from '../fhirtypes/StructureDefinition'; +import { InstanceExporter } from '../export/InstanceExporter'; +import { getUrlFromFshDefinition, getVersionFromFshDefinition } from '../fhirtypes/common'; +import { getNonInstanceValueFromRules } from '../fshtypes/common'; +import { AssignmentRule } from '../fshtypes/rules'; +import { FshCode } from '../fshtypes/FshCode'; +import { IncrementalSessionHooks } from './hooks'; +import { PayloadStore } from './CacheStore'; +import { copyLogInfo, emitLogInfo } from './logCapture'; +import { + ClassRegistry, + UnserializableError, + decode, + encode, + hashString, + replaceOwnProperties +} from './serialize'; +import { definitionRegistry, packageRegistry } from './registries'; + +/** + * An ExportSession records how each FSH entity (Profile, Extension, Logical, Resource, Instance, + * ValueSet, CodeSystem) was exported: every log message it wrote, every lookup it made into the + * package and the tank (and what those lookups found), every nested export it triggered, and the + * resulting FHIR object. On the next build, an entity whose definition is unchanged and whose + * lookups would all find the same things can be "replayed": its log messages are re-emitted, its + * nested exports are re-triggered in the same order, and a copy of its recorded FHIR object is + * added to the package, all without running the exporter. + * + * The rules are conservative. Anything the session cannot account for marks the entity as + * non-reusable, so it is exported normally on the next build. If, during a build, something + * happens that the session did not predict, it aborts, and the caller redoes the whole export + * from scratch without replaying anything. + */ + +type EntityKind = 'sd' | 'vs' | 'cs' | 'inst' | 'other'; +type State = 'p' | 'i' | 'd' | 'n'; + +// Script events. See the Frame class for how each is recorded and ExportSession.replay for how +// each is replayed. +export type ScriptEvent = + | ['L', any] // a log message + | ['P', string] // the entity's FHIR object was added to the named package array + | ['M', string, any] // an entry was added to the package's fshMap + | ['C'] // the duplicate id check ran (it is always re-run, never replayed) + | ['T', string, string, boolean, string[]] // nested export: key, exporter, threw, all keys exported + | ['R', any, string[], string[]] // package lookup: item, types, keys of all matches + | ['Q', string, any, string[], string[], State[], string?] // tank lookup + | ['A', string, string | null] // alias lookup: name, value + | ['S', string, boolean, string, string]; // sdCache use: url, created, fp at use, fp at end + +export interface FrameRecord { + kind: EntityKind; + ok: boolean; + why?: string; + pre: string; + script: ScriptEvent[]; + deps: Record; + vis: string | null; + afterHash: string | null; + afterRef?: string; + payloadRef?: string; + arr?: string; + sdProps?: string; + threw: boolean; + nulls?: any[]; +} + +export interface ExportState { + records: Record; + unstable?: boolean; +} + +export interface ExportStats { + exported: number; + replayed: number; + aborted: boolean; + abortReason?: string; + reasons: Record; + /** Why each entity was exported rather than replayed */ + exportedBecause: Record; + /** Unexpected errors in the session's own bookkeeping, with their stacks */ + errors: string[]; +} + +const PKG_ARRAYS = [ + 'profiles', + 'extensions', + 'logicals', + 'resources', + 'instances', + 'valueSets', + 'codeSystems' +]; +const FRAME_KINDS: Record = { + Profile: 'sd', + Extension: 'sd', + Logical: 'sd', + Resource: 'sd', + Instance: 'inst', + FshValueSet: 'vs', + FshCodeSystem: 'cs' +}; +const SD_PROPS = [ + 'resourceType', + 'id', + 'name', + 'title', + 'description', + 'version', + 'url', + 'type', + 'kind', + 'derivation', + 'baseDefinition', + 'abstract', + 'inProgress' +]; + +class AbortedError extends Error {} + +class Frame { + script: ScriptEvent[] = []; + ok = true; + why: string; + subtree: string[] = []; + segment = new Set(); + aliases = new Set(); + deps = new Map(); + pushed: { arr: string; obj: any }[] = []; + created: any[] = []; + sdTouches: { entry: any; event: any[] }[] = []; + + constructor( + public readonly key: string, + public readonly kind: EntityKind, + public readonly def: any, + public readonly exporter: any, + public readonly mode: 'record' | 'replay' + ) {} + + fail(why: string) { + if (this.ok) { + this.ok = false; + this.why = why; + } + } +} + +/** + * Whether replaying an sdCache use leaves the cache behind what the export would have made it. A + * newly created entry that was not changed is the same as the one the next export using it will + * create; any other use may have changed the entry in ways its fingerprint does not show. + */ +function leavesBehind(ev: ScriptEvent): boolean { + return !(ev[0] === 'S' && ev[2] && ev[3] === ev[4]); +} + +export function sdFingerprint(sd: any): string { + const elements: any[] = sd?.elements ?? []; + let s = `${elements.length}`; + for (const e of elements) { + s += `\n${e?.id}:${e == null ? 0 : Object.keys(e).length}`; + } + return hashString(s); +} + +function sameSequence(a: string[], b: string[]): boolean { + return a.length === b.length && a.every((x, i) => x === b[i]); +} + +export class ExportSession implements IncrementalSessionHooks { + private ctx: any; + private phase: 'idle' | 'main' | 'post' | 'done' = 'idle'; + private readonly defRegistry: ClassRegistry = definitionRegistry(); + private readonly pkgRegistry: ClassRegistry = packageRegistry(); + private readonly oldRecords: Map; + readonly records = new Map(); + + private keyToDef = new Map(); + private defToKey = new Map(); + private kindOfKey = new Map(); + private preHash = new Map(); + private beginSigs = new Map(); + private objKey = new WeakMap(); + private status = new Map(); + private frameCount = new Map(); + private replayed = new Set(); + private liveVis = new Map(); + private liveAfter = new Map(); + private liveObjects = new Map(); + private standIns = new Map(); + private postReads = new Set(); + private probeMemo = new Map(); + // What each InstanceExporter's sdCache would hold if replayed exports had really run. The + // cached StructureDefinitions are changed (unfolded) by the exports that use them, and replaying + // an export does not do that, so the cache can fall behind. A replay is allowed only when the + // cache is as it was when the export was recorded, and an export that runs cannot use an entry + // that has fallen behind (the session aborts if that happens). + private cacheViews = new Map>(); + // sdCache entries (of the main InstanceExporter) that exports expected to run will use. Replays + // that would change these entries are not allowed, so the entries never fall behind. + private pinnedUrls = new Set(); + private stack: Frame[] = []; + private tankDepth = 0; + private outerTankMethod: string = null; + private stash: any = undefined; + private suppress = 0; + private inCheck = 0; + private buffer: any[] = []; + private buffering = false; + private origWrite: any = null; + private restorers: (() => void)[] = []; + private replayEnabled: boolean; + private readonly canAbort: boolean; + unstable = false; + saveable = true; + aborted = false; + abortReason: string; + readonly reasons: Record = {}; + /** Why exports from the previous build could not be replayed at all, if they could not */ + readonly notes: string[] = []; + readonly errors: string[] = []; + private untracked = 0; + /** Whether any record of the previous build was looked at */ + consultedOld = false; + + constructor( + private readonly store: PayloadStore, + old: ExportState | null + ) { + this.oldRecords = new Map(Object.entries(old?.records ?? {})); + this.replayEnabled = old != null && !old.unstable; + this.canAbort = this.replayEnabled; + if (old?.unstable) { + this.notes.push( + 'exports were not reused, as a definition changed unexpectedly during the previous build' + ); + } + } + + /** Whether anything may be replayed, so the export may have to be redone */ + get mayReplay(): boolean { + return this.started && this.canAbort && this.replayEnabled; + } + + // Whether the export has begun, so that something may have been replayed + private started = false; + + get stats(): ExportStats { + return { + exported: this.status.size + this.untracked, + replayed: this.replayed.size, + aborted: this.aborted, + abortReason: this.abortReason, + reasons: this.reasons, + exportedBecause: Object.fromEntries(this.exportedBecause), + errors: this.errors + }; + } + + private lastReason: string; + private readonly exportedBecause = new Map(); + + getState(): ExportState { + const records: Record = {}; + this.records.forEach((rec, key) => (records[key] = rec)); + return { records, unstable: this.unstable }; + } + + // ---------------------------------------------------------------------------------------- + // Setup and teardown + // ---------------------------------------------------------------------------------------- + + beginExport(ctx: any): void { + this.ctx = ctx; + this.phase = 'main'; + this.started = true; + // The logger goes first, so the lookups made while preparing can be kept quiet + this.installLogger(); + try { + this.indexTank(); + if (this.replayEnabled) { + this.suppress++; + try { + this.pinSdCacheEntries(); + } finally { + this.suppress--; + } + } + } catch (e) { + // Nothing has been exported yet, so just export everything and keep no record of it + if (this.replayEnabled) { + this.notes.push('exports were not reused, as the export could not be prepared'); + } + this.replayEnabled = false; + this.saveable = false; + this.abortReason = `could not prepare the export (${e?.message})`; + this.keepError('preparing the export', e); + } + this.installPackageHooks(); + this.installTankHooks(); + } + + private indexTank() { + const tank = this.ctx.tank; + const entities = [ + ...tank.getAllStructureDefinitions(), + ...tank.getAllInstances(), + ...tank.getAllValueSets(), + ...tank.getAllCodeSystems(), + ...tank.getAllInvariants(), + ...tank.getAllRuleSets(), + ...tank.getAllMappings() + ]; + const add = (key: string, def: any, kind: EntityKind) => { + if (this.keyToDef.has(key) || this.defToKey.has(def)) { + // Two entities with the same key cannot be told apart, so nothing can be reused safely + if (this.replayEnabled) { + this.notes.push(`exports were not reused, as there are two definitions of ${key}`); + } + this.replayEnabled = false; + this.saveable = false; + this.abortReason = this.abortReason ?? `there are two definitions of ${key}`; + return; + } + this.keyToDef.set(key, def); + this.defToKey.set(def, key); + this.kindOfKey.set(key, kind); + this.preHash.set(key, this.hashDef(def)); + if (kind !== 'other') { + this.beginSigs.set(key, this.fishSignature(def)); + } + }; + for (const def of entities) { + add(`${def.constructorName}:${def.name}`, def, FRAME_KINDS[def.constructorName] ?? 'other'); + } + for (const doc of tank.docs) { + doc.appliedRuleSets.forEach((ruleSet: any, id: string) => { + const key = `AppliedRuleSet:${id}`; + if (!this.keyToDef.has(key)) { + add(key, ruleSet, 'other'); + } + }); + } + } + + /** + * Finds the sdCache entries that Instances which may be exported (not replayed) use, so replays + * never leave those entries behind. Only uses what is known before exporting anything: an entity + * may be exported if it or something it used changed, or if it changes a pinned entry, since its + * replay is then refused. + */ + private pinSdCacheEntries() { + const mayExport = new Set(); + const pinFrom = (key: string, def: any) => { + if (this.oldRecords.has(key)) { + this.consultedOld = true; + } + for (const ev of this.oldRecords.get(key)?.script ?? []) { + if (ev[0] === 'S') { + this.pinnedUrls.add(ev[1]); + } + } + if (this.kindOfKey.get(key) !== 'inst') { + return; + } + try { + const url = this.ctx.fisher.fishForMetadata( + def.instanceOf, + Type.Resource, + Type.Profile, + Type.Extension, + Type.Type, + Type.Logical + )?.url; + if (url != null) { + this.pinnedUrls.add(url); + } + } catch (e) { + // Which entries this Instance will use is unknown, so no replay can be trusted not to + // change them + if (this.replayEnabled) { + this.notes.push( + `exports were not reused, as looking up ${def.instanceOf} failed (${e?.message})` + ); + } + this.replayEnabled = false; + this.keepError(`looking up ${def.instanceOf}`, e); + } + }; + this.keyToDef.forEach((def, key) => { + if (this.kindOfKey.get(key) !== 'other' && !this.staticallyReusable(key)) { + mayExport.add(key); + pinFrom(key, def); + } + }); + const usesAny = (rec: FrameRecord) => + rec.script.some(ev => { + switch (ev[0]) { + case 'R': + return ev[3].some(k => mayExport.has(k)); + case 'Q': + return ev[4].some(k => mayExport.has(k)); + case 'T': + return mayExport.has(ev[1]) || ev[4].some(k => mayExport.has(k)); + case 'S': + return leavesBehind(ev) && this.pinnedUrls.has(ev[1]); + default: + return false; + } + }); + let grew = true; + while (grew) { + grew = false; + this.keyToDef.forEach((def, key) => { + const rec = this.oldRecords.get(key); + if (rec != null && !mayExport.has(key) && usesAny(rec)) { + mayExport.add(key); + pinFrom(key, def); + grew = true; + } + }); + } + } + + private staticallyReusable(key: string): boolean { + const old = this.oldRecords.get(key); + const pre = this.preHash.get(key); + if (old != null) { + this.consultedOld = true; + } + if (old == null || !old.ok || old.kind !== this.kindOfKey.get(key) || pre == null) { + return false; + } + if (pre !== old.pre) { + return false; + } + if (Object.entries(old.deps).some(([dep, hash]) => this.preHash.get(dep) !== hash)) { + return false; + } + return old.script.every(ev => (ev[0] === 'A' || ev[0] === 'Q' ? this.probe(ev) : true)); + } + + private hashDef(def: any): string | null { + try { + return hashString(JSON.stringify(encode(def, this.defRegistry))); + } catch (e) { + if (e instanceof UnserializableError) { + return null; + } + throw e; + } + } + + /** + * Everything about a definition that decides which lookups in the tank find it, and what + * metadata the tank reports for it. Lookups are checked against the tank as it is at the start + * of the export, so this must not change while exporting. + */ + private fishSignature(def: any): string { + const tank = this.ctx.tank; + const sig: any[] = [ + def.name, + def.id, + getUrlFromFshDefinition(def, tank.config.canonical), + getVersionFromFshDefinition(def, tank.config.version), + tank.extractMetadataFromEntity(def) + ]; + if (def.constructorName !== 'Instance') { + if (def.constructorName === 'FshValueSet' || def.constructorName === 'FshCodeSystem') { + sig.push(getNonInstanceValueFromRules(def, 'name', '', 'name')); + } + } else { + sig.push(def.instanceOf, def.usage, getNonInstanceValueFromRules(def, 'name', '', 'name')); + for (const rule of def.rules) { + if (rule instanceof AssignmentRule && ['derivation', 'kind', 'type'].includes(rule.path)) { + sig.push([rule.path, rule.value instanceof FshCode ? `#${rule.value.code}` : rule.value]); + } + } + } + return JSON.stringify(sig); + } + + private installLogger() { + this.origWrite = logger.write; + // eslint-disable-next-line @typescript-eslint/no-this-alias + const session = this; + const write = function (info: any, ...rest: any[]) { + return session.onLog(info, rest); + }; + Object.defineProperty(logger, 'write', { value: write, configurable: true, writable: true }); + this.buffering = true; + this.restorers.push(() => { + delete (logger as any).write; + if (logger.write !== this.origWrite) { + Object.defineProperty(logger, 'write', { + value: this.origWrite, + configurable: true, + writable: true + }); + } + }); + } + + private installPackageHooks() { + const pkg = this.ctx.pkg; + // eslint-disable-next-line @typescript-eslint/no-this-alias + const session = this; + for (const arr of PKG_ARRAYS) { + const target = pkg[arr]; + Object.defineProperty(target, 'push', { + value: function (...items: any[]) { + session.safely(() => session.onPush(arr, items)); + return Array.prototype.push.apply(this, items); + }, + configurable: true, + writable: true, + enumerable: false + }); + this.restorers.push(() => delete target.push); + } + const fshMap = pkg.fshMap; + Object.defineProperty(fshMap, 'set', { + value: function (key: string, value: any) { + session.safely(() => session.onFshMapSet(key, value)); + return Map.prototype.set.call(this, key, value); + }, + configurable: true, + writable: true, + enumerable: false + }); + this.restorers.push(() => delete fshMap.set); + for (const method of ['fish', 'fishAll']) { + const orig = pkg[method]; + Object.defineProperty(pkg, method, { + value: function (item: any, ...types: Type[]) { + session.safely(() => session.onPackageRead(item, types)); + return orig.call(this, item, ...types); + }, + configurable: true, + writable: true, + enumerable: false + }); + this.restorers.push(() => delete pkg[method]); + } + } + + private installTankHooks() { + const tank = this.ctx.tank; + // eslint-disable-next-line @typescript-eslint/no-this-alias + const session = this; + const methods: [string, string][] = [ + ['fish', 'f'], + ['fishAll', 'a'], + ['fishForMetadata', 'md'], + ['fishForMetadatas', 'mds'], + ['fishForAppliedRuleSet', 'rs'], + ['resolveAlias', 'al'] + ]; + for (const [method, code] of methods) { + const orig = tank[method]; + Object.defineProperty(tank, method, { + value: function (...args: any[]) { + const depth = session.tankDepth; + if (depth === 0) { + session.outerTankMethod = code; + session.stash = undefined; + } + session.tankDepth++; + let result: any; + try { + result = orig.apply(this, args); + } finally { + session.tankDepth--; + } + if (depth === 0) { + session.outerTankMethod = null; + session.safely(() => session.onTankRead(code, args, result)); + } else if ( + depth === 1 && + session.stash === undefined && + (code === 'f' || code === 'a') && + (session.outerTankMethod === 'md' || session.outerTankMethod === 'mds') + ) { + session.stash = result; + } + return result; + }, + configurable: true, + writable: true, + enumerable: false + }); + this.restorers.push(() => delete tank[method]); + } + } + + enterPostExport(): void { + if (this.phase !== 'main') { + return; + } + this.phase = 'post'; + if (!this.aborted) { + this.safely(() => this.checkAfterExport()); + } + } + + private checkAfterExport(): void { + // Definitions should only change while they are being exported, and the lookups recorded for + // replay assume that the things that decide what a lookup finds do not change at all + let unexpected: string = null; + this.keyToDef.forEach((def, key) => { + const kind = this.kindOfKey.get(key); + if (kind !== 'other' && this.fishSignature(def) !== this.beginSigs.get(key)) { + unexpected = unexpected ?? `lookup identity of ${key} changed`; + if (this.records.has(key)) { + this.failRecord(this.records.get(key), 'identity changed'); + } + } + const expected = this.records.has(key) + ? this.records.get(key).afterHash + : this.preHash.get(key); + if (this.replayed.has(key) && this.records.get(key).afterRef == null) { + // replayed with no recorded change; its definition is still the one hashed at the start + if (this.hashDef(def) !== this.preHash.get(key)) { + unexpected = unexpected ?? `definition of ${key} changed outside its export`; + } + } else if (this.hashDef(def) !== expected) { + unexpected = unexpected ?? `definition of ${key} changed outside its export`; + if (this.records.has(key)) { + this.failRecord(this.records.get(key), 'definition changed outside export'); + } + } + }); + if (unexpected != null) { + this.unstable = true; + if (this.replayed.size > 0) { + this.abort(unexpected); + return; + } + } + // The recorded FHIR objects must still be what they were when their export finished + this.liveObjects.forEach(({ obj, payloadHash }, key) => { + const rec = this.records.get(key); + const current = this.payloadOf(rec.kind, obj); + if (current == null || hashString(current) !== payloadHash) { + this.failRecord(rec, 'changed after export'); + if (this.replayed.size > 0) { + this.abort(`${key} changed after its export`); + } + } + }); + this.standIns.forEach((obj, key) => { + const rec = this.records.get(key); + if (rec.kind !== 'sd') { + const current = this.payloadOf(rec.kind, obj); + if (current == null || hashString(current) !== rec.payloadRef) { + this.abort(`replayed ${key} changed after its export`); + } + } + }); + // Profiles with deferred rules are changed again after all exports + const sdExporter = this.ctx.structureDefinitionExporter; + this.liveObjects.forEach(({ obj }, key) => { + const rec = this.records.get(key); + if (rec.kind === 'sd') { + const bindings = sdExporter.knownBindingRules?.get(obj); + if (sdExporter.deferredCaretRules?.has(obj)) { + this.failRecord(rec, 'deferred rules'); + } else if ( + bindings != null && + (bindings.some((b: any) => b.isInline) || obj.contained?.length > 0) + ) { + this.failRecord(rec, 'deferred bindings'); + } + } + }); + } + + endExport(): void { + if (this.phase === 'done') { + return; + } + if (this.phase === 'main') { + this.enterPostExport(); + } + this.phase = 'done'; + this.postReads.forEach(key => { + const rec = this.records.get(key); + if (rec != null) { + this.failRecord(rec, 'used after export'); + } + }); + this.restorers.reverse().forEach(r => r()); + this.restorers = []; + this.buffering = false; + const buffered = this.buffer; + this.buffer = []; + if (!this.aborted) { + for (const info of buffered) { + this.origWrite.call(logger, info); + } + } + } + + /** + * Stops the export hooks without emitting anything. Used when the export failed or aborted + * and is going to be redone. + */ + dispose(flush: boolean): void { + if (!flush) { + this.aborted = true; + } + this.saveable = false; + this.restorers.reverse().forEach(r => r()); + this.restorers = []; + this.buffering = false; + const buffered = this.buffer; + this.buffer = []; + this.phase = 'done'; + if (flush && this.origWrite != null) { + for (const info of buffered) { + this.origWrite.call(logger, info); + } + } + } + + // ---------------------------------------------------------------------------------------- + // Hooks from the exporters + // ---------------------------------------------------------------------------------------- + + exportEntity(kind: string, exporter: any, def: any, live: () => any): any { + if (this.aborted) { + return undefined; + } + const parent = this.top(); + const key = this.defToKey.get(def); + if (key == null || this.kindOfKey.get(key) !== kind) { + // Not an entity from the tank (or not the kind we expect), so it cannot be tracked + this.untracked++; + this.failStack('untracked export'); + if (parent?.mode === 'replay') { + this.abort('untracked export during replay'); + return undefined; + } + return live(); + } + const count = (this.frameCount.get(key) ?? 0) + 1; + this.frameCount.set(key, count); + const ref = this.exporterRef(kind, exporter, parent); + if (count === 1 && ref !== 'other') { + let plan: { old: FrameRecord; standIn: any } = null; + try { + plan = this.planReplay(key, kind as EntityKind, def, exporter, parent); + } catch (e) { + this.keepError(`checking ${key}`, e); + this.abort(`could not check ${key}: ${e?.message}`); + if (this.aborted) { + return undefined; + } + } + if (plan != null) { + return this.replay(key, kind as EntityKind, def, exporter, parent, ref, plan); + } + this.exportedBecause.set(key, this.lastReason); + } + return this.record(key, kind as EntityKind, def, exporter, parent, ref, live, count); + } + + check(fn: () => void): void { + const frame = this.top(); + if (frame?.mode === 'record') { + frame.script.push(['C']); + } + this.inCheck++; + try { + fn(); + } finally { + this.inCheck--; + } + } + + noteSdCache(exporter: any, url: string, created: boolean): void { + this.safely(() => { + const view = this.cacheViews.get(exporter); + const virtual = view?.get(url); + if (virtual != null) { + if (virtual.behind) { + this.abort( + `${this.top()?.key} used the cached ${url}, which the replay of ${virtual.by} did not update` + ); + } + view.delete(url); + } + const frame = this.top(); + if (frame?.mode !== 'record' || this.suppress > 0) { + return; + } + const entry = exporter?.sdCache?.get(url); + const event: ScriptEvent = ['S', url, created, sdFingerprint(entry), null]; + frame.script.push(event); + frame.sdTouches.push({ entry, event }); + if (frame.exporter !== exporter) { + frame.fail('sdCache of another exporter'); + } + }); + } + + /** The fingerprint of an sdCache entry as it would be had replays really run (null if absent). */ + private cachedFp(exporter: any, url: string): string | null { + const virtual = this.cacheViews.get(exporter)?.get(url); + if (virtual != null) { + return virtual.fp; + } + const entry = exporter?.sdCache?.get(url); + return entry != null ? sdFingerprint(entry) : null; + } + + /** Checks the sdCache uses of an export against the cache, to tell whether it can be replayed. */ + private sdCacheMatches(script: ScriptEvent[], exporter: any): boolean { + for (const ev of script) { + if (ev[0] !== 'S') { + continue; + } + const [, url, created, fp] = ev; + const current = this.cachedFp(exporter, url); + if (created ? current != null || this.cacheViews.get(exporter)?.has(url) : current !== fp) { + return false; + } + if (leavesBehind(ev) && exporter === this.ctx.instanceExporter && this.pinnedUrls.has(url)) { + return false; + } + } + return true; + } + + /** After a replay, notes how the sdCache would have changed had the export really run. */ + private applySdCacheEffects(script: ScriptEvent[], exporter: any, by: string) { + for (const ev of script) { + if (ev[0] !== 'S') { + continue; + } + const [, url, , , endFp] = ev; + if (!this.cacheViews.has(exporter)) { + this.cacheViews.set(exporter, new Map()); + } + this.cacheViews.get(exporter).set(url, { fp: endFp, behind: leavesBehind(ev), by }); + } + } + + noteNewInstanceExporter(exporter: any): void { + const frame = this.top(); + if (frame?.mode === 'record') { + frame.created.push(exporter); + } + } + + checkNullValues(resource: any, check: () => void): void { + const key = this.objKey.get(resource); + const rec = key != null ? this.records.get(key) : null; + if (rec != null && rec.kind === 'sd' && this.standIns.get(key) === resource) { + for (const info of rec.nulls ?? []) { + this.emit(info); + } + return; + } + if (rec == null || rec.kind !== 'sd' || !rec.ok) { + check(); + return; + } + const origWrite = logger.write; + const captured: any[] = []; + // eslint-disable-next-line @typescript-eslint/no-this-alias + const session = this; + Object.defineProperty(logger, 'write', { + value: function (info: any, ...rest: any[]) { + const copy = session.copyInfo(info); + if (copy == null) { + session.failRecord(rec, 'unrecordable log'); + } else { + captured.push(copy); + } + return origWrite.call(logger, info, ...rest); + }, + configurable: true, + writable: true + }); + try { + check(); + } finally { + delete (logger as any).write; + if (logger.write !== origWrite) { + Object.defineProperty(logger, 'write', { + value: origWrite, + configurable: true, + writable: true + }); + } + } + rec.nulls = captured; + } + + // ---------------------------------------------------------------------------------------- + // Recording + // ---------------------------------------------------------------------------------------- + + private top(): Frame | undefined { + return this.stack[this.stack.length - 1]; + } + + private recordingFrame(): Frame | null { + if (this.suppress > 0 || this.phase !== 'main') { + return null; + } + const frame = this.top(); + return frame?.mode === 'record' ? frame : null; + } + + private exporterRef(kind: string, exporter: any, parent: Frame | undefined): string { + if (kind === 'sd') { + return exporter === this.ctx.structureDefinitionExporter ? 'top' : 'other'; + } else if (kind === 'vs') { + return exporter === this.ctx.valueSetExporter ? 'top' : 'other'; + } else if (kind === 'cs') { + return exporter === this.ctx.codeSystemExporter ? 'top' : 'other'; + } + if (exporter === this.ctx.instanceExporter) { + return 'top'; + } else if (parent != null && exporter === parent.exporter) { + return 'same'; + } else if (parent != null && parent.created.includes(exporter)) { + return `new#${parent.created.indexOf(exporter)}`; + } + return 'other'; + } + + private record( + key: string, + kind: EntityKind, + def: any, + exporter: any, + parent: Frame | undefined, + ref: string, + live: () => any, + count: number + ): any { + const frame = new Frame(key, kind, def, exporter, 'record'); + if (this.phase !== 'main') { + frame.fail('exported after the main export'); + } + if (count > 1) { + frame.fail('exported more than once'); + const earlier = this.records.get(key); + if (earlier != null) { + this.failRecord(earlier, 'exported more than once'); + } + } + if (ref === 'other') { + frame.fail('unknown exporter'); + parent?.fail('nested export from unknown exporter'); + } + if (parent == null && ref !== 'top') { + frame.fail('top-level export from unknown exporter'); + } + this.stack.push(frame); + this.status.set(key, 'i'); + let result: any; + let threw = false; + let error: any; + try { + result = live(); + } catch (e) { + threw = true; + error = e; + } finally { + this.stack.pop(); + } + this.status.set(key, 'd'); + frame.subtree.push(key); + if (!this.aborted) { + try { + this.finishRecord(frame, threw); + } catch (e) { + this.keepError(`recording ${key}`, e); + this.abort(`could not record ${key}: ${e?.message}`); + } + } + this.afterChild(parent, frame, ref, threw); + if (threw) { + throw error; + } + return result; + } + + private finishRecord(frame: Frame, threw: boolean) { + const rec: FrameRecord = { + kind: frame.kind, + ok: frame.ok, + why: frame.why, + pre: this.preHash.get(frame.key), + script: frame.script, + deps: Object.fromEntries(frame.deps), + vis: null, + afterHash: null, + threw + }; + if (threw) { + this.failRecord(rec, 'threw'); + } + if (rec.pre == null) { + this.failRecord(rec, 'unserializable definition'); + } + for (const { entry, event } of frame.sdTouches) { + event[4] = sdFingerprint(entry); + } + rec.afterHash = this.hashDef(frame.def); + if (rec.afterHash == null) { + this.failRecord(rec, 'unserializable definition after export'); + } + if (frame.pushed.length > 1) { + this.failRecord(rec, 'pushed more than once'); + } + let payload: string = null; + let obj: any; + if (frame.pushed.length === 1 && !threw) { + obj = frame.pushed[0].obj; + rec.arr = frame.pushed[0].arr; + payload = this.payloadOf(frame.kind, obj); + if (payload == null) { + this.failRecord(rec, 'unserializable result'); + } + } else if (frame.pushed.length === 0 && !threw) { + payload = ''; + } + if (payload != null && !threw) { + rec.vis = hashString(`${rec.arr ?? ''}\n${payload}`); + } + if (rec.ok) { + if (rec.afterHash !== rec.pre) { + try { + rec.afterRef = this.store.putPayload(JSON.stringify(encode(frame.def, this.defRegistry))); + } catch (e) { + this.storeFailed(frame.key, e); + this.failRecord(rec, 'could not store definition'); + } + } + if (obj != null && rec.ok) { + try { + rec.payloadRef = this.store.putPayload(payload); + } catch (e) { + this.storeFailed(frame.key, e); + this.failRecord(rec, 'could not store result'); + } + if (frame.kind === 'sd') { + rec.sdProps = this.sdProps(obj); + } + } + } + if (obj != null && payload != null) { + this.liveObjects.set(frame.key, { obj, payloadHash: hashString(payload) }); + } + this.liveVis.set(frame.key, rec.vis); + this.liveAfter.set(frame.key, rec.afterHash); + this.records.set(frame.key, rec); + } + + private payloadOf(kind: EntityKind, obj: any): string | null { + try { + if (kind === 'sd') { + return JSON.stringify({ json: obj.toJSON(true), wjson: obj.toJSON(false) }); + } + return JSON.stringify({ obj: encode(obj, this.pkgRegistry) }); + } catch (e) { + if (e instanceof UnserializableError) { + return null; + } + throw e; + } + } + + private sdProps(sd: any): string { + return JSON.stringify([ + this.ctx.pkg.extractMetadata(sd) ?? null, + sd.getFileName(), + ...SD_PROPS.map(p => sd[p] ?? null) + ]); + } + + private failRecord(rec: FrameRecord, why: string) { + if (rec.ok) { + rec.ok = false; + rec.why = why; + } + } + + private afterChild(parent: Frame | undefined, child: Frame, ref: string, threw: boolean) { + if (parent == null) { + return; + } + parent.subtree.push(...child.subtree); + if (parent.mode === 'record') { + parent.script.push(['T', child.key, ref, threw, child.subtree.slice()]); + parent.segment.clear(); + } + } + + private failStack(why: string) { + for (const frame of this.stack) { + if (frame.mode === 'record') { + frame.fail(why); + } + } + } + + private stateOf(key: string): State { + const status = this.status.get(key); + if (status != null) { + return status; + } + return this.kindOfKey.get(key) === 'other' ? 'n' : 'p'; + } + + /** Reading an entity that is still being exported. */ + private readInProgress(key: string) { + const owner = this.stack.find(f => f.key === key); + if (owner?.mode === 'replay') { + this.abort(`${key} was read while being replayed`); + } + this.failStack('read an entity that was still being exported'); + } + + private onLog(info: any, rest: any[]) { + if (this.aborted) { + // nothing logged during an aborted export is kept + return true; + } + const frame = this.recordingFrame(); + if (this.suppress > 0) { + // lookups made to check whether something can be replayed must not log anything + return true; + } + if (frame != null && this.inCheck === 0) { + const copy = this.copyInfo(info); + if (copy == null) { + frame.fail('unrecordable log'); + } else { + frame.script.push(['L', copy]); + } + } + if (this.buffering) { + this.buffer.push(info); + return true; + } + return this.origWrite.call(logger, info, ...rest); + } + + private copyInfo(info: any): any { + return copyLogInfo(info); + } + + private emit(copy: any) { + emitLogInfo(copy); + } + + private onPush(arr: string, items: any[]) { + const frame = this.top(); + for (const obj of items) { + if (frame != null) { + this.objKey.set(obj, frame.key); + } + } + if (frame == null) { + return; + } + for (const obj of items) { + frame.pushed.push({ arr, obj }); + } + if (frame.mode === 'record') { + frame.script.push(['P', arr]); + frame.segment.clear(); + if (items.length !== 1) { + frame.fail('unexpected push'); + } + } + } + + private onFshMapSet(fileName: string, value: any) { + const frame = this.recordingFrame(); + if (frame == null) { + return; + } + try { + frame.script.push(['M', fileName, JSON.parse(JSON.stringify(value))]); + } catch { + frame.fail('unrecordable fshMap entry'); + } + } + + private matchKeys(item: any, types: Type[]): string[] | null { + const matches: any[] = this.ctx.pkg.findAllMatches(item, ...types); + const keys: string[] = []; + for (const m of matches) { + const key = this.objKey.get(m); + if (key == null) { + return null; + } + keys.push(key); + } + return keys; + } + + private onPackageRead(item: any, types: Type[]) { + if (this.suppress > 0) { + return; + } + if (this.phase === 'post') { + // Some post-export steps change what they find, so whatever they find cannot be reused + const keys = this.matchKeys(item, types); + if (keys == null) { + return; + } + keys.forEach(k => { + this.postReads.add(k); + if (this.replayed.has(k) && this.stack.length === 0) { + this.abort(`replayed ${k} was used after export`); + } + }); + return; + } + const frame = this.recordingFrame(); + if (frame == null) { + return; + } + if (types.length === 1 && types[0] === Type.Type) { + return; + } + const segKey = `R${JSON.stringify([item ?? null, types])}`; + if (frame.segment.has(segKey)) { + return; + } + frame.segment.add(segKey); + const keys = this.matchKeys(item, types); + if (keys == null) { + frame.fail('found an untracked package object'); + return; + } + for (const k of keys) { + if (k !== frame.key && this.status.get(k) === 'i') { + this.readInProgress(k); + } + } + frame.script.push(['R', item ?? null, types, keys]); + } + + private onTankRead(code: string, args: any[], result: any) { + const frame = this.recordingFrame(); + if (frame == null) { + return; + } + if (code === 'al') { + const name = args[0]; + if (!frame.aliases.has(name)) { + frame.aliases.add(name); + frame.script.push(['A', name, result ?? null]); + } + return; + } + const item = args[0] ?? null; + const types: Type[] = code === 'rs' ? [] : args.slice(1); + if (types.length === 1 && types[0] === Type.Type) { + return; + } + const segKey = `Q${code}${JSON.stringify([item, types])}`; + if (frame.segment.has(segKey)) { + return; + } + frame.segment.add(segKey); + let found: any[]; + if (code === 'f' || code === 'rs') { + found = result != null ? [result] : []; + } else if (code === 'a') { + found = result ?? []; + } else if (code === 'md') { + found = this.stash != null ? [this.stash] : []; + } else { + found = this.stash ?? []; + } + const keys: string[] = []; + for (const def of found) { + const key = this.defToKey.get(def); + if (key == null) { + frame.fail('found an untracked definition'); + return; + } + keys.push(key); + } + const states = keys.map(k => (k === frame.key ? 'i' : this.stateOf(k))); + keys.forEach((k, i) => { + if (k !== frame.key && states[i] === 'i') { + this.readInProgress(k); + } + }); + let extra: string; + if (code === 'md' || code === 'mds') { + if (keys.some(k => k.startsWith('RuleSet:'))) { + frame.fail('metadata lookup of a RuleSet'); + } + extra = hashString(JSON.stringify(result ?? null)); + } else { + keys.forEach(k => frame.deps.set(k, this.preHash.get(k))); + } + const ev: ScriptEvent = ['Q', code, item, types, keys, states]; + if (extra != null) { + ev.push(extra); + } + frame.script.push(ev); + } + + // ---------------------------------------------------------------------------------------- + // Replay + // ---------------------------------------------------------------------------------------- + + private reason(why: string) { + this.reasons[why] = (this.reasons[why] ?? 0) + 1; + this.lastReason = why; + return null as null; + } + + /** Whether a dependency produced exactly what it produced when the entity was recorded. */ + private sameOutput(key: string): boolean { + if (this.replayed.has(key)) { + return true; + } + const old = this.oldRecords.get(key); + const vis = this.liveVis.get(key); + return ( + old != null && + vis != null && + vis === old.vis && + this.liveAfter.get(key) != null && + this.liveAfter.get(key) === old.afterHash + ); + } + + private probe(ev: ScriptEvent): boolean { + const memoKey = JSON.stringify(ev.slice(0, ev[0] === 'A' ? 2 : 4)); + let value = this.probeMemo.get(memoKey); + if (value == null) { + const tank = this.ctx.tank; + this.suppress++; + try { + if (ev[0] === 'A') { + value = JSON.stringify(tank.resolveAlias(ev[1]) ?? null); + } else { + const [, code, item, types] = ev as any[]; + const keyOf = (def: any) => this.defToKey.get(def) ?? '!unknown'; + if (code === 'f') { + value = JSON.stringify([tank.fish(item, ...types)].filter(d => d != null).map(keyOf)); + } else if (code === 'a') { + value = JSON.stringify(tank.fishAll(item, ...types).map(keyOf)); + } else if (code === 'rs') { + value = JSON.stringify( + [tank.fishForAppliedRuleSet(item)].filter(d => d != null).map(keyOf) + ); + } else { + const found: any[] = + code === 'md' + ? [tank.fish(item, ...types)].filter(d => d != null) + : tank.fishAll(item, ...types); + if (found.some(d => keyOf(d).startsWith('RuleSet:') || keyOf(d) === '!unknown')) { + value = '!ruleset'; + } else { + const result = + code === 'md' + ? tank.fishForMetadata(item, ...types) + : tank.fishForMetadatas(item, ...types); + value = hashString(JSON.stringify(result ?? null)); + } + } + } + } catch { + value = '!error'; + } finally { + this.suppress--; + } + this.probeMemo.set(memoKey, value); + } + if (ev[0] === 'A') { + return value === JSON.stringify(ev[2]); + } else if (ev[1] === 'md' || ev[1] === 'mds') { + return value === ev[6]; + } + return value === JSON.stringify(ev[4]); + } + + private planReplay( + key: string, + kind: EntityKind, + def: any, + exporter: any, + parent: Frame | undefined + ): { old: FrameRecord; standIn: any } | null { + if (!this.replayEnabled || this.phase !== 'main') { + return null; + } + const old = this.oldRecords.get(key); + if (old == null) { + return this.reason('new'); + } + this.consultedOld = true; + if (!old.ok) { + return this.reason(`not reusable: ${old.why}`); + } + if (old.kind !== kind || this.status.has(key)) { + return this.reason('unexpected state'); + } + const pre = this.preHash.get(key); + if (pre == null || pre !== old.pre) { + return this.reason('changed'); + } + for (const [dep, hash] of Object.entries(old.deps)) { + if (this.preHash.get(dep) !== hash) { + return this.reason('dependency changed'); + } + } + if (parent == null && old.script.length === 0 && old.payloadRef == null) { + return this.reason('nothing recorded'); + } + const pending = new Set(); + const ownKeys = new Set(); + for (const ev of old.script) { + switch (ev[0]) { + case 'R': { + const now = this.matchKeys(ev[1], ev[2] as Type[]); + if (now == null) { + return this.reason('untracked package object'); + } + const current = now.filter(k => k !== key); + const expected = ev[3].filter(k => k !== key && !pending.has(k)); + if (!sameSequence(current, expected)) { + return this.reason('package lookup differs'); + } + if (!current.every(k => this.sameOutput(k))) { + return this.reason('package lookup found changed output'); + } + break; + } + case 'Q': { + if (!this.probe(ev)) { + return this.reason('tank lookup differs'); + } + const [, code, , , keys, states] = ev; + for (let i = 0; i < keys.length; i++) { + const k = keys[i]; + const now = k === key ? 'i' : this.stateOf(k); + if (now === states[i]) { + if ( + now === 'd' && + (code === 'f' || code === 'a' || code === 'rs') && + !this.sameOutput(k) + ) { + return this.reason('tank lookup found changed definition'); + } + } else if (!(states[i] === 'd' && now === 'p' && pending.has(k))) { + return this.reason('tank lookup state differs'); + } + } + break; + } + case 'A': + if (!this.probe(ev)) { + return this.reason('alias differs'); + } + break; + case 'S': + if (!this.sdCacheMatches([ev], exporter)) { + return this.reason('sdCache differs'); + } + break; + case 'T': { + const [, child, ref, , subtree] = ev; + if (ref === 'other') { + return this.reason('unknown exporter'); + } + for (const k of subtree) { + const rec = this.oldRecords.get(k); + if (this.status.has(k) || ownKeys.has(k)) { + return this.reason('nested export already done'); + } + if (rec == null || !rec.ok || this.preHash.get(k) !== rec.pre) { + return this.reason('nested export not reusable'); + } + ownKeys.add(k); + pending.add(k); + } + if (!this.keyToDef.has(child)) { + return this.reason('nested export missing'); + } + break; + } + default: + break; + } + } + let standIn: any = null; + if (old.payloadRef != null) { + try { + const payload = this.store.getPayload(old.payloadRef); + if (kind === 'sd') { + standIn = this.makeStructureDefinition(payload); + // inProgress is not part of the JSON; it is false once an export has finished + const recordedInProgress = JSON.parse(old.sdProps).at(-1); + if (recordedInProgress != null) { + standIn.inProgress = recordedInProgress; + } + if (this.sdProps(standIn) !== old.sdProps) { + return this.reason('stand-in differs'); + } + } else { + standIn = decode(payload.obj, this.pkgRegistry); + } + } catch (e) { + this.keepError(`reading the cached result of ${key}`, e); + this.store.readFailed(e); + return this.reason('cache read failed'); + } + } else if (old.script.some(ev => ev[0] === 'P')) { + return this.reason('missing result'); + } + return { old, standIn }; + } + + private makeStructureDefinition(payload: { json: any; wjson: any }): StructureDefinition { + const sd = StructureDefinition.fromJSON(cloneDeep(payload.json)); + Object.defineProperty(sd, 'toJSON', { + value: (snapshot = true) => cloneDeep(snapshot ? payload.json : payload.wjson), + enumerable: false, + configurable: true, + writable: true + }); + return sd; + } + + private replay( + key: string, + kind: EntityKind, + def: any, + exporter: any, + parent: Frame | undefined, + ref: string, + plan: { old: FrameRecord; standIn: any } + ): any { + const { old, standIn } = plan; + const frame = new Frame(key, kind, def, exporter, 'replay'); + // exporters created while replaying are found by their position, as they were when recording + const created = frame.created; + this.stack.push(frame); + this.status.set(key, 'i'); + try { + for (const ev of old.script) { + if (this.aborted) { + break; + } + switch (ev[0]) { + case 'L': + this.emit(ev[1]); + break; + case 'P': + this.standIns.set(key, standIn); + this.ctx.pkg[ev[1]].push(standIn); + break; + case 'M': + this.ctx.pkg.fshMap.set(ev[1], { ...ev[2] }); + break; + case 'C': + this.check(() => exporter.checkForDuplicateId(standIn, def)); + break; + case 'S': + if (!this.sdCacheMatches([ev], exporter)) { + throw new AbortedError(`sdCache use by ${key} differs during replay`); + } + this.applySdCacheEffects([ev], exporter, key); + break; + case 'R': { + const now = this.matchKeys(ev[1], ev[2] as Type[]); + if ( + now == null || + !sameSequence( + now.filter(k => k !== key), + ev[3].filter(k => k !== key) + ) + ) { + throw new AbortedError(`package lookup by ${key} differs during replay`); + } + break; + } + case 'Q': { + const [, , , , keys, states] = ev; + keys.forEach((k, i) => { + if ((k === key ? 'i' : this.stateOf(k)) !== states[i]) { + throw new AbortedError(`tank lookup by ${key} differs during replay`); + } + }); + break; + } + case 'T': { + const [, child, childRef, threw] = ev; + const childDef = this.keyToDef.get(child); + const childKind = this.kindOfKey.get(child); + let childThrew = false; + let childError: any = null; + try { + if (childKind === 'sd') { + this.ctx.structureDefinitionExporter.exportStructDef(childDef); + } else { + let childExporter: any; + if (childRef === 'top') { + childExporter = this.ctx.instanceExporter; + } else if (childRef === 'same') { + childExporter = exporter; + } else { + const index = parseInt(childRef.slice(4)); + created[index] = + created[index] ?? + new InstanceExporter(this.ctx.tank, this.ctx.pkg, this.ctx.fisher); + childExporter = created[index]; + } + childExporter.exportInstance(childDef); + } + } catch (e) { + childThrew = true; + childError = e; + } + if (this.aborted) { + break; + } + if (childThrew !== threw || this.status.get(child) !== 'd' || !this.sameOutput(child)) { + const error = childError != null ? ` (it threw: ${childError?.message})` : ''; + if (childError != null) { + this.keepError(`replaying the nested export of ${child}`, childError); + } + throw new AbortedError(`nested export of ${child} differs during replay${error}`); + } + break; + } + default: + break; + } + } + } catch (e) { + if (e instanceof AbortedError) { + this.abort(e.message); + } else { + this.keepError(`replaying ${key}`, e); + this.abort(`replay of ${key} failed: ${e?.message}`); + } + } finally { + this.stack.pop(); + } + if (this.aborted) { + return undefined; + } + if (old.afterRef != null) { + try { + replaceOwnProperties(def, decode(this.store.getPayload(old.afterRef), this.defRegistry)); + } catch (e) { + this.keepError(`restoring ${key}`, e); + this.store.readFailed(e); + this.abort(`could not restore ${key}: ${e?.message}`); + return undefined; + } + } + this.status.set(key, 'd'); + this.replayed.add(key); + frame.subtree.push(key); + this.records.set(key, old); + this.afterChild(parent, frame, ref, false); + return standIn ?? undefined; + } + + /** Runs bookkeeping that must never break the export itself. */ + private safely(fn: () => void) { + try { + fn(); + } catch (e) { + this.keepError('bookkeeping', e); + this.abort(`incremental bookkeeping failed: ${e?.message}`); + } + } + + /** Keeps a failure to store a record's payload (only the first is reported as a write error). */ + private storeFailed(key: string, e: any) { + this.keepError(`storing ${key}`, e); + this.store.writeFailed(e); + } + + /** Keeps an unexpected error, with its stack, for debugging. */ + private keepError(during: string, e: any) { + this.errors.push(`while ${during}: ${e?.stack ?? e}`); + } + + private abort(why: string) { + if (!this.mayReplay) { + // Nothing was replayed or can be, so the export is exactly what it would be without a + // session. It just cannot be trusted as a record for the next build. + this.saveable = false; + this.abortReason = this.abortReason ?? why; + return; + } + if (!this.aborted) { + this.aborted = true; + this.abortReason = why; + } + } +} diff --git a/src/incremental/IncrementalBuild.ts b/src/incremental/IncrementalBuild.ts new file mode 100644 index 000000000..1e40b9375 --- /dev/null +++ b/src/incremental/IncrementalBuild.ts @@ -0,0 +1,370 @@ +import fs from 'fs'; +import path from 'path'; +import { FSHImporter, FSHTank, RawFSH } from '../import'; +import { ParseCache } from './ParseCache'; +import { exportFHIR, Package } from '../export'; +import { FHIRDefinitions } from '../fhirdefs'; +import { Configuration } from '../fshtypes'; +import { logger } from '../utils/FSHLogger'; +import { fillTank } from '../utils/Processing'; +import { incrementalHooks } from './hooks'; +import { CACHE_FORMAT, CacheStore, Manifest } from './CacheStore'; +import { ExportSession, ExportState, ExportStats } from './ExportSession'; +import { exportKey, toolKey } from './cacheKey'; +import { decode, encode } from './serialize'; +import { captureLogs, holdLogs } from './logCapture'; +import { definitionRegistry } from './registries'; + +/** + * Coordinates an incremental build. Every step falls back to doing the work normally if anything + * about the cache is missing, unreadable, or does not fit, so an incremental build always produces + * the same output as a normal one; it is only faster when the cache can be used. + */ +export class IncrementalBuild { + private readonly store: CacheStore; + private manifest: Manifest | null = null; + private tool: string; + private key: string = null; + private session: ExportSession = null; + private disabled: string = null; + private parseCache: ParseCache = null; + private notes: string[] = []; + private redone = false; + + constructor( + private readonly projectDir: string, + sushiVersion: string + ) { + this.store = CacheStore.forProject(projectDir); + // so a build that stops early does not leave the summary of an earlier one + try { + fs.rmSync(path.join(this.store.dir, 'last-run.json'), { force: true }); + } catch (e) { + logger.info(`Incremental build: could not remove the debugging summary (${e.message}).`); + } + try { + this.tool = toolKey(sushiVersion); + this.store.open(); + this.manifest = this.store.readManifest(); + if (this.store.manifestProblem != null) { + this.note(`${this.store.manifestProblem}, so nothing was reused`); + } + } catch (e) { + this.disabled = `cache unavailable (${e.message})`; + } + } + + importFSH(rawFSH: RawFSH[], config: Configuration): FSHTank { + this.source = { rawFSH, config }; + if (this.disabled != null) { + return fillTank(rawFSH, config); + } + const old = this.manifest?.parseKey === this.tool ? (this.manifest.parse ?? null) : null; + this.parseCache = new ParseCache(this.store, old); + logger.info('Importing FSH text...'); + const docs = new FSHImporter().import(rawFSH, this.parseCache); + return new FSHTank(docs, config); + } + + private source: { rawFSH: RawFSH[]; config: Configuration } = null; + + exportFHIR(tank: FSHTank, defs: FHIRDefinitions, options: any, config: Configuration): Package { + try { + if (this.disabled == null) { + try { + this.key = exportKey(this.tool, options, config, this.readConfigText(), defs); + } catch (e) { + this.exportSkipped = e.message; + } + } + if (this.disabled != null || this.exportSkipped != null) { + return exportFHIR(tank, defs); + } + return this.exportWithSessions(tank, defs); + } catch (e) { + // The export fails as it would without the cache, but still say what happened, and do not + // leave records that may be what made it fail + this.failed = true; + this.logSummary(); + this.finish(); + throw e; + } + } + + private exportWithSessions(tank: FSHTank, defs: FHIRDefinitions): Package { + let old: ExportState = null; + if (this.manifest != null && this.manifest.globalKey !== this.key) { + this.note( + 'exports were not reused, as the options, configuration, dependencies or SUSHI changed' + ); + } else if (this.manifest != null && this.manifest.export == null) { + this.note('exports were not reused, as the previous build could not save them'); + } else if (this.manifest != null) { + old = this.manifest.export; + } + let snapshot: string = null; + if (old != null) { + // Replaying can be abandoned partway through, and the export changes the definitions in the + // tank, so keep a copy of them to start over from + try { + snapshot = JSON.stringify(encode(tank.docs, definitionRegistry())); + } catch (e) { + old = null; + this.note(`exports were not reused, as the definitions could not be copied (${e.message})`); + } + } + const first = new ExportSession(this.store, old); + this.first = first; + this.session = first; + // If the export is redone, nothing the first attempt logged may be kept. The session drops what + // it logged itself; this holds the rest, such as errors from applying insert rules before it + // begins. + const held = old != null ? holdLogs() : null; + let pkg: Package; + try { + pkg = this.runSession(first, () => exportFHIR(tank, defs), old != null); + } catch (e) { + held?.release(true); + throw e; + } finally { + this.usedPrevious = first.consultedOld; + } + if (pkg != null && !first.aborted) { + held?.release(true); + return pkg; + } + // Nothing the first attempt did is kept: not its records, nor what it logged + held?.release(false); + first.dispose(false); + this.abandoned = first.stats; + const why = first.abortReason ?? 'of an unknown problem'; + let copy: any[]; + try { + copy = this.restoreSnapshot(snapshot); + } catch (e) { + // This should never happen, so do whatever a build without the cache would do, without + // depending on anything the first attempt used + first.errors.push(`while copying the definitions: ${e?.stack ?? e}`); + this.note( + `exported everything without the cache, because ${why}, and the definitions could not be copied (${e.message})` + ); + this.session = null; + this.fellBack = true; + this.redone = true; + return this.exportWithoutCache(defs); + } + this.note(`exported everything again, because ${why}`); + // Start over from the original definitions, and export everything without replaying + this.redone = true; + const fresh = new FSHTank(copy, tank.config); + const second = new ExportSession(this.store, null); + this.session = second; + return this.runSession(second, () => exportFHIR(fresh, defs), false); + } + + private restoreSnapshot(snapshot: string): any[] { + return decode(JSON.parse(snapshot), definitionRegistry()); + } + + /** Imports the FSH again, without the parse cache, and exports it as a normal build would. */ + private exportWithoutCache(defs: FHIRDefinitions): Package { + try { + // what importing logs was already logged, when the FSH was first imported + const tank = captureLogs(() => fillTank(this.source.rawFSH, this.source.config), true).result; + return exportFHIR(tank, defs); + } catch (e) { + // this is the error a build without the cache shows; the first attempt's is kept for + // debugging, with its stack + this.first?.errors.push(`while exporting without the cache: ${e?.stack ?? e}`); + throw e; + } + } + + private abandoned: ExportStats = null; + private fellBack = false; + private first: ExportSession = null; + // Whether the previous build's records were used (so they are not kept if this build fails) + private usedPrevious = false; + // Why exports could not be reused at all, although imports could + private exportSkipped: string = null; + private failed = false; + + /** Something the summary should explain */ + private note(text: string) { + this.notes.push(text); + } + + /** + * Runs an export with the session active. If the export throws, a session that may have + * replayed something is abandoned (returning null), so the export can be redone; otherwise its + * output is kept, and the error is passed on as it would be without a session. + */ + private runSession(session: ExportSession, run: () => Package, canRedo: boolean): Package { + incrementalHooks.session = session; + try { + return run(); + } catch (e) { + const failed = `the export failed: ${e?.message}`; + session.abortReason = + session.abortReason != null ? `${session.abortReason}, then ${failed}` : failed; + session.errors.push(`export: ${e?.stack ?? e}`); + // Nothing was replayed if replaying was turned off, so the error is that of a normal build + const redo = canRedo && session.mayReplay; + session.dispose(!redo); + incrementalHooks.session = null; + if (redo) { + return null; + } + throw e; + } finally { + if (session.aborted && incrementalHooks.session === session) { + incrementalHooks.session = null; + } + } + } + + /** Logs how much of the export was reused. */ + logSummary() { + if (this.disabled != null) { + logger.info(`Incremental build: not used, ${this.disabled}.`); + return; + } + const parse = this.parseCache; + const files = `${parse.hits} of ${parse.hits + parse.misses} files`; + const failed = this.failed ? ', before the export failed' : ''; + const session = this.session; + const notes = [...(this.first?.notes ?? []), ...this.notes]; + if (session == null && this.fellBack) { + logger.info( + `Incremental build: imported all ${parse.hits + parse.misses} files again, and reused no exports (cached results did not apply; exported everything without the cache)${failed}.` + ); + } else if (session == null) { + const why = + this.exportSkipped != null + ? `, as the build could not be identified (${this.exportSkipped})` + : ''; + logger.info(`Incremental build: reused ${files}, but no exports${why}${failed}.`); + } else { + const stats = session.stats; + const redo = this.redone ? ' (cached results did not apply; exported everything)' : ''; + logger.info( + `Incremental build: reused ${files}, ${stats.replayed} of ${stats.exported} exports${redo}${failed}.` + ); + if (!session.saveable) { + notes.push( + `this build's exports cannot be reused (${session.abortReason ?? 'unknown reason'})` + ); + } else if (session.unstable) { + notes.push('the next build will not reuse exports, as a definition changed unexpectedly'); + } + } + if (this.store.corruptPayloads > 0) { + notes.push(`removed ${this.store.corruptPayloads} corrupt file(s) from the cache`); + } + if (this.store.readFailures > 0) { + notes.push( + `could not use ${this.store.readFailures} cached result(s) (first: ${this.store.readError})` + ); + } + if (this.store.writeError != null) { + notes.push(`could not write to the cache (${this.store.writeError})`); + } + // Cache problems are reported as information, so the error and warning counts stay those of + // a normal build + notes.forEach(text => logger.info(`Incremental build: ${text}.`)); + this.logErrors(); + } + + private logErrors() { + const sessions = this.first === this.session ? [this.session] : [this.first, this.session]; + [...this.parseCache.errors, ...sessions.flatMap(session => session?.errors ?? [])].forEach( + error => logger.debug(`Incremental build: unexpected error ${error}`) + ); + this.parseCache.skippedFiles.forEach(text => logger.debug(`Incremental build: ${text}.`)); + } + + /** Saves what this build recorded, for the next build. Must be called after the output is written. */ + finish() { + incrementalHooks.session = null; + if (this.disabled != null) { + return; + } + const session = this.session; + try { + let exportState = session?.saveable ? session.getState() : null; + let globalKey = this.key ?? ''; + if (this.exportSkipped != null) { + // Nothing is known about the exports, so keep what the previous build recorded; the next + // build checks whether it applies, as always + globalKey = this.manifest?.globalKey ?? ''; + exportState = this.manifest?.export ?? null; + } else if ( + exportState == null && + !this.usedPrevious && + this.manifest?.globalKey === this.key + ) { + // Keep what the previous build recorded, if this build did not even try to use it (when it + // did, it may be what made this build fail); it is checked before it is used, like any + // record + exportState = this.manifest.export ?? null; + } + const manifest: Manifest = { + format: CACHE_FORMAT, + globalKey, + parseKey: this.tool, + export: exportState, + parse: this.parseCache.entries + }; + this.store.writeManifest(manifest); + const referenced = new Set(); + Object.values(this.parseCache.entries).forEach(entry => referenced.add(entry.ref)); + for (const rec of Object.values(exportState?.records ?? {})) { + if (rec.payloadRef) { + referenced.add(rec.payloadRef); + } + if (rec.afterRef) { + referenced.add(rec.afterRef); + } + } + this.store.collectGarbage(referenced); + if (this.store.cleanupError != null) { + logger.info( + `Incremental build: could not remove some files from the cache (${this.store.cleanupError}).` + ); + } + } catch (e) { + // The cache is only an optimization; the next build will just do more work + logger.info(`Incremental build: could not save the cache (${e.message}).`); + } + if (process.env.SUSHI_INCREMENTAL_DEBUG) { + try { + fs.writeFileSync( + path.join(this.store.dir, 'last-run.json'), + JSON.stringify( + { + ...session?.stats, + redone: this.redone, + fellBack: this.fellBack, + failed: this.failed, + abandoned: this.abandoned + }, + null, + 2 + ) + ); + } catch (e) { + logger.info(`Incremental build: could not write the debugging summary (${e.message}).`); + } + } + } + + private readConfigText(): string { + for (const name of ['sushi-config.yaml', 'sushi-config.yml']) { + const file = path.join(this.projectDir, name); + if (fs.existsSync(file)) { + return `${name}\n${fs.readFileSync(file, 'utf8')}`; + } + } + return ''; + } +} diff --git a/src/incremental/ParseCache.ts b/src/incremental/ParseCache.ts new file mode 100644 index 000000000..a9f8846a4 --- /dev/null +++ b/src/incremental/ParseCache.ts @@ -0,0 +1,116 @@ +import { FSHDocument, ImportCache, CachedImport } from '../import'; +import { captureLogs, emitLogInfo } from './logCapture'; +import { decode, encode, hashString, hashValue } from './serialize'; +import { definitionRegistry } from './registries'; +import { PayloadStore } from './CacheStore'; + +export type ParseState = Record; + +/** + * The cache of imported FSH files. Each file's entry is found by its path and the hash of its + * content, and holds what importing it produced (see FSHImporter.importWithCache). + */ +export class ParseCache implements ImportCache { + readonly entries: ParseState = {}; + /** The number of files whose cached import was reused */ + hits = 0; + /** The number of files that were imported again */ + get misses(): number { + return this.looked - this.hits; + } + private looked = 0; + + constructor( + private readonly payloads: PayloadStore, + private readonly old: ParseState | null + ) {} + + lookup(file: string, content: string): CachedImport | null { + this.looked++; + const old = this.old?.[file]; + if (old == null || old.hash !== hashString(content)) { + return null; + } + try { + const entry = this.payloads.getPayload(old.ref); + if ( + !Array.isArray(entry?.parseLogs) || + !Array.isArray(entry.items) || + !Array.isArray(entry.dependencies) || + !Array.isArray(entry.visitLogs) || + entry.doc == null + ) { + this.failed(`reading the cached import of ${file}`, new Error('unexpected content')); + return null; + } + return entry; + } catch (e) { + this.failed(`reading the cached import of ${file}`, e); + return null; + } + } + + /** Unexpected errors, with their stacks, for debugging */ + readonly errors: string[] = []; + /** Why some files were not cached, for debugging */ + readonly skippedFiles: string[] = []; + + skipped(file: string, why: string) { + this.skippedFiles.push(`did not cache the import of ${file}, as ${why}`); + } + + /** Keeps an unexpected error, and counts it as a failure to read or write the cache. */ + failed(during: string, e: any, writing = false) { + this.errors.push(`while ${during}: ${e?.stack ?? e}`); + if (writing) { + this.payloads.writeFailed(e); + } else { + this.payloads.readFailed(e); + } + } + + keep(file: string): void { + this.hits++; + this.entries[file] = this.old[file]; + } + + store(file: string, content: string, entry: CachedImport): void { + try { + const ref = this.payloads.putPayload(JSON.stringify(entry)); + this.entries[file] = { hash: hashString(content), ref }; + } catch (e) { + // not cached; the file will just be imported again next time + this.failed(`storing the import of ${file}`, e, true); + } + } + + capture(fn: () => T, mute: boolean): { result: T; logs: any[] | null } { + return captureLogs(fn, mute); + } + + emit(logs: any[]): void { + logs.forEach(emitLogInfo); + } + + hash(value: any): string { + return hashValue(value, definitionRegistry()); + } + + encodeDoc(doc: FSHDocument): any { + return encode(doc, definitionRegistry()); + } + + decodeDoc(encoded: any): FSHDocument | null { + try { + const doc = decode(encoded, definitionRegistry()); + if (!(doc instanceof FSHDocument)) { + throw new Error('the cached document is not a FSHDocument'); + } + return doc; + } catch (e) { + // the file is imported again + this.failed('decoding a cached import', e); + return null; + } + } +} diff --git a/src/incremental/cacheKey.ts b/src/incremental/cacheKey.ts new file mode 100644 index 000000000..3831b1f22 --- /dev/null +++ b/src/incremental/cacheKey.ts @@ -0,0 +1,77 @@ +import fs from 'fs'; +import path from 'path'; +import { createHash } from 'crypto'; +import { FHIRDefinitions } from '../fhirdefs'; +import { Configuration } from '../fshtypes'; +import { CACHE_FORMAT } from './CacheStore'; + +export function fileStamp(file: string): string { + const stat = fs.statSync(file); + return `${stat.size}:${stat.mtimeMs}`; +} + +function listFiles(dir: string, out: string[] = []): string[] { + for (const entry of fs.readdirSync(dir, { withFileTypes: true })) { + const full = path.join(dir, entry.name); + if (entry.isDirectory()) { + listFiles(full, out); + } else if (/\.(c|m)?(js|ts)$/.test(entry.name)) { + // compiled files, or sources when run with a TypeScript loader + out.push(full); + } + } + return out.sort(); +} + +/** + * Identifies the SUSHI build that is running: its version, the files it is made of (compiled, or + * TypeScript sources when it runs from them), and the Node.js version running it. Parsed FSH is + * reusable only by the same build. + */ +export function toolKey(sushiVersion: string): string { + const hash = createHash('sha256'); + hash.update(`${CACHE_FORMAT}\n${sushiVersion}\n${process.version}\n`); + const distDir = path.resolve(__dirname, '..'); + for (const file of listFiles(distDir)) { + hash.update(`${path.relative(distDir, file)}:${fileStamp(file)}\n`); + } + return hash.digest('base64url'); +} + +/** + * Identifies everything other than the FSH itself that the export depends on: the SUSHI build, + * the command line options, the configuration, and every loaded dependency and predefined + * resource. Exported results are reusable only when all of these are unchanged. + */ +export function exportKey( + tool: string, + options: any, + config: Configuration, + configText: string, + defs: FHIRDefinitions +): string { + const hash = createHash('sha256'); + const update = (label: string, value: string) => + hash.update(`${label}:${value.length}:${value}\n`); + update('tool', tool); + update('options', JSON.stringify(options ?? {})); + update('config', JSON.stringify(config ?? null)); + update('configText', configText ?? ''); + for (const info of defs.findPackageInfos('*')) { + update( + 'package', + JSON.stringify([info.name, info.version, info.packagePath, info.packageJSONPath]) + ); + if (info.packageJSONPath && fs.existsSync(info.packageJSONPath)) { + update('packageJSON', fileStamp(info.packageJSONPath)); + } + } + for (const info of defs.findResourceInfos('*')) { + update('resource', JSON.stringify(info)); + if (info.resourcePath && fs.existsSync(info.resourcePath)) { + update('resourceFile', fileStamp(info.resourcePath)); + } + } + update('predefined', JSON.stringify(defs.allPredefinedResources())); + return hash.digest('base64url'); +} diff --git a/src/incremental/hooks.ts b/src/incremental/hooks.ts new file mode 100644 index 000000000..e1c3dc53a --- /dev/null +++ b/src/incremental/hooks.ts @@ -0,0 +1,18 @@ +/** + * The exporters report to the active incremental build session (if any) through this object. It + * deliberately has no imports, so that the export code can depend on it without import cycles. + * When no session is active (the default, and always the case unless incremental builds were + * requested), every hook is skipped and SUSHI behaves exactly as it always has. + */ +export interface IncrementalSessionHooks { + exportEntity(kind: string, exporter: any, fshDefinition: any, live: () => any): any; + check(fn: () => void): void; + noteSdCache(exporter: any, url: string, created: boolean): void; + noteNewInstanceExporter(exporter: any): void; + beginExport(context: any): void; + enterPostExport(): void; + endExport(): void; + checkNullValues(resource: any, check: () => void): void; +} + +export const incrementalHooks: { session: IncrementalSessionHooks | null } = { session: null }; diff --git a/src/incremental/logCapture.ts b/src/incremental/logCapture.ts new file mode 100644 index 000000000..89dcff557 --- /dev/null +++ b/src/incremental/logCapture.ts @@ -0,0 +1,106 @@ +import { logger } from '../utils/FSHLogger'; + +const LEVEL = Symbol.for('level'); + +/** + * Copies a log entry as plain data, so it can be stored and written again later with the same + * result. Returns null if the entry is not plain data. + */ +export function copyLogInfo(info: any): any { + // An Error logged as the entry itself would lose its message, which is not enumerable + if ( + info == null || + Object.getPrototypeOf(info) !== Object.prototype || + typeof info.message !== 'string' || + typeof info.level !== 'string' + ) { + return null; + } + const copy: any = {}; + for (const key of Object.keys(info)) { + if (info[key] !== undefined) { + copy[key] = info[key]; + } + } + try { + return JSON.parse(JSON.stringify(copy)); + } catch { + return null; + } +} + +/** Writes a copied log entry again, through the logger's formats (counting, ignoring, printing). */ +export function emitLogInfo(copy: any): void { + logger.write({ ...copy, [LEVEL]: copy.level }); +} + +/** + * Runs fn and returns copies of the log entries it wrote, or null for logs if any entry could not + * be copied. With mute, the entries are not written at all. Entries written while the importer + * collects messages from a generated document are not seen, as the secret logger sets this aside. + */ +export function captureLogs(fn: () => T, mute: boolean): { result: T; logs: any[] | null } { + const ownWrite = Object.getOwnPropertyDescriptor(logger, 'write'); + const write = logger.write; + let logs: any[] = []; + Object.defineProperty(logger, 'write', { + value: function (info: any, ...rest: any[]) { + if (logs != null) { + const copy = copyLogInfo(info); + if (copy == null) { + logs = null; + } else { + logs.push(copy); + } + } + return mute ? true : write.call(logger, info, ...rest); + }, + configurable: true, + writable: true + }); + try { + return { result: fn(), logs }; + } finally { + if (ownWrite != null) { + Object.defineProperty(logger, 'write', ownWrite); + } else { + delete (logger as any).write; + } + } +} + +/** + * Holds back everything written to the logger until release is called, then writes it (in order) + * or drops it. Entries written while the importer collects messages from a generated document are + * not seen, as the secret logger sets this aside. + */ +export function holdLogs(): { release(write: boolean): void } { + const ownWrite = Object.getOwnPropertyDescriptor(logger, 'write'); + const write = logger.write; + const held: any[][] = []; + Object.defineProperty(logger, 'write', { + value: function (info: any, ...rest: any[]) { + held.push([info, ...rest]); + return true; + }, + configurable: true, + writable: true + }); + let released = false; + return { + release(writeHeld: boolean) { + if (released) { + return; + } + released = true; + if (ownWrite != null) { + Object.defineProperty(logger, 'write', ownWrite); + } else { + delete (logger as any).write; + } + if (writeHeld) { + held.forEach(args => write.call(logger, ...args)); + } + } + }; +} diff --git a/src/incremental/registries.ts b/src/incremental/registries.ts new file mode 100644 index 000000000..91edf2e7e --- /dev/null +++ b/src/incremental/registries.ts @@ -0,0 +1,20 @@ +import * as fshtypes from '../fshtypes'; +import * as rules from '../fshtypes/rules'; +import * as importModule from '../import'; +import * as fhirtypes from '../fhirtypes'; +import { ClassRegistry, buildClassRegistry } from './serialize'; + +let definitions: ClassRegistry; +let packageObjects: ClassRegistry; + +/** Classes that FSH definitions (and the documents that hold them) are made of. */ +export function definitionRegistry(): ClassRegistry { + definitions = definitions ?? buildClassRegistry(fshtypes, rules, importModule); + return definitions; +} + +/** Classes that exported FHIR objects (ValueSets, CodeSystems, Instances) are made of. */ +export function packageRegistry(): ClassRegistry { + packageObjects = packageObjects ?? buildClassRegistry(fshtypes, rules, importModule, fhirtypes); + return packageObjects; +} diff --git a/src/incremental/serialize.ts b/src/incremental/serialize.ts new file mode 100644 index 000000000..ede53a8c0 --- /dev/null +++ b/src/incremental/serialize.ts @@ -0,0 +1,211 @@ +import { createHash } from 'crypto'; + +/** + * A class-aware serializer for the object graphs SUSHI builds (FSH definitions, rules, FSH values). + * Unlike JSON.stringify, it keeps class identity (by constructor name, from a registry of known + * classes), Maps, Sets, undefined-valued properties, bigints, and shared or circular references. + * Anything it does not know how to represent faithfully (functions, symbols, unregistered classes) + * makes it throw, so callers can fall back to doing the work instead of caching it. + */ + +export class UnserializableError extends Error { + constructor(what: string) { + super(`Cannot serialize ${what}`); + } +} + +export type ClassRegistry = Map any>; + +/** + * Builds a registry from the exports of the given modules. Every exported class is registered by + * its name. Two different classes with the same name make the registry ambiguous, so that throws. + */ +export function buildClassRegistry(...modules: any[]): ClassRegistry { + const registry: ClassRegistry = new Map(); + for (const mod of modules) { + for (const value of Object.values(mod ?? {})) { + if (typeof value === 'function' && value.prototype != null && value.name) { + const existing = registry.get(value.name); + if (existing != null && existing !== value) { + throw new Error(`Ambiguous class name in serializer registry: ${value.name}`); + } + registry.set(value.name, value as any); + } + } + } + return registry; +} + +export function encode(value: any, registry: ClassRegistry): any { + const seen = new Map(); + const ctorNames = new Map(); + for (const [name, ctor] of registry) { + ctorNames.set(ctor.prototype, name); + } + + const encodeProps = (obj: any): any => { + const out: any = {}; + for (const key of Object.keys(obj)) { + out[key] = enc(obj[key]); + } + return out; + }; + + const enc = (v: any): any => { + if (v === null) { + return null; + } + switch (typeof v) { + case 'string': + case 'boolean': + return v; + case 'number': + if (Number.isFinite(v) && !Object.is(v, -0)) { + return v; + } + return { $n: Object.is(v, -0) ? '-0' : String(v) }; + case 'undefined': + return { $u: 1 }; + case 'bigint': + return { $b: v.toString() }; + case 'object': + break; + default: + throw new UnserializableError(typeof v); + } + if (seen.has(v)) { + return { $r: seen.get(v) }; + } + seen.set(v, seen.size); + const proto = Object.getPrototypeOf(v); + if (proto === Array.prototype) { + const arr = new Array(v.length); + for (let i = 0; i < v.length; i++) { + arr[i] = enc(v[i]); + } + return arr; + } else if (proto === Object.prototype) { + const props = encodeProps(v); + return Object.keys(props).some(k => k.startsWith('$')) ? { $o: props } : props; + } else if (proto === Map.prototype) { + const entries: any[] = []; + v.forEach((val: any, key: any) => { + const k = enc(key); + entries.push([k, enc(val)]); + }); + return { $m: entries }; + } else if (proto === Set.prototype) { + const items: any[] = []; + v.forEach((item: any) => items.push(enc(item))); + return { $s: items }; + } else if (proto === Date.prototype) { + return { $d: v.getTime() }; + } else if (proto === RegExp.prototype) { + if (Object.keys(v).length > 0) { + throw new UnserializableError('regular expression with extra properties'); + } + return { $x: [v.source, v.flags, v.lastIndex] }; + } else if (ctorNames.has(proto)) { + return { $c: ctorNames.get(proto), $v: encodeProps(v) }; + } + throw new UnserializableError(`object of class ${v?.constructor?.name ?? 'unknown'}`); + }; + + return enc(value); +} + +export function decode(encoded: any, registry: ClassRegistry): any { + const refs: any[] = []; + const decodePropsInto = (target: any, props: any) => { + for (const key of Object.keys(props)) { + target[key] = dec(props[key]); + } + return target; + }; + const dec = (e: any): any => { + if (e === null || typeof e !== 'object') { + return e; + } + if (Array.isArray(e)) { + const arr: any[] = new Array(e.length); + refs.push(arr); + for (let i = 0; i < e.length; i++) { + arr[i] = dec(e[i]); + } + return arr; + } + if ('$r' in e) { + if (e.$r >= refs.length) { + throw new Error('Invalid serialized reference'); + } + return refs[e.$r]; + } else if ('$u' in e) { + return undefined; + } else if ('$n' in e) { + return e.$n === '-0' ? -0 : Number(e.$n); + } else if ('$b' in e) { + return BigInt(e.$b); + } else if ('$m' in e) { + const map = new Map(); + refs.push(map); + for (const [k, v] of e.$m) { + const key = dec(k); + map.set(key, dec(v)); + } + return map; + } else if ('$s' in e) { + const set = new Set(); + refs.push(set); + for (const item of e.$s) { + set.add(dec(item)); + } + return set; + } else if ('$d' in e) { + const date = new Date(e.$d); + refs.push(date); + return date; + } else if ('$x' in e) { + const regex = new RegExp(e.$x[0], e.$x[1]); + regex.lastIndex = e.$x[2]; + refs.push(regex); + return regex; + } else if ('$c' in e) { + const ctor = registry.get(e.$c); + if (ctor == null) { + throw new Error(`Unknown class in serialized data: ${e.$c}`); + } + const obj = Object.create(ctor.prototype); + refs.push(obj); + return decodePropsInto(obj, e.$v); + } else if ('$o' in e) { + const obj = {}; + refs.push(obj); + return decodePropsInto(obj, e.$o); + } + const obj = {}; + refs.push(obj); + return decodePropsInto(obj, e); + }; + return dec(encoded); +} + +export function hashString(s: string): string { + return createHash('sha256').update(s).digest('base64url').slice(0, 32); +} + +export function hashValue(value: any, registry: ClassRegistry): string { + return hashString(JSON.stringify(encode(value, registry))); +} + +/** + * Replaces all of target's own enumerable properties with those of source, keeping target's + * identity (other objects may hold references to it) and the property order of source. + */ +export function replaceOwnProperties(target: any, source: any): void { + for (const key of Object.keys(target)) { + delete target[key]; + } + for (const key of Object.keys(source)) { + target[key] = source[key]; + } +} diff --git a/src/utils/FSHLogger.ts b/src/utils/FSHLogger.ts index f5ab98cbb..a6c23077f 100644 --- a/src/utils/FSHLogger.ts +++ b/src/utils/FSHLogger.ts @@ -187,6 +187,7 @@ export type LoggerData = { level: string; errorsAndWarnings: ErrorsAndWarnings; stats: LoggerStats; + write?: PropertyDescriptor; }; export const logMessage = (level: string, message: string): void => { @@ -204,11 +205,21 @@ export function switchToSecretLogger(): LoggerData { errorsAndWarnings.shouldTrack = true; const oldStats = cloneDeep(stats); stats.reset(); - return { level: oldLevel, errorsAndWarnings: oldErrorsAndWarnings, stats: oldStats }; + // Anything wrapping write (as incremental builds do to capture messages) is set aside, so it does + // not add to the stack while generated documents are parsed, which can run out of stack space + // and log a different number of errors depending on how deep the stack is + const write = Object.getOwnPropertyDescriptor(logger, 'write'); + if (write != null) { + delete (logger as any).write; + } + return { level: oldLevel, errorsAndWarnings: oldErrorsAndWarnings, stats: oldStats, write }; } export function restoreMainLogger(loggerDataToRestore: LoggerData): ErrorsAndWarnings { logger.level = loggerDataToRestore.level; + if (loggerDataToRestore.write != null) { + Object.defineProperty(logger, 'write', loggerDataToRestore.write); + } const secretErrorsAndWarnings = cloneDeep(errorsAndWarnings); errorsAndWarnings.reset(); errorsAndWarnings.errors = loggerDataToRestore.errorsAndWarnings.errors; diff --git a/src/utils/Processing.ts b/src/utils/Processing.ts index 22d448af2..56155dbba 100644 --- a/src/utils/Processing.ts +++ b/src/utils/Processing.ts @@ -35,6 +35,7 @@ import { axiosGet } from './axiosUtils'; import { ImplementationGuideDependsOn } from '../fhirtypes'; import { FHIRVersionName, getFHIRVersionInfo } from '../utils/FHIRVersionUtils'; import { InMemoryVirtualPackage, RegistryClient } from 'fhir-package-loader'; +import { incrementalHooks } from '../incremental/hooks'; export enum AutomaticDependencyPriority { Low = 'Low', // load before configured dependencies / FHIR core (lowest resolution priority) @@ -672,7 +673,13 @@ export function writeFHIRResources( predef.id === resource.id ) ) { - checkNullValuesOnArray(resource); + if (incrementalHooks.session != null) { + incrementalHooks.session.checkNullValues(resource, () => + checkNullValuesOnArray(resource) + ); + } else { + checkNullValuesOnArray(resource); + } fs.outputJSONSync(path.join(exportDir, resource.getFileName()), resource.toJSON(snapshot), { spaces: 2 }); diff --git a/test/export/Package.test.ts b/test/export/Package.test.ts index ea91a17dd..19bb14645 100644 --- a/test/export/Package.test.ts +++ b/test/export/Package.test.ts @@ -267,6 +267,47 @@ describe('Package', () => { pkg.instances.push(instance7); }); + describe('#findAllMatches()', () => { + it('should find every match, of every type, in the order fish considers them', () => { + const matches = pkg.findAllMatches('Cheeses'); + expect(matches.map(m => m.resourceType)).toEqual(['ValueSet', 'CodeSystem']); + expect(pkg.findAllMatches('Cheeses', Type.CodeSystem)).toEqual([matches[1]]); + expect(pkg.findAllMatches('Nothing-Matches')).toEqual([]); + }); + + it('should agree with fish and fishAll', () => { + const items = [ + 'fun-ny', + 'Funny', + 'Cheeses', + 'DrSue', + 'Zone', + 'http://hl7.org/fhir/us/minimal/StructureDefinition/zone', + 'Spices', + 'WheatBeer', + 'Destination|1.0.0', + 'PoorTaste' + ]; + const typeLists = [ + [], + [Type.Profile], + [Type.Resource, Type.Logical], + [Type.Instance, Type.ValueSet, Type.CodeSystem], + [Type.Extension, Type.Type] + ]; + for (const item of items) { + for (const types of typeLists) { + const all = pkg.findAllMatches(item, ...types); + expect(pkg.fish(item, ...types)).toBe(all[0]); + if (types.length > 0) { + const perType = types.flatMap(type => pkg.findAllMatches(item, type).slice(0, 1)); + expect(pkg.fishAll(item, ...types)).toEqual(perType); + } + } + } + }); + }); + describe('#fishForFHIR()', () => { it('should find profiles', () => { const funnyProfile = pkg.fishForFHIR('fun-ny', Type.Profile); diff --git a/test/incremental/CacheStore.test.ts b/test/incremental/CacheStore.test.ts new file mode 100644 index 000000000..e59bf0ef2 --- /dev/null +++ b/test/incremental/CacheStore.test.ts @@ -0,0 +1,199 @@ +import fs from 'fs'; +import path from 'path'; +import zlib from 'zlib'; +import temp from 'temp'; +import { CACHE_FORMAT, CacheStore } from '../../src/incremental/CacheStore'; + +describe('CacheStore', () => { + let dir: string; + let store: CacheStore; + + beforeAll(() => { + temp.track(); + }); + + beforeEach(() => { + dir = path.join(temp.mkdirSync('sushi-test'), 'cache'); + store = new CacheStore(dir); + store.open(); + }); + + afterAll(() => { + temp.cleanupSync(); + }); + + it('should create the cache directory, ignored by git', () => { + expect(fs.readFileSync(path.join(dir, '.gitignore'), 'utf8')).toMatch(/^\*$/m); + }); + + it('should store and read back payloads by their hash', () => { + const ref = store.putPayload('{"a":1}'); + expect(store.putPayload('{"a":1}')).toBe(ref); + expect(store.getPayload(ref)).toEqual({ a: 1 }); + // a new store sees the payloads that are already on disk + const other = new CacheStore(dir); + other.open(); + expect(other.getPayload(ref)).toEqual({ a: 1 }); + }); + + it('should refuse a payload whose content does not match its hash', () => { + const ref = store.putPayload('{"a":1}'); + fs.writeFileSync(path.join(dir, 'p', `${ref}.json.gz`), zlib.gzipSync('{"a":2}')); + expect(() => store.getPayload(ref)).toThrow(/Corrupt/); + // the corrupt file is removed, and written again when the payload is stored + expect(fs.existsSync(path.join(dir, 'p', `${ref}.json.gz`))).toBe(false); + expect(store.putPayload('{"a":1}')).toBe(ref); + expect(store.getPayload(ref)).toEqual({ a: 1 }); + }); + + it('should refuse a payload that is not gzipped or missing', () => { + const ref = store.putPayload('{"a":1}'); + fs.writeFileSync(path.join(dir, 'p', `${ref}.json.gz`), '{"a":1}'); + expect(() => store.getPayload(ref)).toThrow(); + expect(() => store.getPayload('nothere')).toThrow(); + expect(() => store.getPayload('../manifest')).toThrow(/Invalid/); + }); + + it('should read back the manifest it wrote', () => { + expect(store.readManifest()).toBeNull(); + const manifest = { format: CACHE_FORMAT, globalKey: 'g', parseKey: 'p', parse: { x: 1 } }; + store.writeManifest(manifest); + expect(store.readManifest()).toEqual(manifest); + }); + + it('should ignore a manifest of another format, or one that cannot be read', () => { + store.writeManifest({ format: CACHE_FORMAT + 1, globalKey: 'g', parseKey: 'p' }); + expect(store.readManifest()).toBeNull(); + expect(store.manifestProblem).toMatch(/different version/); + fs.writeFileSync(path.join(dir, 'manifest.json.gz'), zlib.gzipSync('{not json')); + expect(store.readManifest()).toBeNull(); + expect(store.manifestProblem).toMatch(/could not be read/); + fs.writeFileSync(path.join(dir, 'manifest.json.gz'), 'garbage'); + expect(store.readManifest()).toBeNull(); + }); + + it('should delete only the payloads that are not referenced', () => { + const keep = store.putPayload('"keep"'); + const drop = store.putPayload('"drop"'); + const old = new Date(Date.now() - 2 * 24 * 60 * 60 * 1000); + fs.utimesSync(path.join(dir, 'p', `${drop}.json.gz`), old, old); + fs.writeFileSync(path.join(dir, 'p', 'leftover.tmp'), ''); + fs.utimesSync(path.join(dir, 'p', 'leftover.tmp'), old, old); + store.collectGarbage(new Set([keep])); + expect(fs.readdirSync(path.join(dir, 'p'))).toEqual([`${keep}.json.gz`]); + // a payload that was collected is written again when needed + expect(store.putPayload('"drop"')).toBe(drop); + expect(store.getPayload(drop)).toBe('drop'); + }); + + it('should keep files that another build may be using', () => { + const hours = (n: number) => new Date(Date.now() - n * 60 * 60 * 1000); + fs.writeFileSync(path.join(dir, 'p', 'unused.json.gz'), zlib.gzipSync('"unused"')); + fs.utimesSync(path.join(dir, 'p', 'unused.json.gz'), hours(2), hours(2)); + // used by another build half an hour ago + fs.writeFileSync(path.join(dir, 'p', 'recent.json.gz'), zlib.gzipSync('"recent"')); + fs.utimesSync(path.join(dir, 'p', 'recent.json.gz'), hours(0.5), hours(0.5)); + const later = new CacheStore(dir); + later.open(); + // written after this build started, by another build + fs.writeFileSync(path.join(dir, 'p', 'other.json.gz'), zlib.gzipSync('"other"')); + fs.writeFileSync(path.join(dir, 'p', 'x.json.gz.123.abc.tmp'), ''); + later.collectGarbage(new Set()); + expect(fs.readdirSync(path.join(dir, 'p')).sort()).toEqual([ + 'other.json.gz', + 'recent.json.gz', + 'x.json.gz.123.abc.tmp' + ]); + }); + + it('should mark the payloads it uses as recently used', () => { + const ref = store.putPayload('"used"'); + const file = path.join(dir, 'p', `${ref}.json.gz`); + const old = new Date(Date.now() - 2 * 60 * 60 * 1000); + fs.utimesSync(file, old, old); + store.getPayload(ref); + expect(fs.statSync(file).mtimeMs).toBeGreaterThan(Date.now() - 60 * 1000); + }); + + it('should only remove payloads whose content is corrupt', () => { + const ref = store.putPayload('{"a":1}'); + const file = path.join(dir, 'p', `${ref}.json.gz`); + // a file that cannot be read is not known to be corrupt + fs.unlinkSync(file); + fs.mkdirSync(file); + expect(() => store.getPayload(ref)).toThrow(); + expect(fs.existsSync(file)).toBe(true); + expect(store.corruptPayloads).toBe(0); + fs.rmdirSync(file); + fs.writeFileSync(file, zlib.gzipSync('{"a":')); + expect(() => store.getPayload(ref)).toThrow(); + expect(fs.existsSync(file)).toBe(false); + expect(store.corruptPayloads).toBe(1); + }); + + it('should write a payload again when it went missing during the build', () => { + const ref = store.putPayload('{"a":1}'); + const file = path.join(dir, 'p', `${ref}.json.gz`); + fs.unlinkSync(file); + expect(store.putPayload('{"a":1}')).toBe(ref); + expect(fs.existsSync(file)).toBe(true); + fs.unlinkSync(file); + expect(() => store.getPayload(ref)).toThrow(); + expect(store.putPayload('{"a":1}')).toBe(ref); + expect(store.getPayload(ref)).toEqual({ a: 1 }); + }); + + it('should count only the corrupt payloads it could remove', () => { + const ref = store.putPayload('{"a":1}'); + const file = path.join(dir, 'p', `${ref}.json.gz`); + fs.writeFileSync(file, zlib.gzipSync('{"a":')); + const spy = jest.spyOn(fs, 'unlinkSync').mockImplementation(() => { + throw Object.assign(new Error('not allowed'), { code: 'EPERM' }); + }); + try { + expect(() => store.getPayload(ref)).toThrow(); + } finally { + spy.mockRestore(); + } + expect(store.corruptPayloads).toBe(0); + expect(store.cleanupError).toBe('not allowed'); + }); + + it('should note a cache directory it cannot list', () => { + fs.rmSync(path.join(dir, 'p'), { recursive: true }); + fs.writeFileSync(path.join(dir, 'p'), ''); + store.collectGarbage(new Set()); + expect(store.cleanupError).toMatch(/ENOTDIR/); + }); + + it('should note unexpected failures to clean up', () => { + const old = new Date(Date.now() - 2 * 24 * 60 * 60 * 1000); + // a file that is already gone is not a failure + const gone = store.putPayload('"gone"'); + fs.unlinkSync(path.join(dir, 'p', `${gone}.json.gz`)); + store.collectGarbage(new Set()); + expect(store.cleanupError).toBeNull(); + // but one that cannot be removed is + const stuck = path.join(dir, 'p', 'stuck.json.gz'); + fs.mkdirSync(stuck); + fs.utimesSync(stuck, old, old); + store.collectGarbage(new Set()); + expect(store.cleanupError).not.toBeNull(); + }); + + it('should note payloads it cannot write', () => { + fs.rmSync(path.join(dir, 'p'), { recursive: true }); + fs.writeFileSync(path.join(dir, 'p'), ''); + expect(() => store.putPayload('{"a":1}')).toThrow(/ENOTDIR|ENOENT/); + expect(store.writeError).toMatch(/ENOTDIR|ENOENT/); + }); + + it('should note a manifest it cannot write, leaving no temporary file', () => { + fs.mkdirSync(path.join(dir, 'manifest.json.gz')); + expect(() => + store.writeManifest({ format: CACHE_FORMAT, globalKey: 'g', parseKey: 'p', parse: {} }) + ).toThrow(); + expect(store.writeError).not.toBeNull(); + expect(fs.readdirSync(dir).filter(f => f.endsWith('.tmp'))).toEqual([]); + }); +}); diff --git a/test/incremental/ExportSession.test.ts b/test/incremental/ExportSession.test.ts new file mode 100644 index 000000000..aae01b9c1 --- /dev/null +++ b/test/incremental/ExportSession.test.ts @@ -0,0 +1,636 @@ +import { CodeSystemExporter, exportFHIR, InstanceExporter, Package } from '../../src/export'; +import { StructureDefinition } from '../../src/fhirtypes'; +import { FSHTank, RawFSH, importText } from '../../src/import'; +import { FHIRDefinitions } from '../../src/fhirdefs'; +import { ExportSession, ExportState } from '../../src/incremental/ExportSession'; +import { PayloadStore } from '../../src/incremental/CacheStore'; +import { incrementalHooks } from '../../src/incremental/hooks'; +import { captureLogs } from '../../src/incremental/logCapture'; +import { logger } from '../../src/utils/FSHLogger'; +import { hashString } from '../../src/incremental/serialize'; +import { getTestFHIRDefinitions, loggerSpy, testDefsPath } from '../testhelpers'; +import { minimalConfig } from '../utils/minimalConfig'; + +class MemoryStore implements PayloadStore { + readonly payloads = new Map(); + failReads = false; + readFailures = 0; + writeFailures = 0; + + readFailed(): void { + this.readFailures++; + } + + writeFailed(): void { + this.writeFailures++; + } + + putPayload(json: string): string { + const ref = hashString(json); + this.payloads.set(ref, json); + return ref; + } + + getPayload(ref: string): any { + if (this.failReads || !this.payloads.has(ref)) { + throw new Error('missing payload'); + } + return JSON.parse(this.payloads.get(ref)); + } +} + +const FILES: Record = { + 'aliases.fsh': ` +Alias: $sct = http://snomed.info/sct +Alias: $loinc = http://loinc.org +`, + 'rulesets.fsh': ` +RuleSet: Common +* ^status = #active +* ^publisher = "Example Publisher" + +RuleSet: Flag(path) +* {path} MS +`, + 'profiles.fsh': ` +Profile: MyPatient +Parent: Patient +* insert Common +* insert Flag(name) +* name 1..* +* gender = #female + +Profile: MyObservation +Parent: Observation +* insert Common +* subject only Reference(MyPatient) +* code from MyVS (required) +* code ^short = "The code" + +Profile: MyChildPatient +Parent: MyPatient +* birthDate 1..1 + +Extension: MyExtension +* value[x] only string +`, + 'terminology.fsh': ` +ValueSet: MyVS +* include codes from system MyCS +* $sct#123 "Something" + +CodeSystem: MyCS +* #a "A" +* #b "B" +`, + 'instances.fsh': ` +Instance: Pat +InstanceOf: MyPatient +* name.family = "Smith" +* gender = #female + +Instance: Obs +InstanceOf: MyObservation +* status = #final +* code = MyCS#a +* subject = Reference(Pat) +* contained[0] = InlinePat + +Instance: InlinePat +InstanceOf: Patient +Usage: #inline +* name.family = "Inline" + +Instance: Child +InstanceOf: MyChildPatient +* name.family = "Child" +* birthDate = "2020-01-01" + +Instance: Bad +InstanceOf: Patient +* notAnElement = "value" +` +}; + +describe('ExportSession', () => { + let defs: FHIRDefinitions; + + beforeAll(async () => { + defs = await getTestFHIRDefinitions(true, testDefsPath('r4-definitions')); + }); + + beforeEach(() => { + loggerSpy.reset(); + }); + + afterEach(() => { + incrementalHooks.session = null; + }); + + function output(pkg: Package) { + return JSON.stringify({ + profiles: pkg.profiles.map(sd => sd.toJSON(true)), + differentials: pkg.profiles.map(sd => sd.toJSON(false)), + extensions: pkg.extensions.map(sd => sd.toJSON(true)), + valueSets: pkg.valueSets.map(vs => vs.toJSON()), + codeSystems: pkg.codeSystems.map(cs => cs.toJSON()), + instances: pkg.instances.map(i => i.toJSON()), + fileNames: [...pkg.profiles, ...pkg.extensions, ...pkg.valueSets, ...pkg.codeSystems].map(r => + r.getFileName() + ), + fshMap: [...pkg.fshMap.entries()] + }); + } + + function logs() { + // debug logs carry stack traces, which naturally differ between call paths + return loggerSpy + .getAllLogs() + .filter(l => l.level !== 'debug') + .map(l => [l.level, l.message, l.file, l.location]); + } + + function run(files: Record, session?: ExportSession) { + loggerSpy.reset(); + const docs = importText(Object.entries(files).map(([path, text]) => new RawFSH(text, path))); + const tank = new FSHTank(docs, minimalConfig); + loggerSpy.reset(); + incrementalHooks.session = session ?? null; + try { + const pkg = exportFHIR(tank, defs); + return { out: output(pkg), logs: logs() }; + } finally { + incrementalHooks.session = null; + } + } + + function record(files: Record, store: MemoryStore): ExportState { + const session = new ExportSession(store, null); + run(files, session); + expect(session.aborted).toBe(false); + return session.getState(); + } + + it('should export exactly as without a session when recording', () => { + const plain = run(FILES); + const session = new ExportSession(new MemoryStore(), null); + const recorded = run(FILES, session); + expect(recorded).toEqual(plain); + expect(session.stats.replayed).toBe(0); + expect(session.stats.exported).toBeGreaterThan(5); + // the bad instance produces an error, which must be kept + expect(plain.logs.some(l => l[0] === 'error')).toBe(true); + }); + + it('should replay everything when nothing changed, with the same output and logs', () => { + const store = new MemoryStore(); + const state = record(FILES, store); + const plain = run(FILES); + const session = new ExportSession(store, state); + const replayed = run(FILES, session); + expect(session.aborted).toBe(false); + expect(replayed).toEqual(plain); + // everything except the instance that failed with an error can be reused + expect(session.stats.replayed).toBeGreaterThan(0); + expect(session.stats.replayed).toBe(Object.values(state.records).filter(rec => rec.ok).length); + }); + + it('should re-export a changed profile and what depends on it', () => { + const store = new MemoryStore(); + const state = record(FILES, store); + const changed = { + ...FILES, + 'profiles.fsh': FILES['profiles.fsh'].replace('* name 1..*', '* name 2..*') + }; + const plain = run(changed); + const session = new ExportSession(store, state); + const result = run(changed, session); + expect(session.aborted).toBe(false); + expect(result).toEqual(plain); + expect(session.stats.reasons.changed).toBeGreaterThan(0); + // the CodeSystem does not depend on the profile, so it is reused + expect(session.stats.replayed).toBeGreaterThan(0); + }); + + it('should re-export what uses a changed RuleSet', () => { + const store = new MemoryStore(); + const state = record(FILES, store); + const changed = { + ...FILES, + 'rulesets.fsh': FILES['rulesets.fsh'].replace('Example Publisher', 'Other Publisher') + }; + const plain = run(changed); + const session = new ExportSession(store, state); + expect(run(changed, session)).toEqual(plain); + expect(session.aborted).toBe(false); + }); + + it('should re-export what uses a changed alias', () => { + const store = new MemoryStore(); + const state = record(FILES, store); + const changed = { + ...FILES, + 'aliases.fsh': FILES['aliases.fsh'].replace( + 'http://snomed.info/sct', + 'http://example.org/sct' + ) + }; + const plain = run(changed); + const session = new ExportSession(store, state); + expect(run(changed, session)).toEqual(plain); + expect(session.aborted).toBe(false); + }); + + it('should handle added, removed, and renamed entities', () => { + const store = new MemoryStore(); + let state = record(FILES, store); + const steps = [ + { + ...FILES, + 'added.fsh': 'Instance: Added\nInstanceOf: MyPatient\n* name.family = "Added"\n' + }, + { + ...FILES, + 'instances.fsh': FILES['instances.fsh'].replace(/Instance: Child[^]*?(?=Instance: Bad)/, '') + }, + { + ...FILES, + 'profiles.fsh': FILES['profiles.fsh'].replace(/MyChildPatient/g, 'RenamedChild'), + 'instances.fsh': FILES['instances.fsh'].replace(/MyChildPatient/g, 'RenamedChild') + } + ]; + for (const files of steps) { + const plain = run(files); + const session = new ExportSession(store, state); + expect(run(files, session)).toEqual(plain); + expect(session.aborted).toBe(false); + state = session.getState(); + } + }); + + it('should reproduce errors when a syntax error is introduced and fixed', () => { + const store = new MemoryStore(); + let state = record(FILES, store); + const broken = { + ...FILES, + 'profiles.fsh': FILES['profiles.fsh'].replace('* name 1..*', '* = = BROKEN') + }; + for (const files of [broken, FILES]) { + const plain = run(files); + const session = new ExportSession(store, state); + expect(run(files, session)).toEqual(plain); + state = session.getState(); + } + }); + + it('should export instances of a profile whose cached definition another instance changed', () => { + const files: Record = { + ...FILES, + 'more.fsh': ` +Instance: Pat2 +InstanceOf: MyPatient +* name.family = "Ann" + +Instance: Pat3 +InstanceOf: MyPatient +* name.family = "Third" +* gender = #male +` + }; + const store = new MemoryStore(); + let state = record(files, store); + const edits = [ + { ...files, 'instances.fsh': files['instances.fsh'].replace('"Smith"', '"Jones"') }, + { ...files, 'more.fsh': files['more.fsh'].replace('"Third"', '"3rd"') }, + files + ]; + for (const edited of edits) { + const plain = run(edited); + const session = new ExportSession(store, state); + expect(run(edited, session)).toEqual(plain); + expect(session.aborted).toBe(false); + expect(session.stats.replayed).toBeGreaterThan(0); + state = session.getState(); + } + }); + + it('should export normally when a cached result cannot be read', () => { + const store = new MemoryStore(); + const state = record(FILES, store); + store.failReads = true; + const plain = run(FILES); + const session = new ExportSession(store, state); + expect(run(FILES, session)).toEqual(plain); + expect(session.stats.replayed).toBe(0); + expect(session.stats.reasons['cache read failed']).toBeGreaterThan(0); + }); + + it('should not replay anything from a state marked unstable', () => { + const store = new MemoryStore(); + const state = record(FILES, store); + const session = new ExportSession(store, { ...state, unstable: true }); + expect(run(FILES, session)).toEqual(run(FILES)); + expect(session.stats.replayed).toBe(0); + }); + + it('should not replay entities that were recorded as not reusable', () => { + const store = new MemoryStore(); + const state = record(FILES, store); + for (const rec of Object.values(state.records)) { + rec.ok = false; + rec.why = 'test'; + } + const session = new ExportSession(store, state); + expect(run(FILES, session)).toEqual(run(FILES)); + expect(session.stats.replayed).toBe(0); + expect(session.stats.reasons['not reusable: test']).toBeGreaterThan(0); + }); + + it('should abort and discard its logs when a replay turns out to be wrong', () => { + const store = new MemoryStore(); + const state = record(FILES, store); + // Pretend the profile read a different set of package entries when it was recorded + const rec = state.records['Profile:MyChildPatient']; + rec.script = rec.script.map(ev => + ev[0] === 'R' ? ['R', ev[1], ev[2], [...ev[3], 'Profile:Nope']] : ev + ) as any; + const session = new ExportSession(store, state); + run(FILES, session); + // MyChildPatient is exported (live) because the planned check fails before replaying + expect(session.stats.reasons['package lookup differs']).toBeGreaterThan(0); + }); + + it('should replay nested exports of profiles and of instances assigned in caret rules', () => { + const files = { + ...FILES, + 'nested.fsh': ` +Profile: EarlyChild +Parent: LateParent + +CodeSystem: ContactCS +* ^contact[0] = Contact +* #x "X" + +Profile: LateParent +Parent: Patient +* gender 1..1 + +Instance: Contact +InstanceOf: ContactDetail +Usage: #inline +* name = "Someone" +* telecom[0] = Phone + +Instance: Phone +InstanceOf: ContactPoint +Usage: #inline +* system = #phone +* value = "555" +` + }; + const store = new MemoryStore(); + const state = record(files, store); + const refs = Object.values(state.records).flatMap(rec => + rec.script.filter(ev => ev[0] === 'T').map(ev => ev[2]) + ); + expect(refs).toEqual(expect.arrayContaining(['top', 'same', 'new#0'])); + const plain = run(files); + const session = new ExportSession(store, state); + expect(run(files, session)).toEqual(plain); + expect(session.aborted).toBe(false); + expect(session.stats.replayed).toBeGreaterThan(5); + }); + + function exportWith(files: Record, session: ExportSession): Package { + const docs = importText(Object.entries(files).map(([path, text]) => new RawFSH(text, path))); + incrementalHooks.session = session; + try { + return exportFHIR(new FSHTank(docs, minimalConfig), defs); + } finally { + incrementalHooks.session = null; + } + } + + it('should replay the messages from checking the null values of a replayed profile', () => { + const store = new MemoryStore(); + const recorder = new ExportSession(store, null); + const recorded = exportWith(FILES, recorder); + loggerSpy.reset(); + const profile = recorded.profiles.find(sd => sd.name === 'MyPatient'); + // also when the logger is already captured, as it is restored afterwards + captureLogs( + () => recorder.checkNullValues(profile, () => logger.warn('null in profile')), + false + ); + recorder.checkNullValues(recorded.instances[0], () => logger.warn('null in instance')); + expect(loggerSpy.getAllMessages('warn')).toEqual(['null in profile', 'null in instance']); + + const replayer = new ExportSession(store, recorder.getState()); + const replayed = exportWith(FILES, replayer); + expect(replayer.stats.replayed).toBeGreaterThan(0); + loggerSpy.reset(); + const standIn = replayed.profiles.find(sd => sd.name === 'MyPatient'); + replayer.checkNullValues(standIn, () => logger.warn('checked again')); + expect(loggerSpy.getAllMessages('warn')).toEqual(['null in profile']); + }); + + it('should not reuse a profile whose null value check logs something it cannot record', () => { + const store = new MemoryStore(); + const recorder = new ExportSession(store, null); + const recorded = exportWith(FILES, recorder); + const profile = recorded.profiles.find(sd => sd.name === 'MyPatient'); + recorder.checkNullValues(profile, () => logger.warn(new Error('not plain data') as any)); + expect(recorder.getState().records['Profile:MyPatient'].ok).toBe(false); + }); + + describe('when something changes outside its export', () => { + let spy: jest.SpyInstance = null; + + afterEach(() => { + spy?.mockRestore(); + spy = null; + }); + + function changeAfterInstances(change: (exporter: any) => void) { + const original = InstanceExporter.prototype.export; + spy = jest.spyOn(InstanceExporter.prototype, 'export').mockImplementation(function () { + const result = original.call(this); + change(this); + return result; + }); + } + + const cases: [string, (exporter: any) => void][] = [ + ['identity changed', exporter => (exporter.tank.fish('MyVS').id = 'changed-id')], + [ + 'definition changed outside export', + exporter => (exporter.tank.fish('MyVS').title = 'Changed') + ], + ['changed after export', exporter => (exporter.pkg.valueSets[0].title = 'Changed')] + ]; + + it.each(cases)('should not reuse a ValueSet whose %s, and abort a replay', (why, change) => { + const store = new MemoryStore(); + const state = record(FILES, store); + changeAfterInstances(change); + const recorder = new ExportSession(store, null); + run(FILES, recorder); + expect(recorder.getState().records['FshValueSet:MyVS']).toMatchObject({ ok: false, why }); + const session = new ExportSession(store, state); + run(FILES, session); + expect(session.aborted).toBe(true); + }); + }); + + it('should abort a replay when a nested export it replays fails', () => { + const store = new MemoryStore(); + const state = record(FILES, store); + const original = InstanceExporter.prototype.exportInstance; + const spy = jest + .spyOn(InstanceExporter.prototype, 'exportInstance') + .mockImplementation(function (fshDefinition) { + if (fshDefinition.name === 'InlinePat') { + throw new Error('boom'); + } + return original.call(this, fshDefinition); + }); + try { + const session = new ExportSession(store, state); + run(FILES, session); + expect(session.aborted).toBe(true); + expect(session.abortReason).toMatch(/nested export of Instance:InlinePat .*it threw: boom/); + } finally { + spy.mockRestore(); + } + }); + + it('should abort a replay when the result of an export cannot be restored', () => { + const store = new MemoryStore(); + const state = record(FILES, store); + const rec = Object.values(state.records).find(rec => rec.afterRef != null); + store.payloads.delete(rec.afterRef); + const session = new ExportSession(store, state); + run(FILES, session); + expect(session.aborted).toBe(true); + expect(session.abortReason).toMatch(/^could not restore /); + expect(store.readFailures).toBe(1); + }); + + describe('when an export cannot be recorded', () => { + let spy: jest.SpyInstance = null; + + afterEach(() => { + spy?.mockRestore(); + spy = null; + }); + + const cases: [string, () => void][] = [ + [ + 'unrecordable log', + () => { + const original = (InstanceExporter.prototype as any).exportNewInstance; + spy = jest + .spyOn(InstanceExporter.prototype as any, 'exportNewInstance') + .mockImplementation(function (fshDefinition: any) { + if (fshDefinition.name === 'Pat') { + logger.warn(new Error('not plain data') as any); + } + return original.call(this, fshDefinition); + }); + } + ], + [ + 'found an untracked package object', + () => { + // a copy of MyPatient that no export made, found by looking up MyPatient + const original = CodeSystemExporter.prototype.export; + spy = jest.spyOn(CodeSystemExporter.prototype, 'export').mockImplementation(function () { + const result = original.call(this); + const myPatient = this.pkg.profiles.find((sd: any) => sd.name === 'MyPatient'); + this.pkg.profiles.push(StructureDefinition.fromJSON(myPatient.toJSON())); + return result; + }); + } + ] + ]; + + it.each(cases)('should not reuse an export that %s', (why, setUp) => { + setUp(); + const store = new MemoryStore(); + const state = record(FILES, store); + expect(state.records['Instance:Pat']).toMatchObject({ ok: false, why }); + const plain = run(FILES); + const session = new ExportSession(store, state); + expect(run(FILES, session)).toEqual(plain); + expect(session.aborted).toBe(false); + expect(session.stats.exportedBecause['Instance:Pat']).toBe(`not reusable: ${why}`); + }); + }); + + describe('when the recorded state does not match', () => { + const cases: [string, (state: ExportState) => void][] = [ + ['unexpected state', state => (state.records['Profile:MyPatient'].kind = 'vs')], + [ + 'nothing recorded', + state => { + state.records['Profile:MyPatient'].script = []; + delete state.records['Profile:MyPatient'].payloadRef; + } + ], + ['missing result', state => delete state.records['Profile:MyPatient'].payloadRef], + ['stand-in differs', state => (state.records['Profile:MyPatient'].sdProps = '[]')], + [ + 'alias differs', + state => { + const ev = state.records['Profile:MyPatient'].script.find(ev => ev[0] === 'A'); + ev[2] = 'http://example.org/changed'; + } + ], + [ + 'tank lookup differs', + state => { + const ev = state.records['Profile:MyObservation'].script.find( + ev => ev[0] === 'Q' && ev[1] === 'md' + ); + ev[ev.length - 1] = 'changed'; + } + ], + [ + 'tank lookup state differs', + state => { + const ev = state.records['Profile:MyObservation'].script.find( + ev => ev[0] === 'Q' && ev[4].length > 0 + ); + ev[5] = ev[5].map(() => 'd'); + } + ], + [ + 'unknown exporter', + state => (state.records['Instance:Obs'].script.find(ev => ev[0] === 'T')[2] = 'other') + ], + [ + 'nested export not reusable', + state => (state.records['Instance:Obs'].script.find(ev => ev[0] === 'T')[4] = ['Nope']) + ], + [ + 'nested export already done', + state => + (state.records['Instance:Obs'].script.find(ev => ev[0] === 'T')[4] = ['Instance:Pat']) + ], + [ + 'nested export missing', + state => + (state.records['Instance:Obs'].script.find(ev => ev[0] === 'T')[1] = 'Instance:Nope') + ] + ]; + + it.each(cases)('should export normally, counting %s', (reason, tamper) => { + const store = new MemoryStore(); + const state = record(FILES, store); + tamper(state); + const session = new ExportSession(store, state); + expect(run(FILES, session)).toEqual(run(FILES)); + expect(session.stats.reasons[reason]).toBeGreaterThan(0); + }); + }); +}); diff --git a/test/incremental/IncrementalBuild.test.ts b/test/incremental/IncrementalBuild.test.ts new file mode 100644 index 000000000..f8d23b007 --- /dev/null +++ b/test/incremental/IncrementalBuild.test.ts @@ -0,0 +1,706 @@ +import fs from 'fs'; +import path from 'path'; +import zlib from 'zlib'; +import temp from 'temp'; +import { exportFHIR, Package } from '../../src/export'; +import { FSHTank, RawFSH } from '../../src/import'; +import { FHIRDefinitions } from '../../src/fhirdefs'; +import { IncrementalBuild } from '../../src/incremental/IncrementalBuild'; +import { ExportSession } from '../../src/incremental/ExportSession'; +import { ParseCache } from '../../src/incremental/ParseCache'; +import { CacheStore } from '../../src/incremental/CacheStore'; +import { InstanceExporter, StructureDefinitionExporter } from '../../src/export'; +import { incrementalHooks } from '../../src/incremental/hooks'; +import { fillTank } from '../../src/utils/Processing'; +import { stats } from '../../src/utils/FSHLogger'; +import { getTestFHIRDefinitions, loggerSpy, testDefsPath } from '../testhelpers'; +import { minimalConfig } from '../utils/minimalConfig'; + +const FSH = [ + 'Profile: MyPatient\nParent: Patient\n* name 1..*\n', + 'ValueSet: MyVS\n* http://example.org#a "A"\n', + 'Instance: Pat\nInstanceOf: MyPatient\n* name.family = "Smith"\n', + 'Instance: Bad\nInstanceOf: Patient\n* notAnElement = "value"\n' +]; + +describe('IncrementalBuild', () => { + let defs: FHIRDefinitions; + let projectDir: string; + + beforeAll(async () => { + temp.track(); + defs = await getTestFHIRDefinitions(true, testDefsPath('r4-definitions')); + }); + + beforeEach(() => { + projectDir = temp.mkdirSync('sushi-test'); + fs.writeFileSync(path.join(projectDir, 'sushi-config.yaml'), 'id: test\n'); + loggerSpy.reset(); + }); + + afterEach(() => { + incrementalHooks.session = null; + }); + + afterAll(() => { + temp.cleanupSync(); + }); + + function output(pkg: Package) { + return JSON.stringify([ + pkg.profiles.map(sd => sd.toJSON(true)), + pkg.valueSets.map(vs => vs.toJSON()), + pkg.instances.map(i => i.toJSON()), + [...pkg.fshMap.entries()] + ]); + } + + function messages() { + return loggerSpy + .getAllLogs() + .filter(l => l.level === 'error' || l.level === 'warn') + .map(l => `${l.level}: ${l.message}`); + } + + function rawFSH(fsh: string[]) { + return fsh.map((text, i) => new RawFSH(text, path.join(projectDir, `input/fsh/f${i}.fsh`))); + } + + function plainBuild(fsh = FSH) { + loggerSpy.reset(); + const pkg = exportFHIR(fillTank(rawFSH(fsh), minimalConfig), defs); + return { out: output(pkg), messages: messages() }; + } + + function incrementalBuild( + fsh = FSH, + options: any = {}, + change?: (tank: FSHTank) => void, + sushiVersion = '9.9.9' + ) { + loggerSpy.reset(); + const build = new IncrementalBuild(projectDir, sushiVersion); + const tank = build.importFSH(rawFSH(fsh), minimalConfig); + change?.(tank); + const pkg = build.exportFHIR(tank, defs, options, minimalConfig); + const result = { out: output(pkg), messages: messages() }; + build.logSummary(); + build.finish(); + const own = loggerSpy.getAllMessages('info').filter(m => m.startsWith('Incremental build:')); + const summary = own.find(m => m.includes(' reused ')) ?? own[0]; + const notes = own.filter(m => m !== summary); + return { ...result, summary, notes }; + } + + it('should produce the same output as a normal build, then reuse it', () => { + const expected = plainBuild(); + const first = incrementalBuild(); + expect({ out: first.out, messages: first.messages }).toEqual(expected); + expect(first.summary).toBe('Incremental build: reused 0 of 4 files, 0 of 4 exports.'); + expect(fs.existsSync(path.join(projectDir, '.sushi-cache', 'manifest.json.gz'))).toBe(true); + const second = incrementalBuild(); + expect({ out: second.out, messages: second.messages }).toEqual(expected); + // the error from the bad instance is reported again, as in the normal build + expect(second.summary).toBe('Incremental build: reused 4 of 4 files, 4 of 4 exports.'); + }); + + it('should not reuse exports when the options change', () => { + incrementalBuild(); + const second = incrementalBuild(FSH, { snapshot: true }); + expect(second.summary).toBe('Incremental build: reused 4 of 4 files, 0 of 4 exports.'); + }); + + it('should not reuse exports when the configuration file changes', () => { + incrementalBuild(); + fs.writeFileSync(path.join(projectDir, 'sushi-config.yaml'), 'id: test\n# changed\n'); + const second = incrementalBuild(); + expect(second.summary).toBe('Incremental build: reused 4 of 4 files, 0 of 4 exports.'); + }); + + it('should follow a change to the FSH', () => { + incrementalBuild(); + const changed = [...FSH]; + changed[0] = 'Profile: MyPatient\nParent: Patient\n* name 2..*\n'; + const expected = plainBuild(changed); + const second = incrementalBuild(changed); + expect({ out: second.out, messages: second.messages }).toEqual(expected); + // the profile and its instance are exported again; the others are not affected + expect(second.summary).toBe('Incremental build: reused 3 of 4 files, 2 of 4 exports.'); + }); + + it('should import a file again when an alias it uses changes', () => { + const fsh = [ + 'Alias: $EX = http://example.org\n', + 'ValueSet: AliasVS\n* $EX#a "A"\n', + ...FSH.slice(2) + ]; + incrementalBuild(fsh); + const changed = [...fsh]; + changed[0] = 'Alias: $EX = http://example.org/changed\n'; + const expected = plainBuild(changed); + const second = incrementalBuild(changed); + expect({ out: second.out, messages: second.messages }).toEqual(expected); + // the alias's own file and the ValueSet that uses it + expect(second.summary).toMatch(/^Incremental build: reused 2 of 4 files, /); + }); + + it('should not reuse anything made by a different SUSHI', () => { + incrementalBuild(); + expect(incrementalBuild(FSH, {}, undefined, '9.9.8').summary).toBe( + 'Incremental build: reused 0 of 4 files, 0 of 4 exports.' + ); + }); + + it('should build without the cache when the cache cannot be opened', () => { + fs.writeFileSync(path.join(projectDir, '.sushi-cache'), 'not a directory'); + const expected = plainBuild(); + const first = incrementalBuild(); + expect({ out: first.out, messages: first.messages }).toEqual(expected); + expect([first.summary, ...first.notes]).toContainEqual( + expect.stringMatching(/^Incremental build: not used, cache unavailable \(/) + ); + }); + + it.each([ + ['rules', 'Profile: UsesVS\nParent: Observation\n* ^contained[0] = InlineVS\n'], + ['bindings', 'Profile: UsesVS\nParent: Observation\n* code from InlineVS\n'] + ])('should not reuse a profile with deferred %s', (deferred, profile) => { + const vs = 'Instance: InlineVS\nInstanceOf: ValueSet\nUsage: #inline\n* status = #draft\n'; + const fsh = [...FSH, profile, vs]; + incrementalBuild(fsh); + process.env.SUSHI_INCREMENTAL_DEBUG = '1'; + try { + const warm = incrementalBuild(fsh); + expect({ out: warm.out, messages: warm.messages }).toEqual(plainBuild(fsh)); + const lastRun = JSON.parse( + fs.readFileSync(path.join(projectDir, '.sushi-cache', 'last-run.json'), 'utf8') + ); + expect(lastRun.exportedBecause['Profile:UsesVS']).toBe(`not reusable: deferred ${deferred}`); + } finally { + delete process.env.SUSHI_INCREMENTAL_DEBUG; + } + const changed = [...FSH, profile, vs.replace('#draft', '#active')]; + const edited = incrementalBuild(changed); + expect({ out: edited.out, messages: edited.messages }).toEqual(plainBuild(changed)); + }); + + it('should report messages once when cached results are abandoned and everything is exported again', () => { + const fsh = [...FSH, 'Profile: Inserted\nParent: Patient\n* insert MissingRuleSet\n']; + incrementalBuild(fsh); + // a Mapping that uses a replayed profile after the main export abandons the replay + const withMapping = [ + ...fsh, + 'Mapping: MyMapping\nSource: MyPatient\nTarget: "http://example.org"\n* -> "Patient"\n' + ]; + let errorsBefore = stats.numError; + const expected = plainBuild(withMapping); + const expectedErrors = stats.numError - errorsBefore; + expect(expected.messages.some(m => /MissingRuleSet/.test(m))).toBe(true); + errorsBefore = stats.numError; + const second = incrementalBuild(withMapping); + expect(second.summary).toMatch(/cached results did not apply/); + expect(second.notes).toEqual([ + expect.stringMatching(/^Incremental build: exported everything again, because .+\.$/) + ]); + expect({ out: second.out, messages: second.messages }).toEqual(expected); + expect(stats.numError - errorsBefore).toBe(expectedErrors); + }); + + describe('when its own bookkeeping fails', () => { + let spy: jest.SpyInstance = null; + + afterEach(() => { + spy?.mockRestore(); + spy = null; + }); + + function failIn(method: string) { + spy = jest.spyOn(ExportSession.prototype as any, method).mockImplementation(() => { + throw new Error('boom'); + }); + } + + it.each(['fishSignature', 'payloadOf', 'checkAfterExport'])( + 'should build normally without a cache when %s fails', + method => { + const expected = plainBuild(); + failIn(method); + const first = incrementalBuild(); + expect({ out: first.out, messages: first.messages }).toEqual(expected); + expect(first.notes).toEqual([ + expect.stringMatching(/exports cannot be reused \(.*boom.*\)/) + ]); + } + ); + + it.each(['payloadOf', 'checkAfterExport'])( + 'should build normally with a cache when %s fails, and not use that cache again', + method => { + const expected = plainBuild(); + incrementalBuild(); + failIn(method); + const second = incrementalBuild(); + expect({ out: second.out, messages: second.messages }).toEqual(expected); + // the cache this build used may be what made it fail, so the next build does not use it, + // and exports everything once + const third = incrementalBuild(); + expect({ out: third.out, messages: third.messages }).toEqual(expected); + expect(third.summary).toBe('Incremental build: reused 4 of 4 files, 0 of 4 exports.'); + expect(third.notes).toContain( + 'Incremental build: exports were not reused, as the previous build could not save them.' + ); + spy.mockRestore(); + spy = null; + incrementalBuild(); + expect(incrementalBuild().summary).toBe( + 'Incremental build: reused 4 of 4 files, 4 of 4 exports.' + ); + } + ); + + it('should keep the previous cache when preparing the export fails before using it', () => { + const expected = plainBuild(); + incrementalBuild(); + failIn('fishSignature'); + const second = incrementalBuild(); + expect({ out: second.out, messages: second.messages }).toEqual(expected); + expect(second.summary).toBe('Incremental build: reused 4 of 4 files, 0 of 4 exports.'); + expect(second.notes[0]).toBe( + 'Incremental build: exports were not reused, as the export could not be prepared.' + ); + spy.mockRestore(); + spy = null; + expect(incrementalBuild().summary).toBe( + 'Incremental build: reused 4 of 4 files, 4 of 4 exports.' + ); + }); + + it('should keep the previous cache when two definitions have the same name', () => { + incrementalBuild(); + const second = incrementalBuild(FSH, {}, tank => { + const all = tank.getAllValueSets.bind(tank); + tank.getAllValueSets = () => [...all(), ...all()]; + }); + expect(second.notes[0]).toBe( + 'Incremental build: exports were not reused, as there are two definitions of FshValueSet:MyVS.' + ); + expect(incrementalBuild().summary).toBe( + 'Incremental build: reused 4 of 4 files, 4 of 4 exports.' + ); + }); + + it('should report what happened when exporting everything again fails', () => { + const expected = plainBuild(); + incrementalBuild(); + failIn('checkAfterExport'); + let original: FSHTank = null; + const all = FSHTank.prototype.getAllInstances; + const tankSpy = jest.spyOn(FSHTank.prototype, 'getAllInstances').mockImplementation(function ( + this: FSHTank + ) { + if (original != null && this !== original) { + throw new Error('kaboom'); + } + return all.call(this); + }); + try { + loggerSpy.reset(); + const build = new IncrementalBuild(projectDir, '9.9.9'); + original = build.importFSH(rawFSH(FSH), minimalConfig); + expect(() => build.exportFHIR(original, defs, {}, minimalConfig)).toThrow('kaboom'); + } finally { + tankSpy.mockRestore(); + } + const own = loggerSpy.getAllMessages('info').filter(m => m.startsWith('Incremental build:')); + expect(own[0]).toMatch( + /cached results did not apply; exported everything\), before the export failed\.$/ + ); + expect(own).toContainEqual( + expect.stringMatching(/exported everything again, because .*boom/) + ); + expect(own).toContainEqual(expect.stringMatching(/exports cannot be reused \(.*kaboom/)); + expect( + loggerSpy + .getAllMessages('debug') + .some(m => /unexpected error export: Error: kaboom/.test(m)) + ).toBe(true); + // the records it used are not used again + spy.mockRestore(); + spy = null; + const third = incrementalBuild(); + expect({ out: third.out, messages: third.messages }).toEqual(expected); + expect(third.notes).toContain( + 'Incremental build: exports were not reused, as the previous build could not save them.' + ); + }); + + function failToCopy() { + return jest + .spyOn(IncrementalBuild.prototype as any, 'restoreSnapshot') + .mockImplementation(() => { + throw new Error('no copy'); + }); + } + + it('should build without the cache when it cannot start over after abandoning a replay', () => { + let errorsBefore = stats.numError; + const expected = plainBuild(); + const expectedErrors = stats.numError - errorsBefore; + incrementalBuild(); + failIn('checkAfterExport'); + const copySpy = failToCopy(); + errorsBefore = stats.numError; + let second: ReturnType; + try { + second = incrementalBuild(); + } finally { + copySpy.mockRestore(); + } + expect({ out: second.out, messages: second.messages }).toEqual(expected); + expect(stats.numError - errorsBefore).toBe(expectedErrors); + expect(second.summary).toBe( + 'Incremental build: imported all 4 files again, and reused no exports (cached results did not apply; exported everything without the cache).' + ); + expect(second.notes[0]).toMatch( + /^Incremental build: exported everything without the cache, because .*boom.*, and the definitions could not be copied \(no copy\)\.$/ + ); + // nothing the abandoned attempt recorded is kept + spy.mockRestore(); + spy = null; + expect(incrementalBuild().notes).toContain( + 'Incremental build: exports were not reused, as the previous build could not save them.' + ); + }); + + it('should build without the cache when it cannot start over after an export failed', () => { + const expected = plainBuild(); + incrementalBuild(); + // fails only while the cache is used + const real = InstanceExporter.prototype.export; + spy = jest.spyOn(InstanceExporter.prototype, 'export').mockImplementation(function ( + this: InstanceExporter + ) { + if (incrementalHooks.session != null) { + throw new Error('first'); + } + return real.call(this); + }); + const copySpy = failToCopy(); + let second: ReturnType; + try { + second = incrementalBuild(); + } finally { + copySpy.mockRestore(); + } + expect({ out: second.out, messages: second.messages }).toEqual(expected); + expect(second.summary).toMatch(/exported everything without the cache\)\.$/); + }); + + it("should fail with a normal build's error when building without the cache fails too", () => { + incrementalBuild(); + spy = jest.spyOn(InstanceExporter.prototype, 'export').mockImplementation(() => { + throw new Error(incrementalHooks.session != null ? 'first' : 'second'); + }); + const copySpy = failToCopy(); + try { + loggerSpy.reset(); + const build = new IncrementalBuild(projectDir, '9.9.9'); + const tank = build.importFSH(rawFSH(FSH), minimalConfig); + expect(() => build.exportFHIR(tank, defs, {}, minimalConfig)).toThrow('second'); + } finally { + copySpy.mockRestore(); + } + expect( + loggerSpy + .getAllMessages('info') + .some(m => /without the cache\), before the export failed/.test(m)) + ).toBe(true); + // the first attempt's error is kept for debugging + expect( + loggerSpy + .getAllMessages('debug') + .some(m => /unexpected error export: Error: first\n\s+at /.test(m)) + ).toBe(true); + }); + + it('should not export again when the export fails before it begins', () => { + incrementalBuild(); + spy = jest + .spyOn(StructureDefinitionExporter.prototype, 'applyInsertRules') + .mockImplementation(() => { + throw new Error('early'); + }); + const exportSpy = jest.spyOn(InstanceExporter.prototype, 'export'); + try { + loggerSpy.reset(); + const build = new IncrementalBuild(projectDir, '9.9.9'); + const tank = build.importFSH(rawFSH(FSH), minimalConfig); + expect(() => build.exportFHIR(tank, defs, {}, minimalConfig)).toThrow('early'); + expect(exportSpy).not.toHaveBeenCalled(); + } finally { + exportSpy.mockRestore(); + } + const own = loggerSpy.getAllMessages('info').filter(m => m.startsWith('Incremental build:')); + expect(own.some(m => /exported everything again/.test(m))).toBe(false); + // the cache was not used, so it is kept + spy.mockRestore(); + spy = null; + expect(incrementalBuild().summary).toBe( + 'Incremental build: reused 4 of 4 files, 4 of 4 exports.' + ); + }); + + it('should count a failure to record what an import used', () => { + const fsh = [ + ...FSH, + 'RuleSet: Named(family)\n* name.family = "{family}"\n', + 'Instance: Pat2\nInstanceOf: Patient\n* insert Named(Jones)\n' + ]; + spy = jest.spyOn(ParseCache.prototype, 'hash').mockImplementation(() => { + throw new Error('boom'); + }); + const first = incrementalBuild(fsh); + expect(first.notes).toContain('Incremental build: could not write to the cache (boom).'); + expect( + loggerSpy + .getAllMessages('debug') + .filter(m => + /unexpected error while hashing the RuleSet Named for .*: Error: boom/.test(m) + ) + ).toHaveLength(1); + }); + + it('should keep a failure to store a recorded export', () => { + spy = jest.spyOn(CacheStore.prototype, 'putPayload').mockImplementation(() => { + throw new Error('boom'); + }); + const expected = plainBuild(); + const first = incrementalBuild(); + expect({ out: first.out, messages: first.messages }).toEqual(expected); + expect(first.notes).toContain('Incremental build: could not write to the cache (boom).'); + expect( + loggerSpy + .getAllMessages('debug') + .some(m => /unexpected error while storing Profile:MyPatient: Error: boom/.test(m)) + ).toBe(true); + expect( + loggerSpy + .getAllMessages('debug') + .some(m => /unexpected error while storing the import of .*: Error: boom/.test(m)) + ).toBe(true); + }); + + it('should count a failure to cache an import', () => { + spy = jest.spyOn(ParseCache.prototype, 'encodeDoc').mockImplementation(() => { + throw new Error('boom'); + }); + const first = incrementalBuild(); + expect(first.notes).toContain('Incremental build: could not write to the cache (boom).'); + expect( + loggerSpy + .getAllMessages('debug') + .some(m => /unexpected error while encoding the import of .*: Error: boom/.test(m)) + ).toBe(true); + }); + + it('should keep the previous cache when it was not used', () => { + incrementalBuild(); + // the definitions cannot be copied, so the cache is not used, and this build cannot be saved + failIn('payloadOf'); + const second = incrementalBuild(FSH, {}, tank => ((tank.docs[0] as any).extra = () => 1)); + expect(second.notes[0]).toMatch(/definitions could not be copied/); + spy.mockRestore(); + spy = null; + expect(incrementalBuild().summary).toBe( + 'Incremental build: reused 4 of 4 files, 4 of 4 exports.' + ); + }); + + it('should keep the stack of an unexpected error', () => { + failIn('checkAfterExport'); + incrementalBuild(); + expect( + loggerSpy + .getAllMessages('debug') + .some(m => /unexpected error while bookkeeping: Error: boom\n\s+at /.test(m)) + ).toBe(true); + }); + }); + + it('should say why nothing was reused when the options change', () => { + incrementalBuild(); + const second = incrementalBuild(FSH, { snapshot: true }); + expect(second.notes).toEqual([ + 'Incremental build: exports were not reused, as the options, configuration, dependencies or SUSHI changed.' + ]); + }); + + it('should explain why a file was not cached', () => { + // the importer logs the error object for a filter with no value + const fsh = [ + ...FSH, + 'ValueSet: FilteredVS\n* include codes from system http://x.org where concept is-a\n' + ]; + const expected = plainBuild(fsh); + const first = incrementalBuild(fsh); + expect({ out: first.out, messages: first.messages }).toEqual(expected); + expect(loggerSpy.getAllMessages('debug')).toContainEqual( + expect.stringMatching( + /^Incremental build: did not cache the import of .*f4\.fsh, as a message it logs could not be copied\.$/ + ) + ); + }); + + it('should not count cache problems as warnings', () => { + incrementalBuild(); + const payloadDir = path.join(projectDir, '.sushi-cache', 'p'); + fs.readdirSync(payloadDir).forEach(file => + fs.writeFileSync(path.join(payloadDir, file), zlib.gzipSync('corrupt')) + ); + const warningsBefore = stats.numWarn; + const expected = plainBuild(); + const expectedWarnings = stats.numWarn - warningsBefore; + const second = incrementalBuild(); + expect({ out: second.out, messages: second.messages }).toEqual(expected); + expect(stats.numWarn - warningsBefore).toBe(2 * expectedWarnings); + expect(second.notes.some(n => /removed \d+ corrupt file\(s\) from the cache/.test(n))).toBe( + true + ); + }); + + it('should reuse a ValueSet with a regex filter', () => { + const fsh = [ + ...FSH, + 'ValueSet: RegexVS\n* include codes from system http://example.org where display regex /^A.*/\n' + ]; + const expected = plainBuild(fsh); + incrementalBuild(fsh); + const second = incrementalBuild(fsh); + expect({ out: second.out, messages: second.messages }).toEqual(expected); + expect(second.summary).toBe('Incremental build: reused 5 of 5 files, 5 of 5 exports.'); + }); + + it('should build normally when the cache is corrupt', () => { + incrementalBuild(); + const cacheDir = path.join(projectDir, '.sushi-cache'); + fs.writeFileSync(path.join(cacheDir, 'manifest.json.gz'), zlib.gzipSync('{"format":')); + const expected = plainBuild(); + const second = incrementalBuild(); + expect({ out: second.out, messages: second.messages }).toEqual(expected); + expect(second.summary).toBe('Incremental build: reused 0 of 4 files, 0 of 4 exports.'); + expect(second.notes).toEqual([ + 'Incremental build: the cache could not be read (Unexpected end of JSON input), so nothing was reused.' + ]); + // and then uses the cache it rewrote + expect(incrementalBuild().summary).toBe( + 'Incremental build: reused 4 of 4 files, 4 of 4 exports.' + ); + }); + + it('should build normally when cached payloads are missing', () => { + incrementalBuild(); + const payloadDir = path.join(projectDir, '.sushi-cache', 'p'); + fs.readdirSync(payloadDir).forEach(file => fs.unlinkSync(path.join(payloadDir, file))); + const expected = plainBuild(); + const second = incrementalBuild(); + expect({ out: second.out, messages: second.messages }).toEqual(expected); + expect(second.summary).toBe('Incremental build: reused 0 of 4 files, 0 of 4 exports.'); + expect(second.notes).toContainEqual( + expect.stringMatching( + /^Incremental build: could not use \d+ cached result\(s\) \(first: ENOENT/ + ) + ); + }); + + it('should reuse imports when the build cannot be identified', () => { + incrementalBuild(); + const config = path.join(projectDir, 'sushi-config.yaml'); + fs.unlinkSync(config); + fs.mkdirSync(config); + const expected = plainBuild(); + const second = incrementalBuild(); + expect({ out: second.out, messages: second.messages }).toEqual(expected); + expect(second.summary).toMatch( + /^Incremental build: reused 4 of 4 files, but no exports, as the build could not be identified \(.*EISDIR/ + ); + fs.rmdirSync(config); + fs.writeFileSync(config, 'id: test\n'); + // the exports recorded before are still there + expect(incrementalBuild().summary).toBe( + 'Incremental build: reused 4 of 4 files, 4 of 4 exports.' + ); + }); + + it('should report the cache when the build cannot be identified and the export fails', () => { + incrementalBuild(); + const payloadDir = path.join(projectDir, '.sushi-cache', 'p'); + fs.readdirSync(payloadDir).forEach(file => fs.unlinkSync(path.join(payloadDir, file))); + const config = path.join(projectDir, 'sushi-config.yaml'); + fs.unlinkSync(config); + fs.mkdirSync(config); + const spy = jest.spyOn(InstanceExporter.prototype, 'export').mockImplementation(() => { + throw new Error('boom'); + }); + try { + loggerSpy.reset(); + const build = new IncrementalBuild(projectDir, '9.9.9'); + const tank = build.importFSH(rawFSH(FSH), minimalConfig); + expect(() => build.exportFHIR(tank, defs, {}, minimalConfig)).toThrow('boom'); + } finally { + spy.mockRestore(); + } + const own = loggerSpy.getAllMessages('info').filter(m => m.startsWith('Incremental build:')); + expect(own[0]).toMatch( + /^Incremental build: reused 0 of 4 files, but no exports, as the build could not be identified \(.*\), before the export failed\.$/ + ); + expect(own).toContainEqual(expect.stringMatching(/could not use \d+ cached result\(s\)/)); + }); + + it('should remove the debugging summary of an earlier build', () => { + incrementalBuild(); + const summary = path.join(projectDir, '.sushi-cache', 'last-run.json'); + fs.writeFileSync(summary, '{}'); + new IncrementalBuild(projectDir, '9.9.9'); + expect(fs.existsSync(summary)).toBe(false); + }); + + it('should use the cache when an earlier debugging summary cannot be removed', () => { + incrementalBuild(); + const summary = path.join(projectDir, '.sushi-cache', 'last-run.json'); + fs.mkdirSync(path.join(summary, 'inside'), { recursive: true }); + const second = incrementalBuild(); + expect(second.summary).toBe('Incremental build: reused 4 of 4 files, 4 of 4 exports.'); + expect(second.notes).toContainEqual( + expect.stringMatching(/^Incremental build: could not remove the debugging summary/) + ); + }); + + it('should keep the cache out of git', () => { + incrementalBuild(); + expect(fs.readFileSync(path.join(projectDir, '.sushi-cache', '.gitignore'), 'utf8')).toMatch( + /^\*$/m + ); + }); + + it('should note a cache it cannot save', () => { + fs.mkdirSync(path.join(projectDir, '.sushi-cache', 'manifest.json.gz'), { recursive: true }); + const expected = plainBuild(); + const first = incrementalBuild(); + expect({ out: first.out, messages: first.messages }).toEqual(expected); + expect(first.notes).toContainEqual( + expect.stringMatching(/^Incremental build: could not save the cache \(/) + ); + }); + + it('should note files it cannot remove from the cache', () => { + incrementalBuild(); + const stuck = path.join(projectDir, '.sushi-cache', 'p', 'stuck.json.gz'); + fs.mkdirSync(stuck); + const old = new Date(Date.now() - 2 * 24 * 60 * 60 * 1000); + fs.utimesSync(stuck, old, old); + const second = incrementalBuild(); + expect(second.notes).toContainEqual( + expect.stringMatching(/^Incremental build: could not remove some files from the cache \(/) + ); + }); +}); diff --git a/test/incremental/ParseCache.test.ts b/test/incremental/ParseCache.test.ts new file mode 100644 index 000000000..fa62333f8 --- /dev/null +++ b/test/incremental/ParseCache.test.ts @@ -0,0 +1,230 @@ +import { FSHDocument, FSHImporter, RawFSH } from '../../src/import'; +import { ParseCache } from '../../src/incremental/ParseCache'; +import { PayloadStore } from '../../src/incremental/CacheStore'; +import { encode, hashString } from '../../src/incremental/serialize'; +import { definitionRegistry } from '../../src/incremental/registries'; +import { loggerSpy } from '../testhelpers'; + +class MemoryStore implements PayloadStore { + readonly payloads = new Map(); + readFailures = 0; + writeFailures = 0; + + putPayload(json: string): string { + const ref = hashString(json); + this.payloads.set(ref, json); + return ref; + } + + getPayload(ref: string): any { + if (!this.payloads.has(ref)) { + throw new Error('missing payload'); + } + return JSON.parse(this.payloads.get(ref)); + } + + readFailed(): void { + this.readFailures++; + } + + writeFailed(): void { + this.writeFailures++; + } +} + +const FILES: Record = { + 'aliases.fsh': 'Alias: $sct = http://snomed.info/sct\nAlias: $unused = http://example.org\n', + 'rulesets.fsh': 'RuleSet: Flag(path)\n* {path} MS\n\nRuleSet: Plain\n* ^status = #active\n', + 'profile.fsh': 'Profile: MyPatient\nParent: Patient\n* insert Flag(name)\n* insert Plain\n', + 'vs.fsh': 'ValueSet: MyVS\n* $sct#123 "Something"\n', + 'cs.fsh': 'CodeSystem: MyCS\n* #a "A"\n', + 'warn.fsh': 'Profile: Warned\nParent: Patient\n* = = BAD\n' +}; + +describe('ParseCache', () => { + beforeEach(() => { + loggerSpy.reset(); + }); + + function rawFSH(files: Record) { + return Object.entries(files).map(([path, text]) => new RawFSH(text, path)); + } + + function encodeDocs(docs: FSHDocument[]) { + return JSON.stringify(encode(docs, definitionRegistry())); + } + + function logs() { + return loggerSpy.getAllLogs().map(l => [l.level, l.message, l.file, l.location]); + } + + function plain(files: Record) { + loggerSpy.reset(); + const docs = new FSHImporter().import(rawFSH(files)); + return { docs: encodeDocs(docs), logs: logs() }; + } + + function cached(files: Record, cache: ParseCache) { + loggerSpy.reset(); + const docs = new FSHImporter().import(rawFSH(files), cache); + return { docs: encodeDocs(docs), logs: logs() }; + } + + function build(files: Record, store: MemoryStore, old: ParseCache | null) { + const cache = new ParseCache(store, old?.entries ?? null); + const result = cached(files, cache); + return { cache, result }; + } + + it('should import the same documents and logs as a normal import, without and with a cache', () => { + const store = new MemoryStore(); + const expected = plain(FILES); + // the syntax error produces an error, which must be reproduced + expect(expected.logs.some(l => l[0] === 'error')).toBe(true); + const first = build(FILES, store, null); + expect(first.result).toEqual(expected); + expect(first.cache.hits).toBe(0); + const second = build(FILES, store, first.cache); + expect(second.result).toEqual(expected); + expect(second.cache.hits).toBe(Object.keys(FILES).length); + expect(second.cache.misses).toBe(0); + }); + + it('should only import a changed file again', () => { + const store = new MemoryStore(); + const first = build(FILES, store, null); + const changed = { ...FILES, 'cs.fsh': 'CodeSystem: MyCS\n* #b "B"\n' }; + const second = build(changed, store, first.cache); + expect(second.result).toEqual(plain(changed)); + expect(second.cache.misses).toBe(1); + }); + + it('should import files that use a changed alias again', () => { + const store = new MemoryStore(); + const first = build(FILES, store, null); + const changed = { + ...FILES, + 'aliases.fsh': FILES['aliases.fsh'].replace('snomed.info', 'x.org') + }; + const second = build(changed, store, first.cache); + expect(second.result).toEqual(plain(changed)); + // aliases.fsh and vs.fsh, which uses $sct + expect(second.cache.misses).toBe(2); + }); + + it('should import files that use a changed parameterized RuleSet again', () => { + const store = new MemoryStore(); + const first = build(FILES, store, null); + const changed = { ...FILES, 'rulesets.fsh': FILES['rulesets.fsh'].replace('MS', 'SU') }; + const second = build(changed, store, first.cache); + expect(second.result).toEqual(plain(changed)); + expect(second.cache.misses).toBe(2); + }); + + it('should import files whose names became duplicates again', () => { + const store = new MemoryStore(); + const first = build(FILES, store, null); + const changed = { ...FILES, 'dup.fsh': 'ValueSet: MyVS\n* $sct#456 "Other"\n' }; + const second = build(changed, store, first.cache); + expect(second.result).toEqual(plain(changed)); + expect(second.result.logs.some(l => /MyVS/.test(l[1]))).toBe(true); + }); + + it('should reproduce syntax errors, and recover when they are fixed', () => { + const store = new MemoryStore(); + const first = build(FILES, store, null); + const broken = { ...FILES, 'profile.fsh': FILES['profile.fsh'] + '* = = BROKEN\n' }; + const second = build(broken, store, first.cache); + expect(second.result).toEqual(plain(broken)); + expect(second.result.logs.some(l => l[0] === 'error' && /File: profile\.fsh/.test(l[1]))).toBe( + true + ); + const third = build(broken, store, second.cache); + expect(third.result).toEqual(plain(broken)); + const fixed = build(FILES, store, third.cache); + expect(fixed.result).toEqual(plain(FILES)); + }); + + it('should import normally when a cached entry is missing or malformed', () => { + const store = new MemoryStore(); + const first = build(FILES, store, null); + const [first1, second1] = Object.values(first.cache.entries); + store.payloads.delete(first1.ref); + store.payloads.set(second1.ref, JSON.stringify({ doc: null })); + const second = build(FILES, store, first.cache); + expect(second.result).toEqual(plain(FILES)); + expect(second.cache.misses).toBe(2); + }); + + function rewriteEntry( + store: MemoryStore, + cache: ParseCache, + file: string, + change: (entry: any) => void + ) { + const ref = cache.entries[file].ref; + const entry = JSON.parse(store.payloads.get(ref)); + change(entry); + store.payloads.set(ref, JSON.stringify(entry)); + } + + it('should import normally when a cached document cannot be decoded', () => { + const store = new MemoryStore(); + const first = build(FILES, store, null); + rewriteEntry(store, first.cache, 'cs.fsh', entry => (entry.doc = 5)); + const second = build(FILES, store, first.cache); + expect(second.result).toEqual(plain(FILES)); + expect(second.cache.misses).toBe(1); + expect(store.readFailures).toBe(1); + expect(second.cache.errors[0]).toMatch(/not a FSHDocument/); + }); + + it('should import normally when what a cached import used cannot be checked', () => { + const store = new MemoryStore(); + const first = build(FILES, store, null); + rewriteEntry(store, first.cache, 'cs.fsh', entry => (entry.dependencies = [['unknown']])); + rewriteEntry(store, first.cache, 'vs.fsh', entry => (entry.dependencies = [null])); + const second = build(FILES, store, first.cache); + expect(second.result).toEqual(plain(FILES)); + expect(second.cache.misses).toBe(2); + // an unknown kind of dependency just doesn't hold, but one that can't be read is a failure + expect(store.readFailures).toBe(1); + }); + + it('should not cache a file that logs a message it cannot copy', () => { + const store = new MemoryStore(); + // the importer logs the error object for a filter with no value + const files = { + ...FILES, + 'filter.fsh': + 'ValueSet: FilteredVS\n* include codes from system http://x.org where concept is-a\n' + }; + const first = build(files, store, null); + expect(first.result).toEqual(plain(files)); + expect(first.cache.entries['filter.fsh']).toBeUndefined(); + expect(first.cache.skippedFiles).toEqual([ + 'did not cache the import of filter.fsh, as a message it logs could not be copied' + ]); + const second = build(files, store, first.cache); + expect(second.result).toEqual(plain(files)); + expect(second.cache.misses).toBe(1); + }); + + it('should not cache a file whose import ran out of stack space', () => { + const store = new MemoryStore(); + // what is logged when the stack runs out depends on how deep the stack already was + const files = { + ...FILES, + 'recursive.fsh': + 'RuleSet: Again(p)\n* name.given = "{p}"\n* insert Again(q)\n\nProfile: Deep\nParent: Patient\n* insert Again(w)\n' + }; + const first = build(files, store, null); + expect(first.result.logs.some(l => /Maximum call stack size exceeded/.test(l[1]))).toBe(true); + expect(first.cache.entries['recursive.fsh']).toBeUndefined(); + expect(first.cache.skippedFiles).toEqual([ + 'did not cache the import of recursive.fsh, as importing it caught a RangeError' + ]); + const second = build(files, store, first.cache); + expect(second.cache.misses).toBe(1); + }); +}); diff --git a/test/incremental/cacheKey.test.ts b/test/incremental/cacheKey.test.ts new file mode 100644 index 000000000..9a34544db --- /dev/null +++ b/test/incremental/cacheKey.test.ts @@ -0,0 +1,47 @@ +import fs from 'fs-extra'; +import os from 'os'; +import path from 'path'; +import { exportKey } from '../../src/incremental/cacheKey'; + +describe('cacheKey', () => { + describe('#exportKey', () => { + let dir: string; + + beforeEach(() => { + dir = fs.mkdtempSync(path.join(os.tmpdir(), 'sushi-cachekey-')); + }); + + afterEach(() => { + fs.removeSync(dir); + }); + + function keyFor(packageJSONPath: string, resourcePath: string) { + const defs: any = { + findPackageInfos: () => [{ name: 'p', version: '1.0.0', packageJSONPath }], + findResourceInfos: () => [{ name: 'r', resourcePath }], + allPredefinedResources: (): any[] => [] + }; + return exportKey('tool', {}, null, 'config', defs); + } + + it('should change when a dependency or loaded resource file changes', () => { + const packageJSON = path.join(dir, 'package.json'); + const resource = path.join(dir, 'resource.json'); + fs.writeFileSync(packageJSON, '{}'); + fs.writeFileSync(resource, '{}'); + const key = keyFor(packageJSON, resource); + expect(keyFor(packageJSON, resource)).toBe(key); + fs.writeFileSync(resource, '{ }'); + const changedResource = keyFor(packageJSON, resource); + expect(changedResource).not.toBe(key); + fs.writeFileSync(packageJSON, '{ }'); + expect(keyFor(packageJSON, resource)).not.toBe(changedResource); + }); + + it('should not need the files to exist', () => { + const missing = path.join(dir, 'missing.json'); + expect(keyFor(missing, missing)).toBe(keyFor(missing, missing)); + expect(keyFor(missing, missing)).not.toBe(keyFor(null, null)); + }); + }); +}); diff --git a/test/incremental/logCapture.test.ts b/test/incremental/logCapture.test.ts new file mode 100644 index 000000000..ef66aaa05 --- /dev/null +++ b/test/incremental/logCapture.test.ts @@ -0,0 +1,131 @@ +import { captureLogs, copyLogInfo, emitLogInfo, holdLogs } from '../../src/incremental/logCapture'; +import { logger, restoreMainLogger, switchToSecretLogger } from '../../src/utils/FSHLogger'; +import { loggerSpy } from '../testhelpers'; + +describe('logCapture', () => { + beforeEach(() => { + loggerSpy.reset(); + }); + + describe('#copyLogInfo', () => { + it('should copy a log entry as plain data, without undefined values', () => { + expect(copyLogInfo({ level: 'warn', message: 'm', file: 'a.fsh', extra: undefined })).toEqual( + { level: 'warn', message: 'm', file: 'a.fsh' } + ); + }); + + it('should not copy an entry without a string message or level', () => { + expect(copyLogInfo(null)).toBeNull(); + expect(copyLogInfo({ level: 'error', message: new Error('e') })).toBeNull(); + expect(copyLogInfo({ message: 'm' })).toBeNull(); + const error: any = new Error('not enumerable'); + error.level = 'error'; + expect(copyLogInfo(error)).toBeNull(); + }); + + it('should not copy an entry that is not plain data', () => { + const circular: any = { level: 'error', message: 'm' }; + circular.self = circular; + expect(copyLogInfo(circular)).toBeNull(); + }); + }); + + describe('#captureLogs', () => { + it('should return the result, and copies of the entries written', () => { + const { result, logs } = captureLogs(() => { + logger.warn('first'); + logger.error('second', { file: 'a.fsh' }); + return 42; + }, false); + expect(result).toBe(42); + expect(logs.map(l => [l.level, l.message, l.file])).toEqual([ + ['warn', 'first', undefined], + ['error', 'second', 'a.fsh'] + ]); + expect(loggerSpy.getAllLogs()).toHaveLength(2); + }); + + it('should not write the entries when muted, and write them again later', () => { + const { logs } = captureLogs(() => logger.warn('muted'), true); + expect(loggerSpy.getAllMessages()).toEqual([]); + logs.forEach(emitLogInfo); + expect(loggerSpy.getAllLogs().map(l => [l.level, l.message])).toEqual([['warn', 'muted']]); + }); + + it('should give no logs if an entry cannot be copied, but still write it', () => { + const { logs } = captureLogs(() => { + logger.error(new Error('as an object') as any); + logger.warn('after'); + }, false); + expect(logs).toBeNull(); + expect(loggerSpy.getAllLogs()).toHaveLength(2); + }); + + it('should pass entries for the secret logger straight through', () => { + const { logs } = captureLogs(() => { + const saved = switchToSecretLogger(); + // set aside while collecting, so it does not add to the stack + expect(Object.getOwnPropertyDescriptor(logger, 'write')).toBeUndefined(); + logger.error('collected'); + const collected = restoreMainLogger(saved); + expect(collected.errors.map(e => e.message)).toEqual(['collected']); + logger.warn('after'); + }, true); + expect(logs.map(l => l.message)).toEqual(['after']); + }); + + it('should restore the logger, also when captures are nested or fn throws', () => { + const write = logger.write; + const outer = captureLogs(() => { + captureLogs(() => logger.warn('inner'), true); + logger.warn('outer'); + expect(() => + captureLogs(() => { + throw new Error('boom'); + }, false) + ).toThrow('boom'); + logger.warn('still captured'); + }, true); + expect(outer.logs.map(l => l.message)).toEqual(['outer', 'still captured']); + expect(logger.write).toBe(write); + expect(Object.getOwnPropertyDescriptor(logger, 'write')).toBeUndefined(); + }); + }); + + describe('#holdLogs', () => { + it('should hold entries until released, then write them or drop them', () => { + const held = holdLogs(); + logger.warn('kept'); + expect(loggerSpy.getAllLogs()).toHaveLength(0); + held.release(true); + held.release(true); + expect(loggerSpy.getAllLogs().map(l => l.message)).toEqual(['kept']); + + const dropped = holdLogs(); + logger.warn('dropped'); + dropped.release(false); + expect(loggerSpy.getAllLogs()).toHaveLength(1); + }); + + it('should pass entries for the secret logger straight through', () => { + const held = holdLogs(); + const saved = switchToSecretLogger(); + logger.error('collected'); + const collected = restoreMainLogger(saved); + held.release(false); + expect(collected.errors.map(e => e.message)).toEqual(['collected']); + }); + + it('should restore a capture it was nested in', () => { + const write = logger.write; + const { logs } = captureLogs(() => { + const held = holdLogs(); + logger.warn('inner'); + held.release(true); + logger.warn('outer'); + }, true); + expect(logs.map(l => l.message)).toEqual(['inner', 'outer']); + expect(logger.write).toBe(write); + }); + }); +}); diff --git a/test/incremental/serialize.test.ts b/test/incremental/serialize.test.ts new file mode 100644 index 000000000..5ddd93ef1 --- /dev/null +++ b/test/incremental/serialize.test.ts @@ -0,0 +1,154 @@ +import { + UnserializableError, + buildClassRegistry, + decode, + encode, + hashValue, + replaceOwnProperties +} from '../../src/incremental/serialize'; +import { definitionRegistry } from '../../src/incremental/registries'; +import { importSingleText } from '../testhelpers'; + +class Point { + constructor( + public x: number, + public y?: number + ) {} + sum() { + return this.x + (this.y ?? 0); + } +} + +describe('serialize', () => { + const registry = buildClassRegistry({ Point }); + const roundTrip = (value: any) => + decode(JSON.parse(JSON.stringify(encode(value, registry))), registry); + + it('should round-trip plain values', () => { + const value = { a: 1, b: 'two', c: [true, null, 3.5], d: { e: 'nested' } }; + expect(roundTrip(value)).toEqual(value); + }); + + it('should keep values that JSON cannot represent', () => { + const value = { u: undefined as any, neg: -0, inf: Infinity, nan: NaN, big: BigInt(12) }; + const result = roundTrip(value); + expect(Object.keys(result)).toEqual(['u', 'neg', 'inf', 'nan', 'big']); + expect(result.u).toBeUndefined(); + expect(Object.is(result.neg, -0)).toBe(true); + expect(result.inf).toBe(Infinity); + expect(result.nan).toBeNaN(); + expect(result.big).toBe(BigInt(12)); + }); + + it('should keep Maps, Sets, Dates, and plain objects with keys that look like markers', () => { + const value = { + map: new Map([ + ['k', 1], + [2, { v: 'x' }] + ]), + set: new Set(['a', 'b']), + date: new Date(1700000000000), + marker: { $r: 1, $c: 'Point' } + }; + const result = roundTrip(value); + expect(result.map).toEqual(value.map); + expect(result.set).toEqual(value.set); + expect(result.date).toEqual(value.date); + expect(result.marker).toEqual({ $r: 1, $c: 'Point' }); + }); + + it('should keep regular expressions', () => { + const sticky = /a+/gy; + sticky.lastIndex = 2; + const value = { regex: /^http:\/\/[a-z]+$/i, sticky, again: sticky }; + const result = roundTrip(value); + expect(result.regex).toBeInstanceOf(RegExp); + expect(result.regex.source).toBe(value.regex.source); + expect(result.regex.flags).toBe('i'); + expect(result.sticky.flags).toBe('gy'); + expect(result.sticky.lastIndex).toBe(2); + expect(result.again).toBe(result.sticky); + expect(hashValue(result, registry)).toBe(hashValue(value, registry)); + }); + + it('should keep class identity and property order', () => { + const result = roundTrip(new Point(1, 2)); + expect(result).toBeInstanceOf(Point); + expect(result.sum()).toBe(3); + expect(Object.keys(result)).toEqual(['x', 'y']); + }); + + it('should keep shared and circular references', () => { + const shared = new Point(5); + const value: any = { first: shared, second: shared, list: [shared] }; + value.self = value; + const result = roundTrip(value); + expect(result.first).toBe(result.second); + expect(result.list[0]).toBe(result.first); + expect(result.self).toBe(result); + }); + + it('should throw an UnserializableError for functions, symbols, and unknown classes', () => { + class Unknown {} + expect(() => encode({ f: () => 1 }, registry)).toThrow(UnserializableError); + expect(() => encode({ s: Symbol('s') }, registry)).toThrow(UnserializableError); + expect(() => encode({ o: new Unknown() }, registry)).toThrow(UnserializableError); + }); + + it('should throw an UnserializableError for a regular expression with extra properties', () => { + const regex: any = /a/; + regex.extra = true; + expect(() => encode(regex, registry)).toThrow(UnserializableError); + }); + + it('should refuse to decode references and classes it does not know', () => { + expect(() => decode({ $r: 0 }, registry)).toThrow(/Invalid serialized reference/); + expect(() => decode({ $c: 'Unknown', p: {} }, registry)).toThrow(/Unknown class/); + }); + + it('should refuse to build a registry with two different classes of the same name', () => { + const a = { Point }; + const b = { Point: class Point {} }; + expect(() => buildClassRegistry(a, b)).toThrow(/Ambiguous/); + }); + + it('should round-trip imported FSH documents exactly', () => { + const doc = importSingleText( + ` + Alias: $sct = http://snomed.info/sct + Profile: MyPatient + Parent: Patient + * name 1..* MS + * gender = #female + RuleSet: Params(path) + * {path} MS + Instance: Pat + InstanceOf: MyPatient + * name.family = "Smith" + ValueSet: RegexVS + * include codes from system http://example.org where display regex /^A.*/ + `, + 'doc.fsh' + ); + const reg = definitionRegistry(); + const result = decode(JSON.parse(JSON.stringify(encode(doc, reg))), reg); + expect(result).toEqual(doc); + expect(result.constructor).toBe(doc.constructor); + expect(result.profiles.get('MyPatient').constructor).toBe( + doc.profiles.get('MyPatient').constructor + ); + expect(hashValue(result, reg)).toBe(hashValue(doc, reg)); + const filter = result.valueSets.get('RegexVS').rules[0].filters[0]; + expect(filter.value).toBeInstanceOf(RegExp); + expect(filter.value.source).toBe('^A.*'); + }); + + it('should replace the own properties of an object while keeping its identity', () => { + const target: any = new Point(1, 2); + const ref = target; + replaceOwnProperties(target, { y: 3, z: 4 }); + expect(ref).toBe(target); + expect(Object.keys(target)).toEqual(['y', 'z']); + expect(target.sum()).toBeNaN(); + }); +});