Timeout

[cocotte42]

Hi all,

I used an old version for some months. Some days ago, after upgrading to debian 11, I upgraded signal-cli to 11.4 and all worked fine. Even I surely did something wrong, I don't know what, and it doesn't work anymore...
I was using v11.4, and just ugrade to 11.5, but it's exactly the same behavior.
I check rights (even if I test it with root 😅)
It's a debian 11 system, JRE17 installed (17.0.4)

Here after the log with -vvv option when I try to do a receive, but it's the same for all commands.
I have tried to rename the config directory, then try a "register", it create the new db, but the result is the same...
Seems to be a problem to communicate with the db ? Perhaps a bad library ?

Thanks for your help.

Rodolphe

signal-cli -vvv --config /root/.local/share/signal-cli -a "+xxxxxxxxx" receive
2022-11-07T22:02:13.212+0100 [main] DEBUG org.asamk.signal.util.IOUtils - XDG_RUNTIME_DIR not set, falling back to temp dir
2022-11-07T22:02:13.440+0100 [main] INFO LibSignal - [libsignal]: rust/bridge/jni/src/logging.rs:156: Initializing libsignal version:0.21.1
2022-11-07T22:02:13.441+0100 [main] TRACE o.a.s.manager.config.ServiceConfig - Expected exception when checking libsignal-client: Deserialization failure in zkgroup
2022-11-07T22:02:13.592+0100 [main] DEBUG java.io.serialization - Builtin factory: null -> new: null
2022-11-07T22:02:13.595+0100 [main] TRACE org.asamk.signal.App - Loading account file for +xxxxxxxx
2022-11-07T22:02:13.651+0100 [main] TRACE o.a.s.manager.storage.SignalAccount - Opening account file
2022-11-07T22:02:13.652+0100 [main] TRACE o.a.s.manager.storage.SignalAccount - Loading account file
2022-11-07T22:02:13.659+0100 [main] TRACE o.a.s.manager.storage.SignalAccount - Migrating legacy parts of account file
2022-11-07T22:02:13.679+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - HikariPool-1 - configuration:
2022-11-07T22:02:13.690+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - allowPoolSuspension.............false
2022-11-07T22:02:13.690+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - autoCommit......................true
2022-11-07T22:02:13.690+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - catalog.........................none
2022-11-07T22:02:13.693+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - connectionInitSql..............."PRAGMA foreign_keys=ON"
2022-11-07T22:02:13.693+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - connectionTestQuery.............none
2022-11-07T22:02:13.693+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - connectionTimeout...............30000
2022-11-07T22:02:13.693+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - dataSource......................none
2022-11-07T22:02:13.693+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - dataSourceClassName.............none
2022-11-07T22:02:13.693+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - dataSourceJNDI..................none
2022-11-07T22:02:13.694+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - dataSourceProperties............{open_mode=70, transaction_mode=IMMEDIATE, password=, date_precision=MILLISECONDS, busy_timeout=60000, date_string_format=yyyy-MM-dd HH:mm:ss.SSS, jdbc.explicit_readonly=false, date_class=INTEGER, shared_cache=false}
2022-11-07T22:02:13.694+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - driverClassName.................none
2022-11-07T22:02:13.694+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - exceptionOverrideClassName......none
2022-11-07T22:02:13.695+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - healthCheckProperties...........{}
2022-11-07T22:02:13.695+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - healthCheckRegistry.............none
2022-11-07T22:02:13.695+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - idleTimeout.....................600000
2022-11-07T22:02:13.695+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - initializationFailTimeout.......1
2022-11-07T22:02:13.695+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - isolateInternalQueries..........false
2022-11-07T22:02:13.695+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - jdbcUrl.........................jdbc:sqlite:/root/.local/share/signal-cli/data/+xxxxxxxx.d/account.db
2022-11-07T22:02:13.696+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - keepaliveTime...................0
2022-11-07T22:02:13.696+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - leakDetectionThreshold..........0
2022-11-07T22:02:13.696+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - maxLifetime.....................1800000
2022-11-07T22:02:13.696+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - maximumPoolSize.................10
2022-11-07T22:02:13.696+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - metricRegistry..................none
2022-11-07T22:02:13.696+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - metricsTrackerFactory...........none
2022-11-07T22:02:13.697+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - minimumIdle.....................1
2022-11-07T22:02:13.697+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - password........................
2022-11-07T22:02:13.697+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - poolName........................"HikariPool-1"
2022-11-07T22:02:13.697+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - readOnly........................false
2022-11-07T22:02:13.697+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - registerMbeans..................false
2022-11-07T22:02:13.697+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - scheduledExecutor...............none
2022-11-07T22:02:13.698+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - schema..........................none
2022-11-07T22:02:13.698+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - threadFactory...................internal
2022-11-07T22:02:13.698+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - transactionIsolation............default
2022-11-07T22:02:13.698+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - username........................none
2022-11-07T22:02:13.698+0100 [main] DEBUG com.zaxxer.hikari.HikariConfig - validationTimeout...............5000
2022-11-07T22:02:13.700+0100 [main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Starting...
2022-11-07T22:02:13.708+0100 [main] DEBUG c.z.hikari.util.DriverDataSource - Loaded driver with class name org.sqlite.JDBC for jdbcUrl=jdbc:sqlite:/root/.local/share/signal-cli/data/+xxxxxxx.d/account.db
2022-11-07T22:02:13.801+0100 [main] INFO com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection org.sqlite.jdbc4.JDBC4Connection@40f70521
2022-11-07T22:02:13.803+0100 [main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Start completed.
2022-11-07T22:02:13.812+0100 [main] TRACE o.a.s.m.storage.AccountDatabase - Current database version: 11 Program database version: 11
2022-11-07T22:02:13.824+0100 [main] DEBUG com.zaxxer.hikari.pool.PoolBase - HikariPool-1 - Reset (autoCommit) on connection org.sqlite.jdbc4.JDBC4Connection@40f70521
2022-11-07T22:02:13.833+0100 [main] DEBUG com.zaxxer.hikari.pool.PoolBase - HikariPool-1 - Reset (autoCommit) on connection org.sqlite.jdbc4.JDBC4Connection@40f70521
2022-11-07T22:02:13.835+0100 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection org.sqlite.jdbc4.JDBC4Connection@34e724ef
2022-11-07T22:02:13.903+0100 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Before cleanup stats (total=2, active=0, idle=2, waiting=0)
2022-11-07T22:02:13.905+0100 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - After cleanup stats (total=2, active=0, idle=2, waiting=0)
2022-11-07T22:02:13.905+0100 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Fill pool skipped, pool has sufficient level or currently being filled (queueDepth=0).
2022-11-07T22:02:14.047+0100 [main] DEBUG com.zaxxer.hikari.pool.PoolBase - HikariPool-1 - Reset (autoCommit) on connection org.sqlite.jdbc4.JDBC4Connection@40f70521
2022-11-07T22:02:43.905+0100 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Before cleanup stats (total=2, active=0, idle=2, waiting=0)
2022-11-07T22:02:43.906+0100 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - After cleanup stats (total=2, active=0, idle=2, waiting=0)
2022-11-07T22:02:43.907+0100 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Fill pool skipped, pool has sufficient level or currently being filled (queueDepth=0).

[cocotte42]

Hi,

I just tried to do a fresh install of a VM debian 11. The install was the simplier as possible (just ssh server), then I only added openjdk-17-jre and install signal-cli => same result ...

I also tried to remove all config files and try a register, same messages ...

[cocotte42]

OK, found the problem !
My "failtoban" is linked to suricata. It seems that I got somethings bad from "chat.signal.org" earlier that is required to communicate with signal services.
I just release the two IP associated with this hostname and it works well now... I have to understand what was understood as bad by Suricata 😅