Failure to upload DAR file to DAML sandbox using "daml ledger upload-dar"

Dear DAML community,

I am trying to upload our smart contracts DAR file using daml ledger upload-dar to a daml sandbox connected to a Postgres database. After the unsuccessful upload I get the following error message on the terminal (daml-helper: GRPCIOBadStatusCode StatusAborted (StatusDetails {unStatusDetails = "Request timed out"})) and continuously looping errors on the Server:

INFO: daml.index.db.connection.indexer - Starting...
DEBUG: daml.index.db.connection.indexer - Added connection org.postgresql.jdbc.PgConnection@35fd4c26
INFO: daml.index.db.connection.indexer - Start completed.
INFO: Found existing ledger with ID: b324b85f-3ff0-4181-90ce-ff5075b68702
INFO: Found existing participant id 'sandbox-participant'
INFO: Restarted Indexer Server
WARN: daml.index.db.connection.indexer - Connection org.postgresql.jdbc.PgConnection@35fd4c26 marked as broken because of SQLSTATE(08006), ErrorCode(0)
java.sql.BatchUpdateException: Batch entry 0 insert into packages(package_id, upload_id, source_description, size, known_since, ledger_offset, package)
select '6442383f2e52716c6c01d63e2bec689d92b0df6b1a046fa0600df87b3faba168', '94fad625-5b43-4543-8b9c-648e57e2957f', NULL, 1973317, '2020-09-24 14:01:44.418529+00'::timestamp with time zone, ledger_end, ?
from parameters
on conflict (package_id) do nothing was aborted: An I/O error occurred while sending to the backend.  Call getNextException to see other errors in the batch.
        at org.postgresql.jdbc.BatchResultHandler.handleError(BatchResultHandler.java:153)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:513)
        at org.postgresql.jdbc.PgStatement.internalExecuteBatch(PgStatement.java:850)
        at org.postgresql.jdbc.PgStatement.executeBatch(PgStatement.java:873)
        at org.postgresql.jdbc.PgPreparedStatement.executeBatch(PgPreparedStatement.java:1562)
        at com.zaxxer.hikari.pool.ProxyStatement.executeBatch(ProxyStatement.java:128)
        at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeBatch(HikariProxyPreparedStatement.java)
        at anorm.BatchSql.execute(BatchSql.scala:70)
        at anorm.BatchSql.execute$(BatchSql.scala:69)
        at anorm.BatchSql$Copy.execute(BatchSql.scala:203)
        at com.daml.platform.store.dao.JdbcLedgerDao.executeBatchSql(JdbcLedgerDao.scala:858)
        at com.daml.platform.store.dao.JdbcLedgerDao.uploadLfPackages(JdbcLedgerDao.scala:700)
        at com.daml.platform.store.dao.JdbcLedgerDao.$anonfun$storePackageEntry$1(JdbcLedgerDao.scala:661)
        at com.daml.platform.store.dao.HikariJdbcConnectionProvider.$anonfun$runSQL$1(HikariJdbcConnectionProvider.scala:131)
        at com.daml.metrics.Timed$.$anonfun$value$1(Timed.scala:18)
        at com.codahale.metrics.Timer.time(Timer.java:118)
        at com.daml.metrics.Timed$.value(Timed.scala:18)
        at com.daml.platform.store.dao.HikariJdbcConnectionProvider.runSQL(HikariJdbcConnectionProvider.scala:131)
        at com.daml.platform.store.dao.DbDispatcher.$anonfun$executeSql$2(DbDispatcher.scala:53)
        at scala.concurrent.Future$.$anonfun$apply$1(Future.scala:659)
        at scala.util.Success.$anonfun$map$1(Try.scala:255)
        at scala.util.Success.map(Try.scala:213)
        at scala.concurrent.Future.$anonfun$map$1(Future.scala:292)
        at scala.concurrent.impl.Promise.liftedTree1$1(Promise.scala:33)
        at scala.concurrent.impl.Promise.$anonfun$transform$1(Promise.scala:33)
        at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:64)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: org.postgresql.util.PSQLException: An I/O error occurred while sending to the backend.
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:514)
        ... 27 common frames omitted
Caused by: javax.net.ssl.SSLProtocolException: Connection reset by peer (Write failed)
        at java.base/sun.security.ssl.Alert.createSSLException(Alert.java:126)
        at java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:321)
        at java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:264)
        at java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:259)
        at java.base/sun.security.ssl.SSLSocketImpl$AppOutputStream.write(SSLSocketImpl.java:988)
        at java.base/java.io.BufferedOutputStream.write(BufferedOutputStream.java:123)
        at org.postgresql.core.PGStream.send(PGStream.java:307)
        at org.postgresql.core.v3.SimpleParameterList.streamBytea(SimpleParameterList.java:287)
        at org.postgresql.core.v3.SimpleParameterList.writeV3Value(SimpleParameterList.java:380)
        at org.postgresql.core.v3.QueryExecutorImpl.sendBind(QueryExecutorImpl.java:1621)
        at org.postgresql.core.v3.QueryExecutorImpl.sendOneQuery(QueryExecutorImpl.java:1861)
        at org.postgresql.core.v3.QueryExecutorImpl.sendQuery(QueryExecutorImpl.java:1386)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:494)
        ... 27 common frames omitted
Caused by: java.net.SocketException: Connection reset by peer (Write failed)
        at java.base/java.net.SocketOutputStream.socketWrite0(Native Method)
        at java.base/java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:110)
        at java.base/java.net.SocketOutputStream.write(SocketOutputStream.java:150)
        at java.base/sun.security.ssl.SSLSocketOutputRecord.deliver(SSLSocketOutputRecord.java:320)
        at java.base/sun.security.ssl.SSLSocketImpl$AppOutputStream.write(SSLSocketImpl.java:983)
        ... 35 common frames omitted
ERROR: Exception while executing SQL query. Rolled back. (context: {updateRecordTime=2020-09-24T14:01:44.418529Z, updateSourceDescription=, metric=store_package_entry, updateOffset=00000000000000020000000000000000, updateSubmissionId=94fad625-5b43-4543-8b9c-648e57e2957f})
java.sql.SQLException: Connection is closed
        at com.zaxxer.hikari.pool.ProxyConnection$ClosedConnection.lambda$getClosedConnection$0(ProxyConnection.java:489)
        at com.sun.proxy.$Proxy2.rollback(Unknown Source)
        at com.zaxxer.hikari.pool.ProxyConnection.rollback(ProxyConnection.java:370)
        at com.zaxxer.hikari.pool.HikariProxyConnection.rollback(HikariProxyConnection.java)
        at com.daml.platform.store.dao.HikariJdbcConnectionProvider.runSQL(HikariJdbcConnectionProvider.scala:144)
        at com.daml.platform.store.dao.DbDispatcher.$anonfun$executeSql$2(DbDispatcher.scala:53)
        at scala.concurrent.Future$.$anonfun$apply$1(Future.scala:659)
        at scala.util.Success.$anonfun$map$1(Try.scala:255)
        at scala.util.Success.map(Try.scala:213)
        at scala.concurrent.Future.$anonfun$map$1(Future.scala:292)
        at scala.concurrent.impl.Promise.liftedTree1$1(Promise.scala:33)
        at scala.concurrent.impl.Promise.$anonfun$transform$1(Promise.scala:33)
        at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:64)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:834)
DEBUG: daml.index.db.connection.indexer - Closing connection org.postgresql.jdbc.PgConnection@35fd4c26: (connection is broken)
ERROR: Error while running indexer, restart scheduled after 10 seconds
java.sql.SQLException: Connection is closed
        at com.zaxxer.hikari.pool.ProxyConnection$ClosedConnection.lambda$getClosedConnection$0(ProxyConnection.java:489)
        at com.sun.proxy.$Proxy2.rollback(Unknown Source)
        at com.zaxxer.hikari.pool.ProxyConnection.rollback(ProxyConnection.java:370)
        at com.zaxxer.hikari.pool.HikariProxyConnection.rollback(HikariProxyConnection.java)
        at com.daml.platform.store.dao.HikariJdbcConnectionProvider.runSQL(HikariJdbcConnectionProvider.scala:144)
        at com.daml.platform.store.dao.DbDispatcher.$anonfun$executeSql$2(DbDispatcher.scala:53)
        at scala.concurrent.Future$.$anonfun$apply$1(Future.scala:659)
        at scala.util.Success.$anonfun$map$1(Try.scala:255)
        at scala.util.Success.map(Try.scala:213)
        at scala.concurrent.Future.$anonfun$map$1(Future.scala:292)
        at scala.concurrent.impl.Promise.liftedTree1$1(Promise.scala:33)
        at scala.concurrent.impl.Promise.$anonfun$transform$1(Promise.scala:33)
        at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:64)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:834)

I tried different things including increasing the timeout using daml ledger upload-dar --timeout 300 and also cleaning the postgres database tables and restarting the Daml sandbox.

Best regards,
Pierre Besson

2 Likes

It’s quite difficult to understand what the problem could be, all I can see is that ultimately the issue seems to point at connection is broken.

  • what version of the SDK are you using?
  • how did you run the sandbox?
  • can you check that the errors you see don’t appear already before you try to upload the package?
1 Like

Thank you for you answer. Here is more information about my setup:
DAML SDK: version 1.5.0
PostgreSQL: version 11 running in GCP (2 vCPU, 3.75GB mem, max connections 200, accessed through SSL)
And here is the startup script that we use to start the sandbox:

    JDBC_URL="jdbc:postgresql://postgresql-daml-01.******/damldb"
    JDBC_URL="$JDBC_URL?user=daml_user"
    JDBC_URL="$JDBC_URL&password=******"
    JDBC_URL="$JDBC_URL&ssl=true"
    JDBC_URL="$JDBC_URL&sslmode=verify-ca"
    JDBC_URL="$JDBC_URL&sslrootcert=/opt/daml/server-ca.pem"
    JDBC_URL="$JDBC_URL&sslcert=/opt/daml/client-cert.pem"
    JDBC_URL="$JDBC_URL&sslkey=/opt/daml/client-key.pk8"
    IP_ADDRESS="$(hostname -I)"

    /opt/daml/sdk-1.5.0/daml/daml sandbox --sql-backend-jdbcurl $JDBC_URL --ledgerid "b324b85f-3ff0-4181-90ce-ff5075b68702" --address $IP_ADDRESS --log-level "TRACE"

I am quite confident that the error happens only after trying to upload the package. I have tried several times to recreate the database and reinitialize the sandbox from scratch. I have tried several different DAR files but the issue still happen.

You might want to try using daml sandbox-classic instead of daml sandbox. The SQL backend for that has existed for a bit longer and is a bit more mature.

Thanks a lot for your answer. I tried to switch to sandbox-classic but I still have an issue. Although it will not loop on the error message in this case.

Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]: WARN: daml.index.db.connection.sandbox - Connection org.postgresql.jdbc.PgConnection@38fe2c0b marked as broken because of SQLSTATE(08006), ErrorCode(0)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]: java.sql.BatchUpdateException: Batch entry 0 insert into packages(package_id, upload_id, source_description, size, known_since, ledger_offset, package)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]: select '6442383f2e52716c6c01d63e2bec689d92b0df6b1a046fa0600df87b3faba168', '0eac736a-e2a8-4a7b-b96c-e62a017f5f1c', NULL, 1973317, '2020-09-28 08:51:03.353018+00'::timestamp with time zone, ledger_end, ?
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]: from parameters
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]: on conflict (package_id) do nothing was aborted: An I/O error occurred while sending to the backend.  Call getNextException to see other errors in the batch.
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at org.postgresql.jdbc.BatchResultHandler.handleError(BatchResultHandler.java:153)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:513)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at org.postgresql.jdbc.PgStatement.internalExecuteBatch(PgStatement.java:850)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at org.postgresql.jdbc.PgStatement.executeBatch(PgStatement.java:873)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at org.postgresql.jdbc.PgPreparedStatement.executeBatch(PgPreparedStatement.java:1562)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at com.zaxxer.hikari.pool.ProxyStatement.executeBatch(ProxyStatement.java:128)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeBatch(HikariProxyPreparedStatement.java)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at anorm.BatchSql.execute(BatchSql.scala:70)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at anorm.BatchSql.execute$(BatchSql.scala:69)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at anorm.BatchSql$Copy.execute(BatchSql.scala:203)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at com.daml.platform.store.dao.JdbcLedgerDao.executeBatchSql(JdbcLedgerDao.scala:858)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at com.daml.platform.store.dao.JdbcLedgerDao.uploadLfPackages(JdbcLedgerDao.scala:700)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at com.daml.platform.store.dao.JdbcLedgerDao.$anonfun$storePackageEntry$1(JdbcLedgerDao.scala:661)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at com.daml.platform.store.dao.HikariJdbcConnectionProvider.$anonfun$runSQL$1(HikariJdbcConnectionProvider.scala:131)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at com.daml.metrics.Timed$.$anonfun$value$1(Timed.scala:18)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at com.codahale.metrics.Timer.time(Timer.java:118)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at com.daml.metrics.Timed$.value(Timed.scala:18)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at com.daml.platform.store.dao.HikariJdbcConnectionProvider.runSQL(HikariJdbcConnectionProvider.scala:131)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at com.daml.platform.store.dao.DbDispatcher.$anonfun$executeSql$2(DbDispatcher.scala:53)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at scala.concurrent.Future$.$anonfun$apply$1(Future.scala:659)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at scala.util.Success.$anonfun$map$1(Try.scala:255)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at scala.util.Success.map(Try.scala:213)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at scala.concurrent.Future.$anonfun$map$1(Future.scala:292)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at scala.concurrent.impl.Promise.liftedTree1$1(Promise.scala:33)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at scala.concurrent.impl.Promise.$anonfun$transform$1(Promise.scala:33)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:64)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at java.base/java.lang.Thread.run(Thread.java:834)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]: Caused by: org.postgresql.util.PSQLException: An I/O error occurred while sending to the backend.
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:514)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         ... 27 common frames omitted
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]: Caused by: javax.net.ssl.SSLProtocolException: Connection reset by peer (Write failed)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at java.base/sun.security.ssl.Alert.createSSLException(Alert.java:126)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:321)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:264)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:259)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at java.base/sun.security.ssl.SSLSocketImpl$AppOutputStream.write(SSLSocketImpl.java:988)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at java.base/java.io.BufferedOutputStream.write(BufferedOutputStream.java:123)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at org.postgresql.core.PGStream.send(PGStream.java:307)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at org.postgresql.core.v3.SimpleParameterList.streamBytea(SimpleParameterList.java:287)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at org.postgresql.core.v3.SimpleParameterList.writeV3Value(SimpleParameterList.java:380)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at org.postgresql.core.v3.QueryExecutorImpl.sendBind(QueryExecutorImpl.java:1621)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at org.postgresql.core.v3.QueryExecutorImpl.sendOneQuery(QueryExecutorImpl.java:1861)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at org.postgresql.core.v3.QueryExecutorImpl.sendQuery(QueryExecutorImpl.java:1386)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:494)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         ... 27 common frames omitted
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]: Caused by: java.net.SocketException: Connection reset by peer (Write failed)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at java.base/java.net.SocketOutputStream.socketWrite0(Native Method)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at java.base/java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:110)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at java.base/java.net.SocketOutputStream.write(SocketOutputStream.java:150)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at java.base/sun.security.ssl.SSLSocketOutputRecord.deliver(SSLSocketOutputRecord.java:320)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at java.base/sun.security.ssl.SSLSocketImpl$AppOutputStream.write(SSLSocketImpl.java:983)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         ... 35 common frames omitted
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]: ERROR: Exception while executing SQL query. Rolled back. (context: {description=, submissionId=0eac736a-e2a8-4a7b-b96c-e62a017f5f1c, participantId=sandbox-participant, metric=store_package_entry, packageHashes=6442383f2e52716c6c01d63e2bec689d92b0df6b1a046fa0600df87b3faba168,fefc7ecb35ea34b9db4d8e6a7c4a2966eb93902a72e01ce350320f25869d37ca,76bf0fd12bd945762a01f8fc5bbcdfa4d0ff20f8762af490f8f41d6237c6524f,d58cf9939847921b2aab78eaa7b427dc4c649d25e6bee3c749ace4c3f52f5c97,40f452260bef3f29dede136108fc08a88d5a5250310281067087da6f0baddff7,e491352788e56ca4603acc411ffe1a49fefd76ed8b163af86cf5ee5f4c38645b,6839a6d3d430c569b2425e9391717b44ca324b88ba621d597778811b2d05031d,518032f41fd0175461b35ae0c9691e08b4aea55e62915f8360af2cc7a1f2ba6c,46e3c294ef09eafe3d83f6abf40b09013a1eee6602ab28833b9dfba053bd7b86,cd314fc519b9e3528f46c92658d77c63f80d1a209f67319f2ece231cf38c79df,bfcd37bd6b84768e86e432f5f6c33e25d9e7724a9d42e33875ff74f6348e733f,cc348d369011362a5190fe96dd1f0dfbc697fdfd10e382b9e9666f0da05961b7,057eed1fd48c238491b8ea06b9b5bf85a5d4c9275dd3f6183e0e6b01730cc2ba,d14e08374fc7197d6a0de468c968ae8ba3aadbf9315476fd39071831f5923662,c1f1f00558799eec139fb4f4c76f95fb52fa1837a5dd29600baa1c8ed1bdccfd,6c2c0667393c5f92f1885163068cd31800d2264eb088eb6fc740e11241b2bf06,e22bce619ae24ca3b8e6519281cb5a33b64b3190cc763248b4c3f9ad5087a92c,8a7806365bbd98d88b4c13832ebfa305f6abaeaf32cfa2b7dd25c4fa489b79fb,733e38d36a2759688a4b2c4cec69d48e7b55ecc8dedc8067b815926c917a182a,99a2705ed38c1c26cbb8fe7acf36bbf626668e167a33335de932599219e0a235,b44866989518b2917d4758e392534b71628c98ab26ccb73e45df0ea28dc289d7})
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]: java.sql.SQLException: Connection is closed
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at com.zaxxer.hikari.pool.ProxyConnection$ClosedConnection.lambda$getClosedConnection$0(ProxyConnection.java:489)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at com.sun.proxy.$Proxy2.rollback(Unknown Source)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at com.zaxxer.hikari.pool.ProxyConnection.rollback(ProxyConnection.java:370)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at com.zaxxer.hikari.pool.HikariProxyConnection.rollback(HikariProxyConnection.java)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at com.daml.platform.store.dao.HikariJdbcConnectionProvider.runSQL(HikariJdbcConnectionProvider.scala:144)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at com.daml.platform.store.dao.DbDispatcher.$anonfun$executeSql$2(DbDispatcher.scala:53)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at scala.concurrent.Future$.$anonfun$apply$1(Future.scala:659)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at scala.util.Success.$anonfun$map$1(Try.scala:255)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at scala.util.Success.map(Try.scala:213)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at scala.concurrent.Future.$anonfun$map$1(Future.scala:292)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at scala.concurrent.impl.Promise.liftedTree1$1(Promise.scala:33)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at scala.concurrent.impl.Promise.$anonfun$transform$1(Promise.scala:33)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:64)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at java.base/java.lang.Thread.run(Thread.java:834)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]: ERROR: Failed to persist packages with offset: 0000000000000004 (context: {participantId=sandbox-participant, submissionId=0eac736a-e2a8-4a7b-b96c-e62a017f5f1c, description=, packageHashes=6442383f2e52716c6c01d63e2bec689d92b0df6b1a046fa0600df87b3faba168,fefc7ecb35ea34b9db4d8e6a7c4a2966eb93902a72e01ce350320f25869d37ca,76bf0fd12bd945762a01f8fc5bbcdfa4d0ff20f8762af490f8f41d6237c6524f,d58cf9939847921b2aab78eaa7b427dc4c649d25e6bee3c749ace4c3f52f5c97,40f452260bef3f29dede136108fc08a88d5a5250310281067087da6f0baddff7,e491352788e56ca4603acc411ffe1a49fefd76ed8b163af86cf5ee5f4c38645b,6839a6d3d430c569b2425e9391717b44ca324b88ba621d597778811b2d05031d,518032f41fd0175461b35ae0c9691e08b4aea55e62915f8360af2cc7a1f2ba6c,46e3c294ef09eafe3d83f6abf40b09013a1eee6602ab28833b9dfba053bd7b86,cd314fc519b9e3528f46c92658d77c63f80d1a209f67319f2ece231cf38c79df,bfcd37bd6b84768e86e432f5f6c33e25d9e7724a9d42e33875ff74f6348e733f,cc348d369011362a5190fe96dd1f0dfbc697fdfd10e382b9e9666f0da05961b7,057eed1fd48c238491b8ea06b9b5bf85a5d4c9275dd3f6183e0e6b01730cc2ba,d14e08374fc7197d6a0de468c968ae8ba3aadbf9315476fd39071831f5923662,c1f1f00558799eec139fb4f4c76f95fb52fa1837a5dd29600baa1c8ed1bdccfd,6c2c0667393c5f92f1885163068cd31800d2264eb088eb6fc740e11241b2bf06,e22bce619ae24ca3b8e6519281cb5a33b64b3190cc763248b4c3f9ad5087a92c,8a7806365bbd98d88b4c13832ebfa305f6abaeaf32cfa2b7dd25c4fa489b79fb,733e38d36a2759688a4b2c4cec69d48e7b55ecc8dedc8067b815926c917a182a,99a2705ed38c1c26cbb8fe7acf36bbf626668e167a33335de932599219e0a235,b44866989518b2917d4758e392534b71628c98ab26ccb73e45df0ea28dc289d7})
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]: java.sql.SQLException: Connection is closed
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at com.zaxxer.hikari.pool.ProxyConnection$ClosedConnection.lambda$getClosedConnection$0(ProxyConnection.java:489)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at com.sun.proxy.$Proxy2.rollback(Unknown Source)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at com.zaxxer.hikari.pool.ProxyConnection.rollback(ProxyConnection.java:370)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at com.zaxxer.hikari.pool.HikariProxyConnection.rollback(HikariProxyConnection.java)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at com.daml.platform.store.dao.HikariJdbcConnectionProvider.runSQL(HikariJdbcConnectionProvider.scala:144)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at com.daml.platform.store.dao.DbDispatcher.$anonfun$executeSql$2(DbDispatcher.scala:53)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at scala.concurrent.Future$.$anonfun$apply$1(Future.scala:659)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at scala.util.Success.$anonfun$map$1(Try.scala:255)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at scala.util.Success.map(Try.scala:213)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at scala.concurrent.Future.$anonfun$map$1(Future.scala:292)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at scala.concurrent.impl.Promise.liftedTree1$1(Promise.scala:33)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at scala.concurrent.impl.Promise.$anonfun$transform$1(Promise.scala:33)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:64)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]:         at java.base/java.lang.Thread.run(Thread.java:834)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]: DEBUG: daml.index.db.connection.sandbox - Closing connection org.postgresql.jdbc.PgConnection@38fe2c0b: (connection is broken)
Sep 28 08:51:03 ls-gcp-dev-daml-on-postgre daml-start.sh[12298]: DEBUG: daml.index.db.connection.sandbox - Added connection org.postgresql.jdbc.PgConnection@18b28f67

[EDIT] I need to add that the DAR upload works fine for the in-memory DAML sandbox.

Hi @pierre.besson. Thanks for posting. :slight_smile:

This looks like some kind of network connectivity issue, where the connection is broken by something sitting in the middle.

Are you running PostgreSQL on the same machine/VM/container/etc. as Sandbox itself, or does it live on another box?

Have you tried connecting to PostgreSQL using psql from the same machine/VM/etc. as you’re running the ledger? Does it give you any errors when you try a query?

If psql works, can you leave it running, start Sandbox, wait until it fails, and then try another query with the open psql shell?

Thank you Samir for your answer which helped me troubleshoot the issue on my own.
Indeed our Posgresql database is running on a separate VM as it is managed by GCP and I am connecting to it over the network.

I had a look at the Postgres logs and I have found the 3 following INFO logs :

2020-09-28 12:32:48.763 UTC [69792]: [1-1] db=damldb,user=daml_user LOG: SSL error: DATA_LENGTH_TOO_LONG
2020-09-28 12:32:48.764 UTC [69792]: [2-1] db=damldb,user=daml_user LOG: could not receive data from client: Connection reset by peer
2020-09-28 12:32:48.764 UTC [69792]: [3-1] db=damldb,user=daml_user LOG: incomplete message from client 

Through a quick Google search the error message SSL error: DATA_LENGTH_TOO_LONG pointed me the cause of the issue which is a JDK bug relating to TLS 1.3 support that has been fixed in JDK 11.05 (https://bugs.openjdk.java.net/browse/JDK-8221253). Unfortunalely we were running JDK 11.01 which is affected by the bug. Upgrading to a newer version of OpenJDK fixed the issue.

3 Likes

Awesome, glad you found it! And thank you for writing up the solution so that someone else with the same problem can diagnose it more easily in the future.

2 Likes

As a final note, I would recommend you don’t manipulate the index database directly. That is an internal whose purpose is to collect and serve Ledger API data and there’s no guarantee it will continue working if you touch the data and/or the schema directly.

Thanks for this precision. I have an additional question (sorry if it is a little off-topic), will the DAML sandbox be able to support SDK upgrades smoothly?

Sandbox classic and DAML on SQL (which I would strongly recommend in favor of sandbox classic) do support upgrades automatically. The default Sandbox does not support upgrades across SDKs.