signal-cli icon indicating copy to clipboard operation
signal-cli copied to clipboard

Error: Unable to search for any number or send messages to new numbers or groups since version 0.13.0

Open Kamaradas opened this issue 1 year ago • 3 comments

We have been using a containerized app(https://github.com/bbernhard/signal-cli-rest-api), that uses the java application for 6 months or so with no problems, the containerized app is running on Linux rhel 4.18.0-513.11.1.el8_9.x86_64. However, since version 0.13.0(java application) we stopped being able to search for any number or send messages to new numbers or groups. We suspect that we are still able to send messages to already registered numbers because the app stored some IDs when it was still able to search for new numbers when it was running on version <= 0.12.8. We are using a proxy server(that is opened to all urls) to redirect our traffic and within the version 0.12.8, it works without a problem.

But when we updated the application to 0.13.2 or 0.13.3, the problems started to appear.

Note: We suspect that this issue might be related to the usage of a proxy server.

Bellow are the output for each java app version:

Java application version 0.12.8 signal-api@738413be8d34:/$ signal-cli --config /home/.local/share/signal-cli/ --verbose --output json getUserStatus 351935789098 2024-05-10T15:28:59.906Z [main] DEBUG org.asamk.signal.util.IOUtils - XDG_RUNTIME_DIR not set, falling back to temp dir 2024-05-10T15:28:59.916Z [main] DEBUG org.asamk.signal.App - Starting signal-cli 0.12.8 2024-05-10T15:29:00.250Z [main] INFO LibSignal - [libsignal]: rust/bridge/jni/src/logging.rs:158: Initializing libsignal version:0.36.1 2024-05-10T15:29:00.354Z [main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Starting... 2024-05-10T15:29:00.444Z [main] INFO com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection org.sqlite.jdbc4.JDBC4Connection@301ec38b 2024-05-10T15:29:00.445Z [main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Start completed. 2024-05-10T15:29:01.978Z [main] DEBUG o.a.s.manager.helper.RecipientHelper - No new numbers to query. 2024-05-10T15:29:02.122Z [main] WARN LibSignal - [PhoneNumberFormatter]: Got local CC: PT 2024-05-10T15:29:02.122Z [main] DEBUG o.a.s.manager.internal.ManagerImpl - Normalized number 351935789098 to +351935789098. 2024-05-10T15:29:02.969Z [OkHttp https://cdsi.signal.org/...] INFO LibSignal - [libsignal]: rust/attest/src/sgx_session.rs:174: Successfully completed attested connection 2024-05-10T15:29:03.613Z [OkHttp https://cdsi.signal.org/...] INFO LibSignal - [CdsiSocket]: [onClosing] code: 1000, reason: Normal Closure 2024-05-10T15:29:03.614Z [main] DEBUG o.a.s.manager.helper.RecipientHelper - CDSI request successful, quota used by this request: 1 2024-05-10T15:29:03.618Z [main] DEBUG o.a.s.m.s.r.MergeRecipientHelper - Got new recipient, serviceId, PNI, number, username are unknown 2024-05-10T15:29:03.620Z [main] DEBUG o.a.s.m.s.recipients.RecipientStore - Added new recipient RecipientId[id=2] with address RecipientAddress[serviceId=Optional[PNI:68680952-6d86-45bc-85e0-1a4d186d53ee], pni=Optional[PNI:68680952-6d86-45bc-85e0-1a4d186d53ee], number=Optional[+351935789098], username=Optional.empty] 2024-05-10T15:29:03.868Z [main] DEBUG o.a.s.m.s.i.IdentityKeyStore - Storing new identity for recipient PNI:68680952-6d86-45bc-85e0-1a4d186d53ee with trust TRUSTED_UNVERIFIED [{"recipient":"351935789098","number":"+351935789098","uuid":"68680952-6d86-45bc-85e0-1a4d186d53ee","isRegistered":true}] 2024-05-10T15:29:03.951Z [main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Shutdown initiated... 2024-05-10T15:29:03.962Z [main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Shutdown completed.

Java application version 0.13.2 signal-api@b2fdf0bdd8c8:/$ signal-cli --config /home/.local/share/signal-cli/ --verbose --output json getUserStatus 351935878902 2024-05-10T16:31:18.774Z [main] DEBUG org.asamk.signal.util.IOUtils - XDG_RUNTIME_DIR not set, falling back to temp dir 2024-05-10T16:31:18.784Z [main] DEBUG org.asamk.signal.App - Starting signal-cli 0.13.2 2024-05-10T16:31:18.985Z [main] INFO LibSignal - [libsignal]: rust/bridge/jni/src/logging.rs:158: Initializing libsignal version:0.40.1 2024-05-10T16:31:19.115Z [main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Starting... 2024-05-10T16:31:19.207Z [main] INFO com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection org.sqlite.jdbc4.JDBC4Connection@5cbe877d 2024-05-10T16:31:19.208Z [main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Start completed. 2024-05-10T16:31:20.934Z [main] DEBUG o.a.s.manager.internal.JobExecutor - Running RefreshRecipientsJob job 2024-05-10T16:31:21.092Z [main] WARN LibSignal - [PhoneNumberFormatter]: Got local CC: PT 2024-05-10T16:31:21.093Z [main] DEBUG o.a.s.manager.internal.ManagerImpl - Normalized number 351935878902 to +351935878902. 2024-05-10T16:31:31.095Z [Thread-0] INFO LibSignal - [libsignal]: rust/net/src/infra/connection_manager.rs:193: Connection attempt failed with an error: Operation timed out 2024-05-10T16:31:31.097Z [pool-2-thread-1] WARN o.a.s.m.jobs.RefreshRecipientsJob - Full CDSI recipients refresh failed, ignoring: org.signal.libsignal.net.NetworkException: Operation timed out (IOException) 2024-05-10T16:31:31.097Z [pool-2-thread-1] DEBUG o.a.s.m.jobs.RefreshRecipientsJob - Full CDSI refresh failed java.io.IOException: org.signal.libsignal.net.NetworkException: Operation timed out at org.whispersystems.signalservice.api.SignalServiceAccountManager.getRegisteredUsersWithCdsi(SignalServiceAccountManager.java:440) at org.asamk.signal.manager.helper.RecipientHelper.getRegisteredUsersV2(RecipientHelper.java:233) at org.asamk.signal.manager.helper.RecipientHelper.getRegisteredUsers(RecipientHelper.java:184) at org.asamk.signal.manager.helper.RecipientHelper.refreshUsers(RecipientHelper.java:154) at org.asamk.signal.manager.jobs.RefreshRecipientsJob.run(RefreshRecipientsJob.java:15) at org.asamk.signal.manager.internal.JobExecutor.lambda$runNextJob$0(JobExecutor.java:59) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) at java.base/java.lang.Thread.run(Thread.java:1583) Caused by: org.signal.libsignal.net.NetworkException: Operation timed out 2024-05-10T16:31:31.214Z [Thread-2] INFO LibSignal - [libsignal]: rust/net/src/infra/connection_manager.rs:193: Connection attempt failed with an error: Operation timed out 2024-05-10T16:31:31.221Z [main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Shutdown initiated... 2024-05-10T16:31:31.223Z [main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Shutdown completed. Unable to check if users are registered: org.signal.libsignal.net.NetworkException: Operation timed out (IOException) java.io.IOException: org.signal.libsignal.net.NetworkException: Operation timed out at org.whispersystems.signalservice.api.SignalServiceAccountManager.getRegisteredUsersWithCdsi(SignalServiceAccountManager.java:440) at org.asamk.signal.manager.helper.RecipientHelper.getRegisteredUsersV2(RecipientHelper.java:233) at org.asamk.signal.manager.helper.RecipientHelper.getRegisteredUsers(RecipientHelper.java:184) at org.asamk.signal.manager.helper.RecipientHelper.getRegisteredUsers(RecipientHelper.java:177) at org.asamk.signal.manager.internal.ManagerImpl.getUserStatus(ManagerImpl.java:263) at org.asamk.signal.commands.GetUserStatusCommand.handleCommand(GetUserStatusCommand.java:50) at org.asamk.signal.commands.CommandHandler.handleLocalCommand(CommandHandler.java:35) at org.asamk.signal.App.handleLocalCommand(App.java:278) at org.asamk.signal.App.handleCommand(App.java:179) at org.asamk.signal.App.init(App.java:144) at org.asamk.signal.Main.main(Main.java:56) Caused by: org.signal.libsignal.net.NetworkException: Operation timed out"

Java application version 0.13.3 signal-api@9743022180aa:/$ signal-cli --config /home/.local/share/signal-cli/ --verbose --output json getUserStatus 351935878902 2024-05-10T16:42:15.706Z [main] DEBUG org.asamk.signal.util.IOUtils - XDG_RUNTIME_DIR not set, falling back to temp dir 2024-05-10T16:42:15.717Z [main] DEBUG org.asamk.signal.App - Starting signal-cli 0.13.3 2024-05-10T16:42:15.944Z [main] INFO LibSignal - [libsignal]: rust/bridge/jni/src/logging.rs:161: Initializing libsignal version:0.44.0 2024-05-10T16:42:16.085Z [main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Starting... 2024-05-10T16:42:16.180Z [main] INFO com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection org.sqlite.jdbc4.JDBC4Connection@3a1dd365 2024-05-10T16:42:16.181Z [main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Start completed. 2024-05-10T16:42:16.187Z [main] DEBUG o.a.s.m.storage.AccountDatabase - Updating database: Create nick_name and note columns 2024-05-10T16:42:16.189Z [main] DEBUG o.a.s.m.storage.AccountDatabase - Updating database: Create discoverabel and profile_phone_number_sharing columns 2024-05-10T16:42:17.784Z [main] DEBUG o.a.s.manager.internal.JobExecutor - Running RefreshRecipientsJob job 2024-05-10T16:42:17.938Z [main] WARN LibSignal - [PhoneNumberFormatter]: Got local CC: PT 2024-05-10T16:42:17.939Z [main] DEBUG o.a.s.manager.internal.ManagerImpl - Normalized number 351935878902 to +351935878902. 2024-05-10T16:42:27.921Z [Thread-0] INFO LibSignal - [libsignal]: rust/net/src/infra/connection_manager.rs:193: Connection attempt failed with an error: timed out while connecting 2024-05-10T16:42:27.924Z [pool-2-thread-1] WARN o.a.s.m.jobs.RefreshRecipientsJob - Full CDSI recipients refresh failed, ignoring: org.signal.libsignal.net.NetworkException: connect timed out (IOException) 2024-05-10T16:42:27.925Z [pool-2-thread-1] DEBUG o.a.s.m.jobs.RefreshRecipientsJob - Full CDSI refresh failed java.io.IOException: org.signal.libsignal.net.NetworkException: connect timed out at org.whispersystems.signalservice.api.SignalServiceAccountManager.getRegisteredUsersWithCdsi(SignalServiceAccountManager.java:444) at org.asamk.signal.manager.helper.RecipientHelper.getRegisteredUsersV2(RecipientHelper.java:232) at org.asamk.signal.manager.helper.RecipientHelper.getRegisteredUsers(RecipientHelper.java:182) at org.asamk.signal.manager.helper.RecipientHelper.refreshUsers(RecipientHelper.java:152) at org.asamk.signal.manager.jobs.RefreshRecipientsJob.run(RefreshRecipientsJob.java:15) at org.asamk.signal.manager.internal.JobExecutor.lambda$runNextJob$0(JobExecutor.java:59) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) at java.base/java.lang.Thread.run(Thread.java:1583) Caused by: org.signal.libsignal.net.NetworkException: connect timed out 2024-05-10T16:42:28.059Z [Thread-2] INFO LibSignal - [libsignal]: rust/net/src/infra/connection_manager.rs:193: Connection attempt failed with an error: timed out while connecting 2024-05-10T16:42:28.087Z [main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Shutdown initiated... 2024-05-10T16:42:28.102Z [main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Shutdown completed. Unable to check if users are registered: org.signal.libsignal.net.NetworkException: connect timed out (IOException) java.io.IOException: org.signal.libsignal.net.NetworkException: connect timed out at org.whispersystems.signalservice.api.SignalServiceAccountManager.getRegisteredUsersWithCdsi(SignalServiceAccountManager.java:444) at org.asamk.signal.manager.helper.RecipientHelper.getRegisteredUsersV2(RecipientHelper.java:232) at org.asamk.signal.manager.helper.RecipientHelper.getRegisteredUsers(RecipientHelper.java:182) at org.asamk.signal.manager.helper.RecipientHelper.getRegisteredUsers(RecipientHelper.java:175) at org.asamk.signal.manager.internal.ManagerImpl.getUserStatus(ManagerImpl.java:263) at org.asamk.signal.commands.GetUserStatusCommand.handleCommand(GetUserStatusCommand.java:50) at org.asamk.signal.commands.CommandHandler.handleLocalCommand(CommandHandler.java:35) at org.asamk.signal.App.handleLocalCommand(App.java:278) at org.asamk.signal.App.handleCommand(App.java:179) at org.asamk.signal.App.init(App.java:144) at org.asamk.signal.Main.main(Main.java:56) Caused by: org.signal.libsignal.net.NetworkException: connect timed out signal-api@9743022180aa:/$"

Kamaradas avatar May 10 '24 17:05 Kamaradas

Quite likely it's related to the Proxy server. libsignal now does some of the network requests in the cross platform rust code instead of in java code. The cdsi code for contact discovery is the first that is implemented there. I don't know if the rust libsignal net implementation has support for proxies at all.

AsamK avatar May 17 '24 17:05 AsamK

Hello,

Thank you for your response.

We have noticed that in libsignal version 0.44 (https://github.com/signalapp/libsignal/releases), there is a release note indicating the addition of TLS proxy support across all platforms. Would it be possible for you to update your code to this version or a newer one to address the proxy issue we are experiencing?

Thank you very much for your assistance.

Kamaradas avatar May 21 '24 11:05 Kamaradas

@Kamaradas: Test builds (see https://github.com/AsamK/signal-cli/actions/workflows/ci.yml) already use libsignal v0.46.0; please note that you currently need to apply a patch in order to make your local builds work until signal-cli uses libsignal v0.47.0 or newer if you want to experiment with the current code base before the next signal-cli release is available.

m-ueberall avatar May 22 '24 07:05 m-ueberall

Looking at the change for the TLS support (https://github.com/signalapp/libsignal/commit/79bab1ce788419e36d73beb02a4bdc996189906a), it seems they just added some methods (set/clearProxy) to configure a proxy. It's not accessible without code changes.

kleptog avatar Dec 30 '24 14:12 kleptog

I had a look to see if I could figure out the right place to fix this. Ideally it should just check for the "https_proxy" environment variable, or the weird way Java does it, and configure it automatically. But, I'm not a Java programmer and I don't understand how any of this works. setProxy() is a method on org.signal.libsignal.net.Network and that's used in only one place (getLibSignalNetwork) which is also only sused in one place (getRegisteredUsersV2). I don't see how it can possibly affect the sending side. :(

kleptog avatar Dec 30 '24 16:12 kleptog

Hi there,

The problem is not in the send method , but when you call the send endpoint.

The first thing it does its to search for the contact/number in your know numbers, if there is a match, he calls the send method and works fine, but when it doesn't match, he calls the signal network do search for the number and fails because its using the proxy and the search part cant be reached.

Kamaradas avatar Jan 02 '25 11:01 Kamaradas

Ah, ok. So it is getRegisteredUsersV2() that's the actual problem, and that fixing that could make it work. If I have some time I'll look into that. Thanks for the tip.

kleptog avatar Jan 02 '25 16:01 kleptog

Looks like libsignal-client has added support for http and socks proxies in the latest version: https://github.com/signalapp/libsignal/releases/tag/v0.65.5 Will look into using that from signal-cli side.

AsamK avatar Feb 04 '25 16:02 AsamK

Can you check if it works with the latest development version? https://github.com/AsamK/signal-cli/actions/runs/13205624745

AsamK avatar Feb 07 '25 18:02 AsamK

Hello, I'm replying on this issue, as I was and unfortunately still am facing the same issue.

My setup is the following (simplified lab environment):

  • Signal CLI v0.13.14 (latest at this time)
  • Proxy: Squid Proxy allowing all, no filtering.
  • Server with no internet access, only way out is though proxy.
  • Java openjdk version "21.0.6" 2025-01-21 LTS

When trying to send message to a new contact, not yet in recipients list:

# Set proxy
export JAVA_OPTS="-Dhttp.proxyHost=proxy.mydomain.lan -Dhttp.proxyPort=3128 -Dhttps.proxyHost=proxy.mydomain.lan -Dhttps.proxyPort=3128"

# Send message to NEW contact => fails
signal-cli --verbose -u +xxxxxxxxxx send -m "Simple test" +yyyyyyyyyyy

The output is still the same:

2025-04-22T23:19:35.052+0200 [pool-2-thread-1] WARN  o.a.s.m.jobs.RefreshRecipientsJob - Full CDSI recipients refresh failed, ignoring: connect timed out (NetworkException)
2025-04-22T23:19:35.053+0200 [pool-2-thread-1] DEBUG o.a.s.m.jobs.RefreshRecipientsJob - Full CDSI refresh failed

Proxy access logs, single line, no denied:

1745356593.916   1233 192.168.1.165 TCP_TUNNEL/200 4123 CONNECT chat.signal.org:443 - HIER_DIRECT/76.223.92.165 -

Observed behavior: when not specifying proxy in JAVA_OPTS, there is a timeout after 10 secs. So Signal-cli is trying before giving up. Which is to be expected, as no proxy specified.

When proxy is set, it connects instantly, but a few steps later when checking the new recipient, the failure is immediate. As soon as it tries to contact CDSi, the timeout error occurs instantly.

@AsamK : is setting the proxy in the JAVA_OPTS (SIGNAL_CLI_OPTS) sufficient? Or it there also an extra config that I am missing?

airthusiast avatar Apr 22 '25 21:04 airthusiast