search

hapifhir / hapi-fhir

🔥 HAPI FHIR - Java API for HL7 FHIR Clients and Servers
http://hapifhir.io
Apache License 2.0
2.05k stars 1.33k forks source link

Duplicate Entry for key 'PRIMARY' / Could not Execute Batch on HFJ_RESOURCE table #2202

Open neilmatthewlott opened 3 years ago

neilmatthewlott commented 3 years ago

Describe the bug When posting an observation (note this is repeatable when it happens but we are not sure how this happens in the first place).

curl -X POST 'https://XXXXXXX:8243/fhir/v2.0.0/Observation' \ -H 'Content-Type: application/json+fhir' \ -H 'authorization: Bearer 59aa1ae7-e06f-318a-9f9c-b8d62c139a88' \ -H 'SSOID: SYSTEM_USER' \ --data-raw '{ "resourceType": "Observation", "id": "115", "meta": { "versionId": "1", "lastUpdated": "2020-06-09T16:34:00.000+00:00", "source": "#nDYIQioa1mgPJo4t" }, "status": "final", "category": [ { "coding": [ { "system": "http://terminology.hl7.org/CodeSystem/observation-category", "code": "vital-signs", "display": "Vital Signs" } ] } ], "code": { "coding": [ { "system": "http://snomed.info/sct", "code": "33747003", "display": "Glucose measurement, blood (procedure)" } ] }, "effectiveDateTime": "2020-11-30T21:15:30.890Z", "device": { "type": "Device", "identifier": { "system": "http://intellicentrics.com/devices/vcloud/glucose/serialnumber", "value": "19H391414" }, "display": "vcloud Glucose Meter" }, "component": [ { "code": { "coding": [ { "system": "http://snomed.info/sct", "code": "33747003", "display": "Glucose measurement, blood (procedure)" } ] }, "valueQuantity": { "value": 45, "unit": "mmol/l", "system": "http://unitsofmeasure.org", "code": "mmol/L" } } ] }'

We are seeing the following error

2020-11-30 22:20:35.775 ERROR 1 --- [nio-8080-exec-9] o.h.engine.jdbc.spi.SqlExceptionHelper : Duplicate entry '2585' for key 'PRIMARY' 2020-11-30 22:20:35.791 ERROR 1 --- [nio-8080-exec-9] c.u.f.r.s.i.ExceptionHandlingInterceptor : Failure during REST processing

ca.uhn.fhir.rest.server.exceptions.InternalErrorException: Failed to call access method: org.springframework.dao.DataIntegrityViolationException: could not execute batch; SQL [insert into HFJ_RESOURCE (RES_DELETED_AT, RES_VERSION, FORCED_ID_PID, HAS_TAGS, RES_PUBLISHED, RES_UPDATED, SP_HAS_LINKS, HASH_SHA256, SP_INDEX_STATUS, RES_LANGUAGE, SP_CMPSTR_UNIQ_PRESENT, SP_COORDS_PRESENT, SP_DATE_PRESENT, SP_NUMBER_PRESENT, SP_QUANTITY_PRESENT, SP_STRING_PRESENT, SP_TOKEN_PRESENT, SP_URI_PRESENT, RES_PROFILE, RES_TYPE, RES_VER, RES_ID) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)]; constraint [PRIMARY]; nested exception is org.hibernate.exception.ConstraintViolationException: could not execute batch at ca.uhn.fhir.rest.server.method.BaseMethodBinding.invokeServerMethod(BaseMethodBinding.java:244) ~[hapi-fhir-server-4.1.0.jar!/:na]

Expected behavior Not seeing this error

Screenshots Fuil log is attached

Environment (please complete the following information):

2020-11-30-HAPI-FHIR-LOG.txt

Additional context application.properties:

Spring DATASOURCE (DataSourceAutoConfiguration & DataSourceProperties)

spring.datasource.url=${DATASOURCE_URL:jdbc:mysql://localhost:3306/fhir_server?useSSL=false&serverTimezone=UTC} spring.datasource.username=${DATASOURCE_USERNAME:root} spring.datasource.password=${DATASOURCE_PASSWORD:root} spring.datasource.driver-class-name=${DATASOURCE_DRIVER:com.mysql.cj.jdbc.Driver} spring.datasource.hikari.maximum-pool-size=${DATASOURCE_MAX_POOL_SIZE:5} spring.jpa.properties.hibernate.dialect=${DATASOURCE_HIBERNATE_DIALECT:org.hibernate.dialect.MySQL5InnoDBDialect} spring.jpa.hibernate.ddl-auto=${DATASOURCE_HIBERNATE_DDL_AUTO:update} spring.jpa.show-sql=${DATASOURCE_SHOW_SQL:true}

properties needed so that Spring JPA does not add underscore to @Column attribute value in the entity

spring.jpa.hibernate.naming.implicit-strategy=org.hibernate.boot.model.naming.ImplicitNamingStrategyLegacyJpaImpl spring.jpa.hibernate.naming.physical-strategy=org.hibernate.boot.model.naming.PhysicalNamingStrategyStandardImpl

HAPI FHIR Spring DATASOURCE configuration

spring.jpa.properties.hibernate.jdbc.batch_size=20 spring.jpa.properties.hibernate.order_updates=true spring.jpa.properties.hibernate.order_inserts=true spring.jpa.properties.hibernate.cache.use_query_cache=false spring.jpa.properties.hibernate.cache.use_second_level_cache=false spring.jpa.properties.hibernate.cache.use_structured_entries=false spring.jpa.properties.hibernate.cache.use_minimal_puts=false spring.jpa.properties.hibernate.search.default.directory_provider=filesystem spring.jpa.properties.hibernate.search.default.indexBase=target/lucenefiles spring.jpa.properties.hibernate.search.lucene_version=LUCENE_CURRENT spring.jpa.properties.hibernate.search.model_mapping=ca.uhn.fhir.jpa.search.LuceneSearchMappingFactory

HAPI FHIR configuration

hapi.fhir.version=r4 hapi.fhir.server.path=/fhir/* hapi.fhir.rest.server-name=sec3ure-fhir-server-jpa hapi.fhir.rest.server-version=1.0.0 hapi.fhir.rest.implementation-description=Sec3ure FHIR Server hapi.fhir.rest.default-response-encoding=json hapi.fhir.rest.e-tag-support=enabled hapi.fhir.rest.default-pretty-print=true hapi.fhir.validation.enabled=true hapi.fhir.validation.request-only=true hapi.fhir.jpa.scheduling-disabled=true hapi.fhir.jpa.subscription-enabled=true hapi.fhir.jpa.resource-encoding=JSON hapi.fhir.enable_index_missing_fields=ENABLED

***Other observations

This was also observed a month ago in the HFJ_SEARCH table

2020-11-10 00:47:04.140 INFO 1 --- [search_coord_23] o.h.e.j.b.internal.AbstractBatchImpl : HHH000010: On release of batch it still contained JDBC statements 2020-11-10 00:47:04.140 ERROR 1 --- [search_coord_23] o.h.e.jdbc.batch.internal.BatchingBatch : HHH000315: Exception executing batch [java.sql.BatchUpdateException: Duplicate entry '6130' for key 'PRIMARY'], SQL: insert into HFJ_SEARCH (CREATED, SEARCH_DELETED, EXPIRY_OR_NULL, FAILURE_CODE, FAILURE_MESSAGE, LAST_UPDATED_HIGH, LAST_UPDATED_LOW, NUM_BLOCKED, NUM_FOUND, PREFERRED_PAGE_SIZE, RESOURCE_ID, RESOURCE_TYPE, SEARCH_LAST_RETURNED, SEARCH_PARAM_MAP, SEARCH_QUERY_STRING, SEARCH_QUERY_STRING_HASH, SEARCH_TYPE, SEARCH_STATUS, TOTAL_COUNT, SEARCH_UUID, OPTLOCK_VERSION, PID) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?,?, ?, ?, ?, ?, ?, ?, ?) 2020-11-10 00:47:04.140 WARN 1 --- [search_coord_23] o.h.engine.jdbc.spi.SqlExceptionHelper : SQL Error: 1062, SQLState: 23000 2020-11-10 00:47:04.140 ERROR 1 --- [search_coord_23] o.h.engine.jdbc.spi.SqlExceptionHelper : Duplicate entry '6130' for key 'PRIMARY' 2020-11-10 00:47:04.144 ERROR 1 --- [search_coord_23] c.u.f.j.search.SearchCoordinatorSvcImpl : Failed during search loading after 7ms

jamesagnew commented 3 years ago

That is a fairly old version of HAPI FHIR, is this reproducible with the current release (5.2.0)?

neilmatthewlott commented 3 years ago

Hi James, I'm not sure, but we are in Production in the moment and it happens sporadically and it would be a big effort to upgrade.

I'm curious if we switched over to UUIDs to solve this problem if it could work?

daoConfig.setResourceServerIdStrategy(DaoConfig.IdStrategyEnum.UUID);

However given this code

https://github.com/jamesagnew/hapi-fhir/blob/283834ed1d140e33cbe6e846e3fd836439b2777d/hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/dao/BaseHapiFhirResourceDao.java#L241 if (myDaoConfig.getResourceServerIdStrategy() == DaoConfig.IdStrategyEnum.UUID) { theResource.setId(UUID.randomUUID().toString()); theResource.setUserData(JpaConstants.RESOURCE_ID_SERVER_ASSIGNED, Boolean.TRUE); }

Generates a UUID of this

[09261bfd-458d-4074-b56b-74ab448ca2ff]

How is this UUID supposed to be put in a table with a bigInt(20) for a id column?

CREATE TABLE HFJ_RESOURCE ( RES_ID bigint(20) NOT NULL,

Thanks,

Neil

neilmatthewlott commented 3 years ago

Hi James -- any word on a workaround for the above we could possibly use? Best, Neil

jamesagnew commented 3 years ago

No, unfortunately switching to UUIDs would likely not help, as there would still be a BIGINT sequence generated by table.

You could certainly try playing with the sequence generator settings in hibernate, or checking if the hibernate changelogs indicate any related fixes from 5.4.6 (the version used in HAPI FHIR 4.1.0) to 5.4.22 (the version used in current Master).

neilmatthewlott commented 3 years ago

James -- would you clarify -- assuming I'm upgrading from 4.1.0 to 5.2.0 and I want to set these properties -- what are the steps I need to take in order to make it work as it seems like I need to migrate all the bigInt columns (of which tables?) to a string? Will it work to leave the existing ids in those columns?

            daoConfig.setResourceClientIdStrategy(DaoConfig.ClientIdStrategyEnum.ANY);
            daoConfig.setResourceServerIdStrategy(DaoConfig.IdStrategyEnum.UUID);

Hi James, I'm not sure, but we are in Production in the moment and it happens sporadically and it would be a big effort to upgrade.

I'm curious if we switched over to UUIDs to solve this problem if it could work?

daoConfig.setResourceServerIdStrategy(DaoConfig.IdStrategyEnum.UUID);

However given this code

https://github.com/jamesagnew/hapi-fhir/blob/283834ed1d140e33cbe6e846e3fd836439b2777d/hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/dao/BaseHapiFhirResourceDao.java#L241 if (myDaoConfig.getResourceServerIdStrategy() == DaoConfig.IdStrategyEnum.UUID) { theResource.setId(UUID.randomUUID().toString()); theResource.setUserData(JpaConstants.RESOURCE_ID_SERVER_ASSIGNED, Boolean.TRUE); }

Generates a UUID of this

[09261bfd-458d-4074-b56b-74ab448ca2ff]

How is this UUID supposed to be put in a table with a bigInt(20) for a id column?

CREATE TABLE HFJ_RESOURCE ( RES_ID bigint(20) NOT NULL,

Thanks,

Neil