whisperfish/presage

Lots of InvalidSignedPreKeyId errors

k-bx opened this issue · 7 comments

k-bx commented

Sorry for not understanding the guts of the Signal protocol, but I just want to finally launch my bot on a "production" Signal account in order to do some useful work, but can't get it going. Things worked fine on my little test account.

After several failed attempts, I was able to "link" my presage as a new device. I am now trying to receive some messages, and getting tons of these:

[2023-02-23T14:27:03Z WARN  presage::store::sled] trusting new identity ProtocolAddress { name: "2ad6d5f5-f75a-484e-9539-804235bda596", device_id: DeviceId(1) }
[2023-02-23T14:27:03Z ERROR presage::manager] Error opening envelope: SignalProtocolError(InvalidSignedPreKeyId), message will be skipped!

Things don't improve over time, e.g. trusting that is mentioned in the warning doesn't make a difference. What should I do?

gferon commented

It sounds like the issue might have stemmed from having to link multiple times, which is really not supposed to happen. Can you try to delete the store directory completely and try again?

k-bx commented

Will do in a few days, thanks

k-bx commented

Hey @gferon . I've just tried this again with an Android device, no luck. Android is displaying the presage as linked, but receiving messages errors with "this client is not yet registered". How can I debug this?

Linking:


   ▄▄▄▄▄   ▄▄ ▄   ▄  ▄▄  ▄▄▄ ▄   ▄   ▄▄▄▄▄
           ▄  ▄▄ ▄▄ ▄  ▄▄▄ ▄ ▄▄▄ ▄
    ▄▄▄    ▄▄  ▄ ▄ ▄▄▄  ▄▄▄▄ ▄ ▄▄▄▄   ▄▄▄
  ▄▄▄▄▄▄▄   ▄ ▄   ▄ ▄▄ ▄ ▄▄ ▄▄  ▄ ▄ ▄▄▄▄▄▄▄
  ▄▄▄ ▄▄▄ ▄▄ ▄   ▄▄ ▄▄▄▄ ▄ ▄▄▄  ▄ ▄▄▄  ▄▄ ▄
     ▄  ▄ ▄▄ ▄▄    ▄▄  ▄▄▄  ▄     ▄▄▄▄  ▄ ▄
  ▄▄▄  ▄▄  ▄▄▄▄▄▄▄ ▄▄▄▄  ▄ ▄   ▄▄▄▄ ▄▄▄▄▄
   ▄  ▄ ▄ ▄ ▄ ▄ ▄▄  ▄ ▄ ▄▄▄▄▄▄  ▄▄    ▄▄▄
    ▄ ▄ ▄▄ ▄▄  ▄ ▄ ▄   ▄  ▄ ▄▄▄  ▄  ▄▄▄▄▄
       ▄▄▄    ▄ ▄   ▄▄▄ ▄         ▄ ▄▄▄▄▄▄
  ▄▄▄   ▄ ▄       ▄ ▄   ▄ ▄▄ ▄▄▄▄▄ ▄▄▄▄▄ ▄▄
    ▄▄▄ ▄  ▄▄▄  ▄▄▄  ▄   ▄  ▄▄ ▄▄▄▄▄▄▄▄▄▄▄▄
    ▄  ▄▄▄▄▄▄▄▄▄   ▄▄▄▄▄▄ ▄▄▄▄▄▄▄ ▄▄▄▄▄  ▄
  ▄ ▄▄▄ ▄▄▄▄  ▄▄      ▄    ▄  ▄▄▄▄ ▄▄ ▄ ▄ ▄
  ▄▄ ▄▄▄▄▄▄  ▄▄  ▄▄▄  ▄▄ ▄▄  ▄▄▄  ▄ ▄▄▄▄▄ ▄
     ▄▄ ▄▄ ▄▄▄▄▄▄▄▄▄  ▄▄    ▄ ▄ ▄ ▄  ▄▄▄▄▄
  ▄ ▄▄  ▄▄▄▄   ▄▄ ▄ ▄▄▄ ▄ ▄ ▄   ▄  ▄▄▄    ▄
   ▄▄▄▄▄  ▄  ▄▄▄▄   ▄▄▄ ▄▄  ▄▄  ▄▄  ▄  ▄▄ ▄
             ▄▄ ▄ ▄ ▄▄▄▄▄  ▄ ▄▄ ▄   ▄▄▄ ▄▄▄
    ▄▄▄   ▄▄▄▄▄▄▄▄ ▄▄   ▄▄▄▄▄▄▄▄▄ ▄▄▄▄▄▄ ▄
  ▄▄▄▄▄▄▄ ▄   ▄▄ ▄  ▄   ▄ ▄▄▄▄ ▄ ▄  ▄▄ ▄▄

[2023-03-16T08:41:42Z WARN  presage::store::sled] trusting new identity ProtocolAddress { name: "a176ebe3-5739-4a63-9e46-942f6c8dadb0", device_id: DeviceId(1) }
[2023-03-16T08:41:42Z WARN  presage::store::sled] trusting new identity ProtocolAddress { name: "a176ebe3-5739-4a63-9e46-942f6c8dadb0", device_id: DeviceId(2) }
[2023-03-16T08:41:42Z WARN  presage::store::sled] trusting new identity ProtocolAddress { name: "a176ebe3-5739-4a63-9e46-942f6c8dadb0", device_id: DeviceId(3) }




[2023-03-16T08:41:58Z WARN  presage::store::sled] trusting new identity ProtocolAddress { name: "a101610b-3eed-4791-a209-c5458a3c523f", device_id: DeviceId(2) }
[2023-03-16T08:42:04Z WARN  presage::store::sled] trusting new identity ProtocolAddress { name: "a101610b-3eed-4791-a209-c5458a3c523f", device_id: DeviceId(3) }
Timeout(Elapsed(()))

Receiving:

nc190@nc190:~/workspace/presage$ cargo run --example=cli -- --db-path ~/storage/presage receive
    Finished dev [unoptimized + debuginfo] target(s) in 0.60s
warning: the following packages contain code that will be rejected by a future version of Rust: nom v5.1.2, quick-xml v0.18.1
note: to see what the problems were, use the option `--future-incompat-report`, or run `cargo report future-incompatibilities --id 1`
     Running `target/debug/examples/cli --db-path /home/nc190/storage/presage receive`
Error: this client is not yet registered, please register or link as a secondary device
gferon commented

I see. This is most definitely an issue with presage since it never received synchronized contacts from your primary device. It should be optional and succeed while issuing a warning. I'll fix that later today!

EDIT: I'm not sure why it's not getting the contacts though, but this should be entirely optional.

  • 👍1
k-bx commented

Hey @gferon, any luck looking into this?

gferon commented

Hi @k-bx I just merged #136 which should help with the timeout you're seeing in your last comment, although it is unrelated to the issue you initially reported.

The synchronization can fail (because your phone doesn't send the data) when you try to link too many times (rate limiting), but should now be treated as a warning.

Can you try again and let me know what happens? Otherwise it would be helpful to link with RUST_LOG=presage=trace,libsignal=trace and send the logs to me. However, this will contain PII data, which is a problem for posting that here.

EDIT: linking whisperfish/libsignal-service-rs#53 for visibility, since log censoring would be really useful here.

k-bx commented

@gferon this time it also exited with an error, but succeeded in reading messages afterwards:

[2023-03-25T17:38:34Z TRACE libsignal_service::websocket] Decoded WebSocketMessage { r#type: Some(Response), request: None, response: Some(WebSocketResponseMessage { id: Some(...), status:
Some(200), message: Some("OK"), headers: ["Content-Length:0"], body: None }) }
[2023-03-25T17:38:40Z WARN  presage::manager] failed to synchronize contacts: timeout: deadline has elapsed
[2023-03-25T17:38:40Z DEBUG libsignal_service_hyper::push_service] HTTP request GET https://chat.signal.org/v1/accounts/whoami
...

Subsequent "receive" succeeded, thus I'm closing this issue since things are working. I am ok to give you the secret gist with more data to debug if needed.

Thanks for looking into this!

  • ❤️1