Unknown connection Error

[krebsni]

Only happens sometimes (at the start of running the backend).

Tested with Docker and MariaDB

qhana-backend-backend-1 | error: Connection between remote client and host is closed

[PhilWun]

I got the same error, but not at the start, but after the PC woke up from standby.

Log:

{"level":"info","ts":1693234553.716017,"msg":"using adjacent Caddyfile"}
{"level":"warn","ts":1693234553.7169027,"msg":"Caddyfile input is not formatted; run 'caddy fmt --overwrite' to fix inconsistencies","adapter":"caddyfile","file":"Caddyfile","line":2}
{"level":"info","ts":1693234553.719208,"logger":"admin","msg":"admin endpoint started","address":"localhost:2019","enforce_origin":false,"origins":["//localhost:2019","//[::1]:2019","//127.0.0.1:2019"]}
{"level":"info","ts":1693234553.7198195,"logger":"http.log","msg":"server running","name":"srv0","protocols":["h1","h2","h3"]}
{"level":"info","ts":1693234553.7202647,"msg":"autosaved config (load with --resume flag)","file":"/app/caddy/autosave.json"}
{"level":"info","ts":1693234553.720285,"msg":"serving initial configuration"}
{"level":"info","ts":1693234553.7205567,"logger":"tls","msg":"cleaning storage unit","description":"FileStorage:/home/ballerina/.local/share/caddy"}
{"level":"info","ts":1693234553.7207274,"logger":"tls","msg":"finished cleaning storage units"}
{"level":"info","ts":1693234553.7208896,"logger":"tls.cache.maintenance","msg":"started background certificate maintenance","cache":"0x4000481680"}
####################################################
##   _     _             _ _                      ##
##  | |   (_)           (_) |                     ##
##  | |    _  __ _ _   _ _| |__   __ _ ___  ___   ##
##  | |   | |/ _` | | | | | '_ \ / _` / __|/ _ \  ##
##  | |___| | (_| | |_| | | |_) | (_| \__ \  __/  ##
##  \_____/_|\__, |\__,_|_|_.__/ \__,_|___/\___|  ##
##              | |                               ##
##              |_|                               ##
##                                                ## 
##  Get documentation at docs.liquibase.com       ##
##  Get certified courses at learn.liquibase.com  ## 
##  Free schema change activity reports at        ##
##      https://hub.liquibase.com                 ##
##                                                ##
####################################################
Starting Liquibase at 14:55:54 (version 4.11.0 #2708 built at 2022-05-23 15:17+0000)
Liquibase Version: 4.11.0
Liquibase Community 4.11.0 by Liquibase
Liquibase command 'updateTestingRollback' was executed successfully.
[INFO  wait] --------------------------------------------------------
[INFO  wait]  docker-compose-wait 2.9.0
[INFO  wait] ---------------------------
[DEBUG wait] Starting with configuration:
[DEBUG wait]  - Hosts to be waiting for: [mariadb-registry:3306]
[DEBUG wait]  - Paths to be waiting for: []
[DEBUG wait]  - Timeout before failure: 30 seconds 
[DEBUG wait]  - TCP connection timeout before retry: 5 seconds 
[DEBUG wait]  - Sleeping time before checking for hosts/paths availability: 0 seconds
[DEBUG wait]  - Sleeping time once all hosts/paths are available: 0 seconds
[DEBUG wait]  - Sleeping time between retries: 1 seconds
[DEBUG wait] --------------------------------------------------------
[INFO  wait] Checking availability of host [mariadb-registry:3306]
[INFO  wait] Host [mariadb-registry:3306] is now available!
[INFO  wait] --------------------------------------------------------
[INFO  wait] docker-compose-wait - Everything's fine, the application can now start!
[INFO  wait] --------------------------------------------------------
####################################################
##   _     _             _ _                      ##
##  | |   (_)           (_) |                     ##
##  | |    _  __ _ _   _ _| |__   __ _ ___  ___   ##
##  | |   | |/ _` | | | | | '_ \ / _` / __|/ _ \  ##
##  | |___| | (_| | |_| | | |_) | (_| \__ \  __/  ##
##  \_____/_|\__, |\__,_|_|_.__/ \__,_|___/\___|  ##
##              | |                               ##
##              |_|                               ##
##                                                ## 
##  Get documentation at docs.liquibase.com       ##
##  Get certified courses at learn.liquibase.com  ## 
##  Free schema change activity reports at        ##
##      https://hub.liquibase.com                 ##
##                                                ##
Successfully started Caddy (pid=17) - Caddy is running in the background
####################################################
Starting Liquibase at 14:55:56 (version 4.11.0 #2708 built at 2022-05-23 15:17+0000)
Liquibase Version: 4.11.0
Liquibase Community 4.11.0 by Liquibase
Liquibase command 'updateTestingRollback' was executed successfully.
time = 2023-08-28T14:56:17.718Z level = ERROR module = qhana/qhana_backend message = "Could not get timeline step list." error = "Error while executing SQL query: SELECT count(*) AS rowCount FROM TimelineStep  WHERE experimentId =  ?   AND processorName LIKE  ?   AND processorVersion LIKE  ?  ;. java.util.ConcurrentModificationException" stackTrace = ["callableName: query moduleName: ballerinax.java.jdbc.1.Client fileName: client.bal lineNumber: 56","callableName: getTimelineStepCount moduleName: qhana.qhana_backend.database.0 fileName: database.bal lineNumber: 739","callableName: $get$experiments$^$timeline moduleName: qhana.qhana_backend.0.$anonType$_0 fileName: main.bal lineNumber: 664"]
error: Transaction: 3ba0ec62-4876-4de3-825e-d64340ad06b6:16 not found
at ballerinai.transaction.0:endTransaction(transaction_block.bal:115)
   qhana.qhana_backend.0.$anonType$_0:$get$experiments$^$timeline(main.bal:667)
time = 2023-08-29T07:22:17.700Z level = ERROR module = qhana/qhana_backend message = "Could not get timeline step list." error = "Error while executing SQL query: SELECT count(*) AS rowCount FROM TimelineStep  WHERE experimentId =  ?   AND processorName LIKE  ?   AND processorVersion LIKE  ?  ;. error while getting the connection for SQLClientConnector. HikariDataSource HikariDataSource (HikariPool-1) has been closed.." stackTrace = ["callableName: query moduleName: ballerinax.java.jdbc.1.Client fileName: client.bal lineNumber: 56","callableName: getTimelineStepCount moduleName: qhana.qhana_backend.database.0 fileName: database.bal lineNumber: 739","callableName: $get$experiments$^$timeline moduleName: qhana.qhana_backend.0.$anonType$_0 fileName: main.bal lineNumber: 664"]
time = 2023-08-29T07:22:17.706Z level = ERROR module = qhana/qhana_backend message = "Could not get timeline step list." error = "Error while executing SQL query: SELECT count(*) AS rowCount FROM TimelineStep  WHERE experimentId =  ?   AND processorName LIKE  ?   AND processorVersion LIKE  ?  ;. error while getting the connection for SQLClientConnector. HikariDataSource HikariDataSource (HikariPool-1) has been closed.." stackTrace = ["callableName: query moduleName: ballerinax.java.jdbc.1.Client fileName: client.bal lineNumber: 56","callableName: getTimelineStepCount moduleName: qhana.qhana_backend.database.0 fileName: database.bal lineNumber: 739","callableName: $get$experiments$^$timeline moduleName: qhana.qhana_backend.0.$anonType$_0 fileName: main.bal lineNumber: 664"]
time = 2023-08-29T07:22:17.707Z level = ERROR module = qhana/qhana_backend message = "Could not get timeline step list." error = "Error while executing SQL query: SELECT count(*) AS rowCount FROM TimelineStep  WHERE experimentId =  ?   AND processorName LIKE  ?   AND processorVersion LIKE  ?  ;. error while getting the connection for SQLClientConnector. HikariDataSource HikariDataSource (HikariPool-1) has been closed.." stackTrace = ["callableName: query moduleName: ballerinax.java.jdbc.1.Client fileName: client.bal lineNumber: 56","callableName: getTimelineStepCount moduleName: qhana.qhana_backend.database.0 fileName: database.bal lineNumber: 739","callableName: $get$experiments$^$timeline moduleName: qhana.qhana_backend.0.$anonType$_0 fileName: main.bal lineNumber: 664"]
time = 2023-08-29T07:22:17.707Z level = ERROR module = qhana/qhana_backend message = "Could not get timeline step list." error = "Error while executing SQL query: SELECT count(*) AS rowCount FROM TimelineStep  WHERE experimentId =  ?   AND processorName LIKE  ?   AND processorVersion LIKE  ?  ;. error while getting the connection for SQLClientConnector. HikariDataSource HikariDataSource (HikariPool-1) has been closed.." stackTrace = ["callableName: query moduleName: ballerinax.java.jdbc.1.Client fileName: client.bal lineNumber: 56","callableName: getTimelineStepCount moduleName: qhana.qhana_backend.database.0 fileName: database.bal lineNumber: 739","callableName: $get$experiments$^$timeline moduleName: qhana.qhana_backend.0.$anonType$_0 fileName: main.bal lineNumber: 664"]
time = 2023-08-29T07:22:17.700Z level = ERROR module = qhana/qhana_backend message = "Could not get timeline step list." error = "Error while executing SQL query: SELECT count(*) AS rowCount FROM TimelineStep  WHERE experimentId =  ?   AND processorName LIKE  ?   AND processorVersion LIKE  ?  ;. error while getting the connection for SQLClientConnector. HikariDataSource HikariDataSource (HikariPool-1) has been closed.." stackTrace = ["callableName: query moduleName: ballerinax.java.jdbc.1.Client fileName: client.bal lineNumber: 56","callableName: getTimelineStepCount moduleName: qhana.qhana_backend.database.0 fileName: database.bal lineNumber: 739","callableName: $get$experiments$^$timeline moduleName: qhana.qhana_backend.0.$anonType$_0 fileName: main.bal lineNumber: 664"]
time = 2023-08-29T07:22:17.706Z level = ERROR module = qhana/qhana_backend message = "Could not get timeline step list." error = "Error while executing SQL query: SELECT count(*) AS rowCount FROM TimelineStep  WHERE experimentId =  ?   AND processorName LIKE  ?   AND processorVersion LIKE  ?  ;. error while getting the connection for SQLClientConnector. HikariDataSource HikariDataSource (HikariPool-1) has been closed.." stackTrace = ["callableName: query moduleName: ballerinax.java.jdbc.1.Client fileName: client.bal lineNumber: 56","callableName: getTimelineStepCount moduleName: qhana.qhana_backend.database.0 fileName: database.bal lineNumber: 739","callableName: $get$experiments$^$timeline moduleName: qhana.qhana_backend.0.$anonType$_0 fileName: main.bal lineNumber: 664"]
error: Connection between remote client and host is closed
error: Connection between remote client and host is closed
error: Connection between remote client and host is closed
error: Connection between remote client and host is closed

[infacc]

I encountered this error when a plugin execution didn't finish properly (The UI showed Status: PENDING). In the log this line appeared:

time = 2023-10-26T17:35:28.928+02:00 level = ERROR module = qhana/qhana_backend message = "Could not get task status response." error = "Connection between client and remote host is closed" stackTrace = [] resultEndpoint = "http://localhost:5005/tasks/40/"

which led me to this line:

qhana-backend/result-watcher.bal

Line 432 in 8140161

log:printError("Could not get task status response.", 'error = result, resultEndpoint = self.resultEndpoint, stackTrace = result.stackTrace());

However, I can't reliably reproduce this error.

[buehlefs]

I have also seen similar errors, nearly always together with the transaction issues of ballerina. I believe they are somehow related and hope they get accidentally fixed by fixing the transaction issues...