search

bbernhard / signal-cli-rest-api

Dockerized Signal Messenger REST API
https://bbernhard.github.io/signal-cli-rest-api/
MIT License
1.26k stars 151 forks source link

Cannot send anything #412

Closed anotherbridge closed 10 months ago

anotherbridge commented 11 months ago

The problem

After registering a number on a fresh container with no prior configuration I am not able to send any messages.

Command that was run: 

curl -X POST -H "Content-Type: application/json" 'http://localhost:8080/v2/send' -d '{"message": "Test via Signal API!", "number": "<sender>", "recipients": [ "<recipient>" ]}'

And the response is: 

{
  "error": "WARN  SendHelper - Failed to send message due to IO exception: Unable to parse entity\nFailed to send message\n"
}

In the container logs I am seeing: 

[GIN] <timestamp> | 400 |    6.6703771s |      10.0.2.100 | POST     "/v2/send"

Are you using the latest released version?

Have you read the troubleshooting page?

What type of installation are you running?

signal-cli-rest-api Docker Container

In which mode are you using the docker container?

Native Mode

What's the architecture of your host system?

x86-64

Additional information

I encountered this issue in all modes, i.e. normal, native and json-rpc.

Further, I have a version where a number was registered under version 0.64 and strangely when mounting this configuration directory, I can do everything without any problems..

anotherbridge commented 11 months ago

An update regarding the latest version (0.68) that was released after I opened the issue:

Now I am getting a different error: 

{
  "error": "WARN  Manager - Failed to call libsignal-client: Can't load library: /tmp/977663829282952040libsignal_jni.so\nMissing required native library dependency: libsignal-client\n"
}
anotherbridge commented 11 months ago

In addition to that when trying to send a message using the signal-cli directly from within the container, by running

uname -a | signal-cli --config /home/.local/share/signal-cli -v -a "+123456789" send --message-from-stdin "+987654321"

as the signal-api user I am getting 

2023-09-28T08:36:37.907Z [main] DEBUG org.asamk.signal.util.IOUtils - XDG_RUNTIME_DIR not set, falling back to temp dir
2023-09-28T08:36:37.939Z [main] DEBUG org.asamk.signal.App - Starting signal-cli 0.12.1
2023-09-28T08:36:38.164Z [main] INFO  LibSignal - [libsignal]: rust/bridge/jni/src/logging.rs:156: Initializing libsignal version:0.30.0
2023-09-28T08:36:39.008Z [main] INFO  com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Starting...
2023-09-28T08:36:39.268Z [main] INFO  com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection org.sqlite.jdbc4.JDBC4Connection@1c7fd41f
2023-09-28T08:36:39.271Z [main] INFO  com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Start completed.
2023-09-28T08:36:46.869Z [main] WARN  LibSignal - [PhoneNumberFormatter]: Got local CC: DE
2023-09-28T08:36:46.909Z [main] DEBUG o.asamk.signal.commands.SendCommand - Reading message from stdin...
2023-09-28T08:36:47.345Z [main] INFO  LibSignal - [libsignal]: rust/protocol/src/session_cipher.rs:59: Building PreKeyWhisperMessage for: 9550a8d4-11c6-4cc6-8f45-160528beaa58.1 with preKeyId: 14448630
2023-09-28T08:36:47.400Z [main] INFO  LibSignal - [libsignal]: rust/protocol/src/session_cipher.rs:59: Building PreKeyWhisperMessage for: 9550a8d4-11c6-4cc6-8f45-160528beaa58.2 with preKeyId: 29
2023-09-28T08:36:47.832Z [main] INFO  LibSignal - [SignalServiceMessageSender]: [sendMessage][1695890206928] Pipe unavailable, falling back... (WebSocketUnavailableException: WebSocket not currently available.)
Failed to send (some) messages:
+987654321: CAPTCHA proof required for sending to "+987654321", available options "RECAPTCHA, PUSH_CHALLENGE" with challenge token "<token>", or wait "86400" seconds.
To get the captcha token, go to https://signalcaptchas.org/challenge/generate.html
Check the developer tools (F12) console for a failed redirect to signalcaptcha://
Everything after signalcaptcha:// is the captcha token.
Use the following command to submit the captcha token:
signal-cli submitRateLimitChallenge --challenge CHALLENGE_TOKEN --captcha CAPTCHA_TOKEN
1695890206928
2023-09-28T08:36:48.304Z [main] INFO  com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Shutdown initiated...
2023-09-28T08:36:48.315Z [main] INFO  com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Shutdown completed.
2023-09-28T08:36:48.316Z [msl-cleanup] DEBUG o.a.s.m.s.s.MessageSendLogStore - Stopping msl cleanup thread
Failed to send message

When running 

signal-cli --config /home/.local/share/signal-cli -v submitRateLimitChallenge --challenge "<token>" --captcha "<captcha>"

afterwards, I still get the error: 

2023-09-28T08:39:13.470Z [main] DEBUG org.asamk.signal.util.IOUtils - XDG_RUNTIME_DIR not set, falling back to temp dir
2023-09-28T08:39:13.497Z [main] DEBUG org.asamk.signal.App - Starting signal-cli 0.12.1
2023-09-28T08:39:13.722Z [main] INFO  LibSignal - [libsignal]: rust/bridge/jni/src/logging.rs:156: Initializing libsignal version:0.30.0
2023-09-28T08:39:14.499Z [main] INFO  com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Starting...
2023-09-28T08:39:14.746Z [main] INFO  com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection org.sqlite.jdbc4.JDBC4Connection@77a98a6a
2023-09-28T08:39:14.750Z [main] INFO  com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Start completed.
2023-09-28T08:39:22.623Z [main] INFO  com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Shutdown initiated...
2023-09-28T08:39:22.634Z [main] INFO  com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Shutdown completed.
Submit challenge error: [400] Bad response: 400
org.whispersystems.signalservice.api.push.exceptions.NonSuccessfulResponseCodeException: [400] Bad response: 400
    at org.whispersystems.signalservice.internal.push.PushServiceSocket.validateServiceResponse(PushServiceSocket.java:1898)
    at org.whispersystems.signalservice.internal.push.PushServiceSocket.makeServiceRequest(PushServiceSocket.java:1842)
    at org.whispersystems.signalservice.internal.push.PushServiceSocket.makeServiceRequest(PushServiceSocket.java:1780)
    at org.whispersystems.signalservice.internal.push.PushServiceSocket.makeServiceRequest(PushServiceSocket.java:1774)
    at org.whispersystems.signalservice.internal.push.PushServiceSocket.submitRateLimitRecaptchaChallenge(PushServiceSocket.java:1123)
    at org.whispersystems.signalservice.api.SignalServiceAccountManager.submitRateLimitRecaptchaChallenge(SignalServiceAccountManager.java:905)
    at org.asamk.signal.manager.internal.ManagerImpl.submitRateLimitRecaptchaChallenge(ManagerImpl.java:334)
    at org.asamk.signal.commands.SubmitRateLimitChallengeCommand.handleCommand(SubmitRateLimitChallengeCommand.java:38)
    at org.asamk.signal.commands.CommandHandler.handleLocalCommand(CommandHandler.java:35)
    at org.asamk.signal.App.handleLocalCommand(App.java:276)
    at org.asamk.signal.App.handleCommand(App.java:192)
    at org.asamk.signal.App.init(App.java:144)
    at org.asamk.signal.Main.main(Main.java:60)
mattwr18 commented 11 months ago

@anotherbridge are you running in native mode? From our testing of 0.68-pre, it does not work in native mode due to an issue with GraalVM .

See: https://github.com/bbernhard/signal-cli-rest-api/pull/401 https://github.com/AsamK/signal-cli/issues/1305

anotherbridge commented 11 months ago

@mattwr18 Thanks for the hint. I indeed ran in native mode. I also tried with the json-rpc mode, but there I am also getting: 

{
  "error": "Failed to send message"
}

And within the container after stopping the running signal-cli process and sending again: 

2023-09-28T16:27:21.153Z [main] DEBUG org.asamk.signal.util.IOUtils - XDG_RUNTIME_DIR not set, falling back to temp dir
2023-09-28T16:27:21.226Z [main] DEBUG org.asamk.signal.App - Starting signal-cli 0.12.1
2023-09-28T16:27:21.624Z [main] INFO  LibSignal - [libsignal]: rust/bridge/jni/src/logging.rs:156: Initializing libsignal version:0.30.0
2023-09-28T16:27:23.271Z [main] INFO  com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Starting...
2023-09-28T16:27:23.713Z [main] INFO  com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection org.sqlite.jdbc4.JDBC4Connection@1c7fd41f
2023-09-28T16:27:23.717Z [main] INFO  com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Start completed.
2023-09-28T16:27:28.829Z [main] WARN  LibSignal - [PhoneNumberFormatter]: Got local CC: DE
2023-09-28T16:27:28.923Z [main] DEBUG o.asamk.signal.commands.SendCommand - Reading message from stdin...
2023-09-28T16:27:29.792Z [main] INFO  LibSignal - [libsignal]: rust/protocol/src/session_cipher.rs:59: Building PreKeyWhisperMessage for: 9550a8d4-11c6-4cc6-8f45-160528beaa58.1 with preKeyId: 14448630
2023-09-28T16:27:29.902Z [main] INFO  LibSignal - [libsignal]: rust/protocol/src/session_cipher.rs:59: Building PreKeyWhisperMessage for: 9550a8d4-11c6-4cc6-8f45-160528beaa58.2 with preKeyId: 29
2023-09-28T16:27:30.770Z [main] INFO  LibSignal - [SignalServiceMessageSender]: [sendMessage][1695918448970] Pipe unavailable, falling back... (WebSocketUnavailableException: WebSocket not currently available.)
Failed to send (some) messages:
+987654321: CAPTCHA proof required for sending to "+987654321", available options "RECAPTCHA, PUSH_CHALLENGE" with challenge token "<token>", or wait "86400" seconds.
To get the captcha token, go to https://signalcaptchas.org/challenge/generate.html
Check the developer tools (F12) console for a failed redirect to signalcaptcha://
Everything after signalcaptcha:// is the captcha token.
Use the following command to submit the captcha token:
signal-cli submitRateLimitChallenge --challenge CHALLENGE_TOKEN --captcha CAPTCHA_TOKEN
1695918448970
2023-09-28T16:27:31.312Z [main] INFO  com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Shutdown initiated...
2023-09-28T16:27:31.334Z [main] INFO  com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Shutdown completed.
2023-09-28T16:27:31.336Z [msl-cleanup] DEBUG o.a.s.m.s.s.MessageSendLogStore - Stopping msl cleanup thread
Failed to send message

Running the challenge thereafter again, I'm getting basically the same error: 

2023-09-28T16:29:37.039Z [main] DEBUG org.asamk.signal.util.IOUtils - XDG_RUNTIME_DIR not set, falling back to temp dir
2023-09-28T16:29:37.104Z [main] DEBUG org.asamk.signal.App - Starting signal-cli 0.12.1
2023-09-28T16:29:37.541Z [main] INFO  LibSignal - [libsignal]: rust/bridge/jni/src/logging.rs:156: Initializing libsignal version:0.30.0
2023-09-28T16:29:39.239Z [main] INFO  com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Starting...
2023-09-28T16:29:39.686Z [main] INFO  com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection org.sqlite.jdbc4.JDBC4Connection@77a98a6a
2023-09-28T16:29:39.697Z [main] INFO  com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Start completed.
2023-09-28T16:29:45.263Z [main] INFO  com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Shutdown initiated...
2023-09-28T16:29:45.283Z [main] INFO  com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Shutdown completed.
Submit challenge error: [400] Bad response: 400
org.whispersystems.signalservice.api.push.exceptions.NonSuccessfulResponseCodeException: [400] Bad response: 400
    at org.whispersystems.signalservice.internal.push.PushServiceSocket.validateServiceResponse(PushServiceSocket.java:1898)
    at org.whispersystems.signalservice.internal.push.PushServiceSocket.makeServiceRequest(PushServiceSocket.java:1842)
    at org.whispersystems.signalservice.internal.push.PushServiceSocket.makeServiceRequest(PushServiceSocket.java:1780)
    at org.whispersystems.signalservice.internal.push.PushServiceSocket.makeServiceRequest(PushServiceSocket.java:1774)
    at org.whispersystems.signalservice.internal.push.PushServiceSocket.submitRateLimitRecaptchaChallenge(PushServiceSocket.java:1123)
    at org.whispersystems.signalservice.api.SignalServiceAccountManager.submitRateLimitRecaptchaChallenge(SignalServiceAccountManager.java:905)
    at org.asamk.signal.manager.internal.ManagerImpl.submitRateLimitRecaptchaChallenge(ManagerImpl.java:334)
    at org.asamk.signal.commands.SubmitRateLimitChallengeCommand.handleCommand(SubmitRateLimitChallengeCommand.java:38)
    at org.asamk.signal.commands.CommandHandler.handleLocalCommand(CommandHandler.java:35)
    at org.asamk.signal.App.handleLocalCommand(App.java:276)
    at org.asamk.signal.App.handleCommand(App.java:192)
    at org.asamk.signal.App.init(App.java:144)
    at org.asamk.signal.Main.main(Main.java:60)
mattwr18 commented 11 months ago

@anotherbridge I don't have any experience with json-rpc mode, but I have solved these rate limit challenges before. The error in the second log output seems to indicate there was some error in solving the challenge:

Submit challenge error: [400] Bad response: 400

However, it's not clear what the error is. Is this the verbose output?

bbernhard commented 11 months ago

Sorry, completely forgot about that issue. I'll have a look whether a different GraalVM version creates a valid native image.

anotherbridge commented 11 months ago

@mattwr18 Yes, this is the verbose output. Unfortunately it doesn't provide much information on why it gets the response..

I got that when executing

signal-cli --config /home/.local/share/signal-cli -v submitRateLimitChallenge --challenge "<token>" --captcha "<captcha>"

where the <token> was taken from the response I got from trying to send a message and the <captcha> was generated from https://signalcaptchas.org/registration/generate in the same manner as I did when registering the number.

bbernhard commented 11 months ago

The issue with the native mode should be fixed with the next release. If you want to give it a try, use the following docker image: bbernhard/signal-cli-rest-api:0.123-dev

mattwr18 commented 11 months ago

@bbernhard I tested this out with native mode and 0.69 and it works great, thanks! I guess you have already received confirmation of this, but thought I would give feedback as well.

One issue that I wanted to discuss is related to @anotherbridge first error posted in this issue. We have some numbers that when we try to send messages to fail and we get the message in signal-cli 

Failed to send (some) messages:\n+49176xxxxxxxx: CAPTCHA proof required for sending to \"+49176xxxxxxxx\", available options \"RECAPTCHA, PUSH_CHALLENGE\" with challenge token \"1f209ee0-d487-4efc-xxxx-xxxxxxxxxxxx\", or wait \"86400\" seconds.\nTo get the captcha token, go to https://signalcaptchas.org/challenge/generate.html\nCheck the developer tools (F12) console for a failed redirect to signalcaptcha://\nEverything after signalcaptcha:// is the captcha token.\nUse the following command to submit the captcha token:\nsignal-cli submitRateLimitChallenge --challenge CHALLENGE_TOKEN --captcha CAPTCHA_TOKEN\nxxxxxxxxxxxxx\nFailed to send message\n

However, in signal-cli-rest-api we would just get the Failed to send message. This is related to the recently merged PR https://github.com/bbernhard/signal-cli-rest-api/pull/404 Now, we still do not get this more verbose message, but instead are getting the message @anotherbridge reported.

{
  "error": "WARN  SendHelper - Failed to send message due to IO exception: Unable to parse entity\nFailed to send message\n"
}

I also received a second error with:

strconv.ParseInt: parsing "WARN  ManagerImpl - No profile name set. When sending a message it's recommended to set a profile name with the updateProfile command. This may become mandatory in the future.\n1696440947443": invalid syntax

It seems to be throwing an error due to the 1696440947443, but I'm not sure why we didn't run into that error when testing it before @roschaefer put in the PR https://github.com/bbernhard/signal-cli-rest-api/pull/404. Maybe you might have some more insight @bbernhard ?

bbernhard commented 11 months ago

I've improved the error handling a bit. Can you maybe test the docker image bbernhard/signal-cli-rest-api:0.124-dev whether this improves the situation for you.

mattwr18 commented 11 months ago

@bbernhard I've done some quick initial testing and what I have encountered is that the changes introduced in :point_up: do in fact get rid of the strconv.ParseInt error, but I didn't get any further information why the request failed. There is a warning:

WARN  ManagerImpl - No profile name set. When sending a message it's recommended to set a profile name with the updateProfile command. This may become mandatory in the future.1696486348539

As far I know though, not having a profile name set did not result in a 400 Bad Request, but when I set the profile name the error is no longer being reported.

For the case where the number is still hitting the rate limit issue, for some reason the error message displayed in signal-cli-rest-api response is:

WARN  SendHelper - Failed to send message due to IO exception: Unable to parse entity
Network failure for "<NUMBER>"

even though I can see the entire message from the output of signal-cli

bbernhard commented 11 months ago

As far I know though, not having a profile name set did not result in a 400 Bad Request, but when I set the profile name the error is no longer being reported.

yeah, it is a bit unfortunate, that a warning output in signal-cli is now reported as an error in the REST API. But not sure if there is much we can do about that. I mean, we could try to parse those warning messages, but I think this will be quite error prone :/

Unfortunately I can't reproduce the error here, as I do not run in any rate limiting issues. But I've added some debug logging to the bbernhard/signal-cli-rest-api:0.126-dev image. Please first enable debug logging with curl -X POST -H "Content-Type: application/json" -d '{"logging": {"level": "debug"}}' 'http://127.0.0.1:8080/v1/configuration' and then call the send method again.

In the docker log file you should see the following lines:

signal-cli-rest-api-signal-cli-rest-api-1  | time="2023-10-05T16:01:23Z" level=debug msg="signal-cli output (stdout): <some output>"
signal-cli-rest-api-signal-cli-rest-api-1  | time="2023-10-05T16:01:23Z" level=debug msg="signal-cli output (stderr): <some output>"

Does the log file contain more information then you get back via REST?

If you want to disable the debug logging again, simply restart the docker container.

sebthesun commented 11 months ago

I get the same error as reported first by @anotherbridge with the latest docker. If I want to add a new recipient I have to run a challenge by signal-cli in the container.

mattwr18 commented 10 months ago

@bbernhard sorry it took so long to test this out. I was working on some other things and just got a chance to get back to it. Here is the output from the additional logging:

time="2023-10-17T18:17:35Z" level=debug msg="signal-cli output (stdout): Failed to send (some) messages:\n<signal_phone_number>: Network failure for \"<signal_phone_number>\"\n1697566654816\n"
time="2023-10-17T18:17:35Z" level=debug msg="signal-cli output (stderr): WARN  SendHelper - Failed to send message due to IO exception: Unable to parse entity\nFailed to send message\n"

This is the same info I get back via REST, but it is different from the info I get if I try to send the same message to the same number via signal-cli directly.

mattwr18 commented 10 months ago

@bbernhard I tested this with the latest https://github.com/bbernhard/signal-cli-rest-api/releases/tag/0.70 and now we get the error message containing the information needed to resolve the rate limit challenge. Thank you :green_heart:

anotherbridge commented 10 months ago

I just confirmed what @mattwr18 already stated! Regarding that also question came up whether it is possible to solve the challenge via the API or is it mandatory to solve it using the signal-cli from within the container?

bbernhard commented 10 months ago

Currently that is only possible with signal-cli directly. But please create a new issue for that.