Skip to content

Commit

Permalink
Debug log stacks from unexpected errors (FHIR#1331)
Browse files Browse the repository at this point in the history 
* Fix bug that tried to log sourceInfo from the wrong place

* Whenever we log an arbitrary error.message, debug log its stack

* Support --log-level for init and update-dependencies commands

* Update README w/ new commandline usage
  • Loading branch information
@cmoesel
cmoesel authored Aug 28, 2023
1 parent a989e88 commit 1666d88
Show file tree
Hide file tree
Showing 14 changed files with 167 additions and 25 deletions.
12 changes: 6 additions & 6 deletions README.md
View file
Original file line number Diff line number Diff line change
Expand Up @@ -27,14 +27,14 @@ $ sushi help
Usage: sushi [options] [command]
Options:
-v, --version print SUSHI version
-h, --help display help for command
-v, --version print SUSHI version
-h, --help display help for command
Commands:
build [options] [path-to-fsh-project] build a SUSHI project
init initialize a SUSHI project
update-dependencies [path-to-fsh-project] update FHIR packages in project configuration
help [command] display help for command
build [options] [path-to-fsh-project] build a SUSHI project
init [options] initialize a SUSHI project
update-dependencies [options] [path-to-fsh-project] update FHIR packages in project configuration
help [command] display help for command
```

To build a SUSHI project, use the `build` command:
Expand Down
39 changes: 31 additions & 8 deletions src/app.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -38,6 +38,9 @@ const FSH_VERSION = '3.0.0-ballot';

function logUnexpectedError(e: Error) {
logger.error(`SUSHI encountered the following unexpected error: ${e.message}`);
if (e.stack) {
logger.debug(e.stack);
}
process.exit(1);
}

Expand Down Expand Up @@ -68,6 +71,7 @@ async function app() {
)
.option('-s, --snapshot', 'generate snapshot in Structure Definition output', false)
.action(async function (projectPath, options) {
setLogLevel(options);
await runBuild(projectPath, options, program.helpInformation()).catch(logUnexpectedError);
})
.on('--help', () => {
Expand Down Expand Up @@ -97,7 +101,14 @@ async function app() {
program
.command('init')
.description('initialize a SUSHI project')
.action(async function () {
.addOption(
new Option(
'-l, --log-level <level>',
'specify the level of log messages (default: "info")'
).choices(['error', 'warn', 'info', 'debug'])
)
.action(async function (options) {
setLogLevel(options);
await init().catch(logUnexpectedError);
process.exit(0);
});
Expand All @@ -106,7 +117,14 @@ async function app() {
.command('update-dependencies')
.description('update FHIR packages in project configuration')
.argument('[path-to-fsh-project]')
.action(async function (projectPath) {
.addOption(
new Option(
'-l, --log-level <level>',
'specify the level of log messages (default: "info")'
).choices(['error', 'warn', 'info', 'debug'])
)
.action(async function (projectPath, options) {
setLogLevel(options);
await runUpdateDependencies(projectPath).catch(logUnexpectedError);
process.exit(0);
})
Expand Down Expand Up @@ -137,12 +155,6 @@ async function runBuild(input: string, program: OptionValues, helpText: string)
process.exit(1);
}

// Set the log level. If no level is specified, logger defaults to info
if (program.logLevel != null) {
// program.logLevel has only valid log levels because the CLI sets the choices
logger.level = program.logLevel;
}

logger.info(`Running ${getVersion()}`);
logger.info('Arguments:');
if (program.logLevel) {
Expand Down Expand Up @@ -243,6 +255,9 @@ async function runBuild(input: string, program: OptionValues, helpText: string)
// If no errors have been logged yet, log this exception so the user knows why we're exiting
if (stats.numError === 0) {
logger.error(`An unexpected error occurred: ${e.message ?? e}`);
if (e.stack) {
logger.debug(e.stack);
}
}
process.exit(1);
}
Expand Down Expand Up @@ -310,6 +325,14 @@ function getVersion(): string {
return 'unknown';
}

function setLogLevel(options: OptionValues) {
// Set the log level. If no level is specified, logger defaults to info
if (options.logLevel != null) {
// options.logLevel has only valid log levels because the CLI sets the choices
logger.level = options.logLevel;
}
}

function printResults(pkg: Package, sushiVersions: any) {
// NOTE: These variables are creatively names to align well in the strings below while keeping prettier happy
const profileNum = pad(pkg.profiles.length.toString(), 13);
Expand Down
9 changes: 9 additions & 0 deletions src/export/CodeSystemExporter.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -111,6 +111,9 @@ export class CodeSystemExporter {
}
} catch (e) {
logger.error(e.message, rule.sourceInfo);
if (e.stack) {
logger.debug(e.stack);
}
}
});
resolveSoftIndexing(successfulRules);
Expand Down Expand Up @@ -147,6 +150,9 @@ export class CodeSystemExporter {
assignInstanceFromRawValue(codeSystem, rule, instanceExporter, this.fisher, originalErr);
} else {
logger.error(originalErr.message, rule.sourceInfo);
if (originalErr.stack) {
logger.debug(originalErr.stack);
}
}
}
}
Expand Down Expand Up @@ -246,6 +252,9 @@ export class CodeSystemExporter {
this.exportCodeSystem(cs);
} catch (e) {
logger.error(e.message, cs.sourceInfo);
if (e.stack) {
logger.debug(e.stack);
}
}
}
if (codeSystems.length > 0) {
Expand Down
17 changes: 16 additions & 1 deletion src/export/InstanceExporter.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -208,19 +208,31 @@ export class InstanceExporter implements Fishable {
const instanceToAssign = this.fishForFHIR(rule.rawValue);
if (instanceToAssign == null) {
logger.error(originalErr.message, rule.sourceInfo);
if (originalErr.stack) {
logger.debug(originalErr.stack);
}
} else {
try {
doRuleValidation(instanceToAssign);
} catch (instanceErr) {
if (instanceErr instanceof MismatchedTypeError) {
logger.error(originalErr.message, rule.sourceInfo);
if (originalErr.stack) {
logger.debug(originalErr.stack);
}
} else {
logger.error(instanceErr.message, rule.sourceInfo);
if (instanceErr.stack) {
logger.debug(instanceErr.stack);
}
}
}
}
} else {
logger.error(originalErr.message, rule.sourceInfo);
if (originalErr.stack) {
logger.debug(originalErr.stack);
}
}
}
});
Expand Down Expand Up @@ -852,7 +864,10 @@ export class InstanceExporter implements Fishable {
try {
this.exportInstance(instance);
} catch (e) {
logger.error(e.message, e.sourceInfo);
logger.error(e.message, instance.sourceInfo);
if (e.stack) {
logger.debug(e.stack);
}
}
}
this.warnOnInstanceOfCustomResource();
Expand Down
6 changes: 6 additions & 0 deletions src/export/MappingExporter.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -50,6 +50,9 @@ export class MappingExporter {
element.applyMapping(fshDefinition.id, rule.map, rule.comment, rule.language);
} catch (e) {
logger.error(e.message, rule.sourceInfo);
if (e.stack) {
logger.debug(e.stack);
}
}
} else {
logger.error(
Expand Down Expand Up @@ -131,6 +134,9 @@ export class MappingExporter {
this.exportMapping(mapping);
} catch (e) {
logger.error(e.message, mapping.sourceInfo);
if (e.stack) {
logger.debug(e.stack);
}
}
}
// The mappings on each Structure Definition should have a unique id
Expand Down
30 changes: 30 additions & 0 deletions src/export/StructureDefinitionExporter.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -738,6 +738,9 @@ export class StructureDefinitionExporter implements Fishable {
}
} catch (e) {
logger.error(e.message, rule.sourceInfo);
if (e.stack) {
logger.debug(e.stack);
}
}
continue;
}
Expand Down Expand Up @@ -848,6 +851,9 @@ export class StructureDefinitionExporter implements Fishable {
element.addSlice(item.name);
} catch (e) {
logger.error(e.message, rule.sourceInfo);
if (e.stack) {
logger.debug(e.stack);
}
}
});
}
Expand Down Expand Up @@ -926,6 +932,9 @@ export class StructureDefinitionExporter implements Fishable {
}
} catch (e) {
logger.error(e.message, rule.sourceInfo);
if (e.stack) {
logger.debug(e.stack);
}
}
} else {
logger.error(
Expand Down Expand Up @@ -961,13 +970,22 @@ export class StructureDefinitionExporter implements Fishable {
} catch (e) {
if (e instanceof MismatchedTypeError && originalErr != null) {
logger.error(originalErr.message, rule.sourceInfo);
if (originalErr.stack) {
logger.debug(originalErr.stack);
}
} else {
logger.error(e.message, rule.sourceInfo);
if (e.stack) {
logger.debug(e.stack);
}
}
}
} else {
if (originalErr != null) {
logger.error(originalErr.message, rule.sourceInfo);
if (originalErr.stack) {
logger.debug(originalErr.stack);
}
} else {
logger.error(`Could not find a resource named ${rule.value}`, rule.sourceInfo);
}
Expand Down Expand Up @@ -1020,11 +1038,17 @@ export class StructureDefinitionExporter implements Fishable {
const slice = element.getSlices().find(el => el.sliceName === item.name);
if (slice?.type[0]?.profile?.some(p => p === extension.url)) {
logger.warn(e.message, rule.sourceInfo);
if (e.stack) {
logger.debug(e.stack);
}
return;
}
}
// Otherwise it is a conflicting duplicate extension or some other error
logger.error(e.message, rule.sourceInfo);
if (e.stack) {
logger.debug(e.stack);
}
}
// check if we have used modifier extensions correctly
const isModifier = isModifierExtension(extension);
Expand Down Expand Up @@ -1061,6 +1085,9 @@ export class StructureDefinitionExporter implements Fishable {
// as inline extensions require further definition outside of the contains rule, so
// there is more likely to be conflict, and detecting such conflict is more difficult.
logger.error(e.message, rule.sourceInfo);
if (e.stack) {
logger.debug(e.stack);
}
}
}
});
Expand Down Expand Up @@ -1350,6 +1377,9 @@ export class StructureDefinitionExporter implements Fishable {
this.exportStructDef(sd);
} catch (e) {
logger.error(e.message, e.sourceInfo || sd.sourceInfo);
if (e.stack) {
logger.debug(e.stack);
}
}
});
this.warnOnNonConformantResourceDefinitions();
Expand Down
6 changes: 6 additions & 0 deletions src/export/ValueSetExporter.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -205,6 +205,9 @@ export class ValueSetExporter {
assignInstanceFromRawValue(valueSet, rule, instanceExporter, this.fisher, originalErr);
} else {
logger.error(originalErr.message, rule.sourceInfo);
if (originalErr.stack) {
logger.debug(originalErr.stack);
}
}
}
}
Expand Down Expand Up @@ -293,6 +296,9 @@ export class ValueSetExporter {
this.exportValueSet(valueSet);
} catch (e) {
logger.error(e.message, valueSet.sourceInfo);
if (e.stack) {
logger.debug(e.stack);
}
}
}
if (valueSets.length > 0) {
Expand Down
6 changes: 6 additions & 0 deletions src/fhirdefs/load.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -78,6 +78,9 @@ export function loadCustomResources(
continue;
}
logger.error(`Loading ${file} failed with the following error:\n${e.message}`);
if (e.stack) {
logger.debug(e.stack);
}
continue;
}
// All resources are added to the predefined map, so that this map can later be used to
Expand Down Expand Up @@ -125,5 +128,8 @@ export async function loadSupplementalFHIRPackage(
.then((def: FHIRDefinitions) => defs.addSupplementalFHIRDefinitions(fhirPackage, def))
.catch((e: Error) => {
logger.error(`Failed to load supplemental FHIR package ${fhirPackage}: ${e.message}`);
if (e.stack) {
logger.debug(e.stack);
}
});
}
9 changes: 9 additions & 0 deletions src/fhirtypes/common.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1513,6 +1513,9 @@ export function assignInstanceFromRawValue(
const instance = instanceExporter.fishForFHIR(rule.rawValue);
if (instance == null) {
logger.error(originalErr.message, rule.sourceInfo);
if (originalErr.stack) {
logger.debug(originalErr.stack);
}
} else {
try {
setPropertyOnDefinitionInstance(
Expand All @@ -1524,8 +1527,14 @@ export function assignInstanceFromRawValue(
} catch (instanceErr) {
if (instanceErr instanceof MismatchedTypeError) {
logger.error(originalErr.message, rule.sourceInfo);
if (originalErr.stack) {
logger.debug(originalErr.stack);
}
} else {
logger.error(instanceErr.message, rule.sourceInfo);
if (instanceErr.stack) {
logger.debug(instanceErr.stack);
}
}
}
}
Expand Down
6 changes: 6 additions & 0 deletions src/import/FSHImporter.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -247,6 +247,9 @@ export class FSHImporter extends FSHVisitor {
} catch (err) {
const sourceInfo = { location: this.extractStartStop(e), file: this.currentFile };
logger.error(`Error in parsing: ${err.message}`, sourceInfo);
if (err.stack) {
logger.debug(err.stack);
}
}
});
}
Expand Down Expand Up @@ -445,6 +448,9 @@ export class FSHImporter extends FSHVisitor {
this.currentDoc.instances.set(instance.name, instance);
} catch (e) {
logger.error(e.message, instance.sourceInfo);
if (e.stack) {
logger.debug(e.stack);
}
}
}
}
Expand Down
3 changes: 3 additions & 0 deletions src/import/importConfiguration.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -79,6 +79,9 @@ export function importConfiguration(yaml: YAMLConfiguration | string, file: stri
parsed = YAML.parse(yaml);
} catch (e) {
logger.error(`Error parsing configuration: ${e.message}.`, { file });
if (e.stack) {
logger.debug(e.stack);
}
throw new Error('Invalid configuration YAML');
}
if (typeof parsed !== 'object' || parsed === null) {
Expand Down
Loading

0 comments on commit 1666d88

Please sign in to comment.