FHIR Chat · SnapshotGeneratingValidationSupport gives NPE · hapi

Stream: hapi

Topic: SnapshotGeneratingValidationSupport gives NPE

Morten Ernebjerg (Jun 28 2021 at 14:52):

I am using the HAPI SnapshotGeneratingValidationSupport and am getting an NPE when I try to use it for the profile https://www.netzwerk-universitaetsmedizin.de/fhir/StructureDefinition/chronic-lung-diseases.

This profile defines a slice on Coding.code.coding with a required binding to a ValueSet containing a few explicitly listed (German) ICD-codes. However, it is a re-profiling of the base profile https://www.netzwerk-universitaetsmedizin.de/fhir/StructureDefinition/gecco-base-condition which, in turn, also defines a slice on Coding.code with a required binding to a ValueSet containing all (german) ICD codes.

Possibly, it is this combination that causes problems. What I observe is that the validation codes tries to expand the full ICD-10 ValueSets and fails but nonetheless assumes that it succeeded, causing an NPE. The first bit of the stack trace I see at the top level is this:

Failed to generate snapshot
ca.uhn.fhir.rest.server.exceptions.InternalErrorException: Failed to generate snapshot
    at org.hl7.fhir.common.hapi.validation.support.SnapshotGeneratingValidationSupport.generateSnapshot(SnapshotGeneratingValidationSupport.java:134)
    at org.hl7.fhir.common.hapi.validation.support.ValidationSupportChain.generateSnapshot(ValidationSupportChain.java:95)
    at org.hl7.fhir.common.hapi.validation.validator.VersionSpecificWorkerContextWrapper.lambda$new$0(VersionSpecificWorkerContextWrapper.java:100)

Through some longwinded debugging, I managed to dig a bit deeper and find the following chain of events:

1. SnapshotGeneratingValidationSupport#generateSnapshot is called with the input SD https://www.netzwerk-universitaetsmedizin.de/fhir/StructureDefinition/chronic-lung-diseases
2. This triggers a call to ProfileUtilities#generateSnapshot with the parameters base = SD for https://www.netzwerk-universitaetsmedizin.de/fhir/StructureDefinition/gecco-base-condition and derived = SD for https://www.netzwerk-universitaetsmedizin.de/fhir/StructureDefinition/chronic-lung-diseases
3. This eventually triggers a call to ProfileUtilities#updateFromDefinition with parameters dest = "Condition.code.coding:icd10-gm" , source = "Condition.code.coding:icd10-gm", and srcSD = SD for https://www.netzwerk-universitaetsmedizin.de/fhir/StructureDefinition/gecco-base-condition
4. In the line ValueSetExpansionOutcome expBase = context.expandVS(baseVs, true, false);, expBase is set to null since no validation support can expand this (baseVs is the full ICD-10 ValueSet)
5. Nonetheless, two lines further down, the call expBase.getValueset()is made, causing a null pointer exception.

Is this a known issue? (@Julian Sass This is a GECCO profile, maybe have you seen smt. like this before?)

Julian Sass (Jun 29 2021 at 10:09):

Morten Ernebjerg said:

Is this a known issue? (Julian Sass This is a GECCO profile, maybe have you seen smt. like this before?)

No, also first time I'm seeing this.

Morten Ernebjerg (Jun 29 2021 at 14:33):

A similar (but possibly different) error also happens with the latest command-line validator (well, actually the validator seems to complete but output errors along the way). I tested it using this Condition resource (which also provokes the error in my code) and pulling in the latest version of the de.gecco package. (I wonder if the differences in the details may be due to the fact that the command-line validator uses a terminology server, but my code not):

> java -jar validator/validator_cli.jar -version 4.0.1 -ig de.gecco#1.0.4 test.json
FHIR Validation tool Version 5.4.6 (Git# aa0b7bc056c6). Built 2021-06-24T19:45:14.861Z (4 days old)
  Java:   16.0.1 from /Library/Java/JavaVirtualMachines/adoptopenjdk-16.jdk/Contents/Home on x86_64 (64bit). 4096MB available
  Paths:  Current = [REDACTED], Package Cache = [REDACTED]/.fhir/packages
  Params: -version 4.0.1 -ig de.gecco#1.0.4 test.json
Loading
  Load FHIR v4.0 from hl7.fhir.r4.core#4.0.1 - 4575 resources (00:04.0261)
  Load hl7.terminology#2.0.0 - 3749 resources (00:00.0908)
  Terminology server http://tx.fhir.org - Version 1.9.378 (00:01.0816)
  Load de.medizininformatikinitiative.kerndatensatz.meta#1.0.3 - 2 resources (00:00.0065)
  Load hl7.fhir.uv.ips#1.0.0 - 82 resources (00:00.0023)
  Load de.medizininformatikinitiative.kerndatensatz.medikation#1.0.8 - 9 resources (00:00.0105)
  Load de.basisprofil.r4#0.9.13 - 128 resources (00:00.0131)
  Load de.medizininformatikinitiative.kerndatensatz.prozedur#1.0.7 - 15 resources (00:06.0046)
  Load de.medizininformatikinitiative.kerndatensatz.laborbefund#1.0.5 - 10 resources (00:00.0017)
  Load kbv.basis#1.1.3 - 68 resources (00:00.0063)
  Load de.medizininformatikinitiative.kerndatensatz.diagnose#1.0.4 - 12 resources (00:03.0793)
  Load de.gecco#1.0.4 - 134 resources (00:00.0122)
  Get set... Previous POST attempt returned HTTP<422> from url -> http://tx.fhir.org/r4/ValueSet/$expand?_limit=1000&_incomplete=true.
Unable to generate snapshot for cardiovascular-diseases from gecco-base-condition because Profile CardiovascularDiseases (https://www.netzwerk-universitaetsmedizin.de/fhir/StructureDefinition/cardiovascular-diseases), element Cardiovascular Diseases.coding.Condition.code.coding. Error generating snapshot: Binding https://www.netzwerk-universitaetsmedizin.de/fhir/ValueSet/cardiovascular-diseases is not a subset of binding https://www.medizininformatik-initiative.de/fhir/core/modul-diagnose/ValueSet/diagnoses-sct
org.hl7.fhir.exceptions.DefinitionException: Profile CardiovascularDiseases (https://www.netzwerk-universitaetsmedizin.de/fhir/StructureDefinition/cardiovascular-diseases), element Cardiovascular Diseases.coding.Condition.code.coding. Error generating snapshot: Binding https://www.netzwerk-universitaetsmedizin.de/fhir/ValueSet/cardiovascular-diseases is not a subset of binding https://www.medizininformatik-initiative.de/fhir/core/modul-diagnose/ValueSet/diagnoses-sct
        at org.hl7.fhir.r5.context.SimpleWorkerContext.generateSnapshot(SimpleWorkerContext.java:786)
        at org.hl7.fhir.r5.context.SimpleWorkerContext.generateSnapshot(SimpleWorkerContext.java:753)
        at org.hl7.fhir.r5.context.SimpleWorkerContext.allStructures(SimpleWorkerContext.java:636)
        at org.hl7.fhir.validation.ValidationEngine.prepare(ValidationEngine.java:502)
        at org.hl7.fhir.validation.cli.services.ValidationService.initializeValidator(ValidationService.java:257)
        at org.hl7.fhir.validation.cli.services.ValidationService.initializeValidator(ValidationService.java:212)
        at org.hl7.fhir.validation.ValidatorCli.doValidation(ValidatorCli.java:203)
        at org.hl7.fhir.validation.ValidatorCli.main(ValidatorCli.java:159)
[a number of similar errors for other binding follow]

@Mark Iantorno Do you happen to have an idea what might be happening?

Mark Iantorno (Jun 29 2021 at 14:36):

So, you're saying that when you run it with the core validator, you expect no errors, but you are getting one error?

Mark Iantorno (Jun 29 2021 at 14:36):

Forget about the HAPI validation for a second, let's just deal with the core validator first.

Mark Iantorno (Jun 29 2021 at 14:43):

Let me take a closer look

Morten Ernebjerg (Jun 29 2021 at 18:25):

Thanks! The resource should be valid. Indeed, that is also what the validator outputs, i.e. it does not crash. But it does output all these stacktraces on the way, which makes it look as if an error is occurring under the hood. And judging by the stacktrace, that error might also be related to the one I'm seing in HAPI (snapshot generation).

Mark Iantorno (Jun 29 2021 at 18:26):

it most likely is being caused by the core validator if it is happening in both instances

Mark Iantorno (Jun 29 2021 at 18:26):

HAPI does eventually call the core validator in most cases

Morten Ernebjerg (Jun 29 2021 at 18:28):

Right, my debugging (above) also seems to indicate that it happens in the core, if I read it right (BTW to clarify: the HAPI validator does crash, the command-line one does not)

Grahame Grieve (Jun 29 2021 at 18:32):

well, is the validator right?

Mark Iantorno (Jun 29 2021 at 18:32):

If it bubles up an Error to hapi, hapi will most likely just stop, so this all makes sense

Mark Iantorno (Jun 29 2021 at 18:33):

Which is why I said not to worry about HAPI, and only focus on the core validator

Morten Ernebjerg (Jun 30 2021 at 06:38):

I have to correct steps 4 and 5 of the initial description (above :point_up:) of the error in see in my code. The NPE actually flies inside HAPI code, specifically in the expandVS method of VersionSpecificWorkerContextWrapper (around line 266).:

IValidationSupport.ValueSetExpansionOutcome expanded = myValidationSupportContext.getRootValidationSupport().expandValueSet(myValidationSupportContext, null, convertedSource);

org.hl7.fhir.r5.model.ValueSet convertedResult = null;
if (expanded.getValueSet() != null) {
    ...

With the input I describe above, myValidationSupportContext.getRootValidationSupport() returns a ValidationSupportChain instance. Calling expandValueSet on that returns null (no support in chain can expand the ICD-10 VS), so the variable expanded is null leading to the NPE in the if-check two lines below.

Mark Iantorno (Jun 30 2021 at 12:13):

Yeah, the validation chain in HAPI is getting a null returned value because the core is throwing an error then returning null. This has nothing to do with HAPI and we should stop looking at HAPI altogether

Mark Iantorno (Jun 30 2021 at 12:13):

I'm just eating breakfast now. I'm going to dedicate a couple hours this morning to look at it starting at 9.

Morten Ernebjerg (Jun 30 2021 at 12:19):

:+1:

Mark Iantorno (Jun 30 2021 at 13:12):

Alright, here's the full output I get...similar to what you encountered:
stacktrace.txt

Mark Iantorno (Jun 30 2021 at 13:13):

So, it's reproducible on the latest

Mark Iantorno (Jun 30 2021 at 13:13):

good start

Mark Iantorno (Jun 30 2021 at 13:28):

Well, this is strange.

Mark Iantorno (Jun 30 2021 at 13:28):

When I actually create the test case within the validator with all the provided data, I get this output:

Mark Iantorno (Jun 30 2021 at 13:28):

---- gecco-profile-slicing ----------------------------------------------------------------
** Core:
SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/home/mark/.m2/repository/org/slf4j/slf4j-simple/1.7.28/slf4j-simple-1.7.28.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/home/mark/.m2/repository/ch/qos/logback/logback-classic/1.2.3/logback-classic-1.2.3.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
SLF4J: Actual binding is of type [org.slf4j.impl.SimpleLoggerFactory]
  Load de.medizininformatikinitiative.kerndatensatz.meta#1.0.3 - 2 resources (00:05.0432)
  Load hl7.fhir.uv.ips#1.0.0 - 82 resources (00:00.0012)
  Load de.medizininformatikinitiative.kerndatensatz.medikation#1.0.8 - 9 resources (00:00.0119)
  Load de.basisprofil.r4#0.9.13 - 128 resources (00:00.0142)
  Load de.medizininformatikinitiative.kerndatensatz.prozedur#1.0.7 - 15 resources (00:05.0273)
  Load de.medizininformatikinitiative.kerndatensatz.laborbefund#1.0.5 - 10 resources (00:00.0014)
  Load kbv.basis#1.1.3 - 68 resources (00:00.0062)
  Load de.medizininformatikinitiative.kerndatensatz.diagnose#1.0.4 - 12 resources (00:04.0884)
  Load de.gecco#1.0.4 - 134 resources (00:00.0140)
Start Validating (16464 to set up)
Unable to generate snapshot for https://www.netzwerk-universitaetsmedizin.de/fhir/StructureDefinition/chronic-lung-diseases: Profile ChronicLungDiseases (https://www.netzwerk-universitaetsmedizin.de/fhir/StructureDefinition/chronic-lung-diseases), element Chronic Lung Diseases.coding.Condition.code.coding. Error generating snapshot: Binding https://www.netzwerk-universitaetsmedizin.de/fhir/ValueSet/chronic-lung-diseases is not a subset of binding https://www.medizininformatik-initiative.de/fhir/core/modul-diagnose/ValueSet/diagnoses-sct
Times (ms): overall = 9403, tx = 1212, sd = 1, load = 5, fpe = 6
WARNING: Condition.category[0]: None of the codings provided are in the value set http://hl7.org/fhir/ValueSet/condition-category (http://hl7.org/fhir/ValueSet/condition-category), and a coding should come from this value set unless it has no suitable code (note that the validator cannot judge what is suitable) (codes = http://snomed.info/sct#418112009)

Mark Iantorno (Jun 30 2021 at 13:28):

Which is a pass

Mark Iantorno (Jun 30 2021 at 13:28):

only one warning

Mark Iantorno (Jun 30 2021 at 13:29):

no 422 timeouts

Grahame Grieve (Jun 30 2021 at 19:28):

you still get the same error, just no satck dump. No one has addressed the question of whether the error is correct or not

Morten Ernebjerg (Jul 02 2021 at 08:42):

@Grahame Grieve I had a deeper look a the look the snapshot generation errors logged in the command line validator output I posted above (third msg. in this thread), i.e. this:

Unable to generate snapshot for cardiovascular-diseases from gecco-base-condition because Profile CardiovascularDiseases (https://www.netzwerk-universitaetsmedizin.de/fhir/StructureDefinition/cardiovascular-diseases), element Cardiovascular Diseases.coding.Condition.code.coding. Error generating snapshot: Binding https://www.netzwerk-universitaetsmedizin.de/fhir/ValueSet/cardiovascular-diseases is not a subset of binding https://www.medizininformatik-initiative.de/fhir/core/modul-diagnose/ValueSet/diagnoses-sct

If I understood everything correctly, it seems this error is not correct , i.e. the new binding is indeed a subset of the old one. The profile https://www.netzwerk-universitaetsmedizin.de/fhir/StructureDefinition/cardiovascular-diseases

• is a re-profiling of https://www.netzwerk-universitaetsmedizin.de/fhir/StructureDefinition/gecco-base-condition
• which is turn is a re-profiling of https://www.medizininformatik-initiative.de/fhir/core/modul-diagnose/StructureDefinition/Diagnose

The profile at the bottom of the hierarchy (".../Diagnose") defines a slicing of Condition.code.coding. with the a pattern-discriminator on the path $this. A least one slice must be present. The sct-slice has patternCoding set to "http://snomed.info/sct" and also has a required binding to a subset of SNOMED given by the value set https://www.medizininformatik-initiative.de/fhir/core/modul-diagnose/ValueSet/diagnoses-sct. This value set contains all terms that have a "is-a" relationship with either "Situation with explicit context" (243796009), "Event" (272379006), or "Clinical finding" (404684003).

The profile at the top of the hierarchy (".../cardiovascular-diseases") overrides the binding for the sct-slice of Condition.code.coding, replacing it with a required binding to the value set https://www.netzwerk-universitaetsmedizin.de/fhir/ValueSet/cardiovascular-diseases .The latter contains all codes with an is-a relation to "Disorder of cardiovascular system (disorder)" (49601007) and contains a number of SNOMED disorder terms. I checked all the terms in this value set and they are indeed all connected to either "Clinical finding" or "Situation with explicit context" through parent-links. Hence, the new VS does seem to be subset of the VS bound in the base profile. @Julian Sass Was this ensured by construction in this and other Conditions profiles from GECCO?

Julian Sass (Jul 02 2021 at 10:30):

Morten Ernebjerg said:

Julian Sass Was this ensured by construction in this and other Conditions profiles from GECCO?

Yes, the concepts in the derived profile are all subsumed by the concepts in the parent profile.

Morten Ernebjerg (Jul 07 2021 at 11:29):

Hi @Mark Iantorno, was there any conclusion to this?

Mark Iantorno (Jul 07 2021 at 12:55):

I was working on other things. I will get back on this, this afternoon

Morten Ernebjerg (Jul 07 2021 at 13:36):

Great, thanks! - let me know if you need more info etc.

Mark Iantorno (Jul 09 2021 at 15:44):

So, couple things to keep in mind here: 1. I have very little knowledge about or experience with slicing. 2. I haven't really touched this part of the validator before.

Mark Iantorno (Jul 09 2021 at 15:44):

So I'm going to ask a bunch of dumb questions as I'm going through this.

Mark Iantorno (Jul 09 2021 at 15:45):

You said: "However, it is a re-profiling of the base profile https://www.netzwerk-universitaetsmedizin.de/fhir/StructureDefinition/gecco-base-condition which, in turn, also defines a slice on Coding.code with a required binding to a ValueSet containing all (german) ICD codes."

Mark Iantorno (Jul 09 2021 at 15:47):

Where in the JSON is that defined? I only see 3 sliceNames? and they don't appear to point to a set of all german ICD codes

Mark Iantorno (Jul 09 2021 at 15:47):

I see slices for verification status and uncertainty of presence

Mark Iantorno (Jul 09 2021 at 15:47):

@Morten Ernebjerg

Mark Iantorno (Jul 09 2021 at 15:49):

What timezone are you in Morten, can we have a quick call at some point

Julian Sass (Jul 10 2021 at 10:51):

Hi @Mark Iantorno thanks for looking into this.
The profile https://www.netzwerk-universitaetsmedizin.de/fhir/StructureDefinition/gecco-base-condition again is a re-profiling. The base where the slices on Condition.code.coding are defined is https://www.medizininformatik-initiative.de/fhir/core/modul-diagnose/StructureDefinition/Diagnose. Here in the diff is e.g. the Condition.code.coding:icd10-gm slice with a required binding to the ValueSet containing all German ICD Codes.

Morten Ernebjerg (Jul 10 2021 at 11:40):

Hi @Mark Iantorno, I'm on central European time. Would be happy to talk, feel free to PM me. Mondays looks good, but I will be away on vacation starting Tuesday late afternoon.

Morten Ernebjerg (Jul 12 2021 at 15:21):

@Rene Lebherz FYI

Morten Ernebjerg (Aug 02 2021 at 08:37):

Hi @Mark Iantorno, any updates on this?

Mark Iantorno (Aug 03 2021 at 12:40):

Grahame has requested that this wait until he returns

Morten Ernebjerg (Aug 03 2021 at 12:44):

OK, thanks for the update!

Last updated: Apr 12 2022 at 19:14 UTC