Mixed results on importing via REST API

[debakkerb]

I've reported this problem already, but we keep running into it. It's very unpredictable, but quite often we run into the following problem when importing a file with data:

Caused by: java.lang.RuntimeException: 30,000 milliseconds timeout on connection http-outgoing-46 [ACTIVE]
	at org.springframework.data.elasticsearch.client.elc.ElasticsearchExceptionTranslator.translateException(ElasticsearchExceptionTranslator.java:63)
	... 46 common frames omitted
Caused by: java.net.SocketTimeoutException: 30,000 milliseconds timeout on connection http-outgoing-46 [ACTIVE]
	at org.elasticsearch.client.RestClient.extractAndWrapCause(RestClient.java:915)
	at org.elasticsearch.client.RestClient.performRequest(RestClient.java:300)
	at org.elasticsearch.client.RestClient.performRequest(RestClient.java:288)
	at co.elastic.clients.transport.rest_client.RestClientHttpClient.performRequest(RestClientHttpClient.java:91)
	at co.elastic.clients.transport.ElasticsearchTransportBase.performRequest(ElasticsearchTransportBase.java:144)
	at co.elastic.clients.elasticsearch.ElasticsearchClient.bulk(ElasticsearchClient.java:337)
	at org.springframework.data.elasticsearch.client.elc.ElasticsearchTemplate.lambda$doBulkOperation$11(ElasticsearchTemplate.java:296)
	at org.springframework.data.elasticsearch.client.elc.ElasticsearchTemplate.execute(ElasticsearchTemplate.java:633)
	... 45 common frames omitted
Caused by: java.net.SocketTimeoutException: 30,000 milliseconds timeout on connection http-outgoing-46 [ACTIVE]
	at org.apache.http.nio.protocol.HttpAsyncRequestExecutor.timeout(HttpAsyncRequestExecutor.java:387)
	at org.apache.http.impl.nio.client.InternalIODispatch.onTimeout(InternalIODispatch.java:98)
	at org.apache.http.impl.nio.client.InternalIODispatch.onTimeout(InternalIODispatch.java:40)
	at org.apache.http.impl.nio.reactor.AbstractIODispatch.timeout(AbstractIODispatch.java:175)
	at org.apache.http.impl.nio.reactor.BaseIOReactor.sessionTimedOut(BaseIOReactor.java:261)
	at org.apache.http.impl.nio.reactor.AbstractIOReactor.timeoutCheck(AbstractIOReactor.java:506)
	at org.apache.http.impl.nio.reactor.BaseIOReactor.validate(BaseIOReactor.java:211)
	at org.apache.http.impl.nio.reactor.AbstractIOReactor.execute(AbstractIOReactor.java:280)
	at org.apache.http.impl.nio.reactor.BaseIOReactor.execute(BaseIOReactor.java:104)
	at org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:591)
	... 1 common frames omitted

We've already changed the startup parameters to reduce the batch size, but apparently that doesn't seem to fix the issue at hand:

    "--add-opens",
    "java.base/java.util=ALL-UNNAMED",
    "-Djava.security.egd=file:/dev/./urandom",
    "-Djavax.net.ssl.trustStore=/truststore/cacerts",
    "--add-opens=java.base/java.lang=ALL-UNNAMED",
    "-cp",
    "@/app/jib-classpath-file",
    "org.snomed.snowstorm.SnowstormApplication",
    "-Xms8g",
    "-Xmx10g",
    "--server.servlet.context-path=/snowstorm",
    "--elasticsearch.api-key=$(es_apikey)",
    "--elasticsearch.urls=https://ES_URL",
    "--elasticsearch.index.prefix=${var.namespace}-",
    "--elasticvc.save.batch-size=2500",

On Friday an import failed and now I'm running into the issue again that the MAIN is locked, with no way of unlocking it.

{
  "path" : "MAIN",
  "state" : "UP_TO_DATE",
  "containsContent" : true,
  "locked" : true,
  "creation" : "2025-05-09T03:57:26.119Z",
  "base" : "2025-05-09T03:57:26.119Z",
  "head" : "2025-05-09T03:57:26.405Z",
  "creationTimestamp" : 1746763046119,
  "baseTimestamp" : 1746763046119,
  "headTimestamp" : 1746763046405,
  "userRoles" : [ ],
  "metadata" : {
    "internal" : { },
    "lock" : {
      "context" : {
        "description" : "Loading components from RF2 import.",
        "userId" : "anonymousUser"
      },
      "creationDate" : "2025-05-09T06:26:04Z"
    }
  },
  "versionsReplacedCounts" : {
    "ReferenceSetType" : 0
  },
  "globalUserRoles" : [ ]
}

What's also weird is that whenever I start an import, I poll the /imports/ endpoint every 60 seconds to check where we are and to inform users that the import has finished. On Friday (and this has happened in the past), it seems like the import job has suddenly vanished from Snowstorm. The Status goes from RUNNING to an empty string, meaning that the import can't be retrieved anymore. It doesn't look like snowstorm has restarted, which would explain the behaviour.

When I now check the status of the import, I'm getting the following response:

{
  "status" : "FAILED",
  "type" : "SNAPSHOT",
  "branchPath" : "MAIN",
  "internalRelease" : false,
  "moduleIds" : [ ],
  "createCodeSystemVersion" : false
}

[debakkerb]

When I try to unlock by calling the /branches/MAIN/actions/unlock endpoint, I get the following error:

There is a partial commit on this branch. Please wait for the commit to complete, or if you are sure that it has failed use the rollback partial commit admin function.

[kaicode]

The message you got back is my advice. If you are sure the commit has failed use the rollback partial commit admin function.
POST /admin/{branch}/actions/rollback-partial-commit
It's in swagger.

Snowstorm should only need about 4g of ram.
Make sure Elasticsearch also has 4g of ram (elasticsearch/config/jvm.options) and is using an SSD disk.
You could reduce that save batch size further if needed until you see reliable behaviour. When using the standard SSD disk in AWS the default batch size works unless importing something huge like the UK Edition snapshot.

[kaicode]

It's not possible for an import to disappear from the Snowstorm API unless either:

• Snowstorm was restarted
• or the import was never created in the first place:
  • Because either the job creation failed
  • Or there are two Snowstorms running and the other one created it in a load balancing situation

We have been using Snowstorm imports in production for more than 6 years. The import configuration is held in memory, it's not written to Elasticsearch so this is not a persistence issue.

[pgwilliams]

If the import job no longer existed (or existed in the memory of a different instance), I would expect to see a 404 returned, rather than an empty string in the status element:

I couldn't explain seeing an empty string for the status.

[debakkerb]

I had to park this for a couple of days and came back to it. I think the missing status was more linked to wonky error handling in my application, which should now be fixed (i.e. better messaging should be sent to Slack when an Import finishes).

However, the 30,000 milliseconds timeout is still occurring and it's even occurring now when I try to rollback a commit on the MAIN branch:

url := fmt.Sprintf("%s/admin/%s/actions/rollback-partial-commit", snowstormEndpoint, branchName)

I send a request to that endpoint, which works, but then I see this in the Snowstorm logs:

2025-05-16T05:31:00.359Z  INFO 1 --- [nio-8080-exec-6] o.s.s.core.data.services.SBranchService  : Found partial commit on MAIN at 1747315569761. Closing the branch at 1747315569761 and then rolling back.
2025-05-16T05:31:00.359Z  INFO 1 --- [nio-8080-exec-6] o.s.s.core.data.services.SBranchService  : Preparing to roll back commit 1747315569761 on MAIN.
2025-05-16T05:31:00.527Z  INFO 1 --- [nio-8080-exec-6] io.kaicode.elasticvc.api.BranchService   : Rolling back commit 1747315569761 on MAIN.
2025-05-16T05:31:00.765Z  INFO 1 --- [nio-8080-exec-6] io.kaicode.elasticvc.api.BranchService   : Deleting documents on MAIN started at 1747315569761.



2025-05-16T05:31:53.666Z ERROR 1 --- [nio-8080-exec-6] o.s.s.rest.config.RestControllerAdvice   : 30,000 milliseconds timeout on connection http-outgoing-135 [ACTIVE]

org.springframework.dao.DataAccessResourceFailureException: 30,000 milliseconds timeout on connection http-outgoing-135 [ACTIVE]
	at org.springframework.data.elasticsearch.client.elc.ElasticsearchExceptionTranslator.translateExceptionIfPossible(ElasticsearchExceptionTranslator.java:110)
	at org.springframework.data.elasticsearch.client.elc.ElasticsearchExceptionTranslator.translateException(ElasticsearchExceptionTranslator.java:64)
	at org.springframework.data.elasticsearch.client.elc.ElasticsearchTemplate.execute(ElasticsearchTemplate.java:635)
	at org.springframework.data.elasticsearch.client.elc.ElasticsearchTemplate.delete(ElasticsearchTemplate.java:186)
	at io.kaicode.elasticvc.api.BranchService.doContentRollback(BranchService.java:573)
	at io.kaicode.elasticvc.api.BranchService.rollbackCompletedCommit(BranchService.java:557)
	at org.snomed.snowstorm.core.data.services.SBranchService.rollbackCommit(SBranchService.java:176)
	at org.snomed.snowstorm.core.data.services.SBranchService.rollbackPartialCommit(SBranchService.java:206)
	at org.snomed.snowstorm.rest.AdminController.rollbackPartialCommit(AdminController.java:156)

...

	at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:63)
	at java.base/java.lang.Thread.run(Thread.java:840)
Caused by: java.lang.RuntimeException: 30,000 milliseconds timeout on connection http-outgoing-135 [ACTIVE]
	at org.springframework.data.elasticsearch.client.elc.ElasticsearchExceptionTranslator.translateException(ElasticsearchExceptionTranslator.java:63)
	... 213 common frames omitted
Caused by: java.net.SocketTimeoutException: 30,000 milliseconds timeout on connection http-outgoing-135 [ACTIVE]
	at org.elasticsearch.client.RestClient.extractAndWrapCause(RestClient.java:915)
	at org.elasticsearch.client.RestClient.performRequest(RestClient.java:300)
	at org.elasticsearch.client.RestClient.performRequest(RestClient.java:288)
	at co.elastic.clients.transport.rest_client.RestClientHttpClient.performRequest(RestClientHttpClient.java:91)
	at co.elastic.clients.transport.ElasticsearchTransportBase.performRequest(ElasticsearchTransportBase.java:144)
	at co.elastic.clients.elasticsearch.ElasticsearchClient.deleteByQuery(ElasticsearchClient.java:588)
	at org.springframework.data.elasticsearch.client.elc.ElasticsearchTemplate.lambda$delete$3(ElasticsearchTemplate.java:186)
	at org.springframework.data.elasticsearch.client.elc.ElasticsearchTemplate.execute(ElasticsearchTemplate.java:633)
	... 212 common frames omitted
Caused by: java.net.SocketTimeoutException: 30,000 milliseconds timeout on connection http-outgoing-135 [ACTIVE]
	at org.apache.http.nio.protocol.HttpAsyncRequestExecutor.timeout(HttpAsyncRequestExecutor.java:387)
	at org.apache.http.impl.nio.client.InternalIODispatch.onTimeout(InternalIODispatch.java:98)
	at org.apache.http.impl.nio.client.InternalIODispatch.onTimeout(InternalIODispatch.java:40)
	at org.apache.http.impl.nio.reactor.AbstractIODispatch.timeout(AbstractIODispatch.java:175)
	at org.apache.http.impl.nio.reactor.BaseIOReactor.sessionTimedOut(BaseIOReactor.java:261)
	at org.apache.http.impl.nio.reactor.AbstractIOReactor.timeoutCheck(AbstractIOReactor.java:506)
	at org.apache.http.impl.nio.reactor.BaseIOReactor.validate(BaseIOReactor.java:211)
	at org.apache.http.impl.nio.reactor.AbstractIOReactor.execute(AbstractIOReactor.java:280)
	at org.apache.http.impl.nio.reactor.BaseIOReactor.execute(BaseIOReactor.java:104)
	at org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:591)
	... 1 common frames omitted

[kaicode]

Usually changing the batch size and making sure Elasticsearch has enough memory and a fast disk resolves this timeout issue.

I am reading that it might be possible to change this timeout using this configuration option:

spring.data.elasticsearch.socket-timeout=120s

This is an AI generated configuration suggestion.