When sending a message to a group (as a secondary device), one can see in the main device that the message was sent (right side) but also that the same message was received from the own contact (left side). Additionally, other people in the chat also sometimes receive the message twice (see e.g. the Whisperfish Signal group).
This can be reproduced in the cli in the PR I made.
Also no need to hurry, just wanted to make sure it will not be forgotten.
Log (Censored, UUIDs replaced by UUID1 - UUID7)
```
[2022-08-04T15:56:15Z DEBUG cli] opening config database from CENSORED
[2022-08-04T15:56:15Z DEBUG libsignal_service_hyper::push_service] HTTP request GET https://chat.signal.org/v1/certificate/group/CENSORED/CENSORED
[2022-08-04T15:56:15Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE | WRITABLE
[2022-08-04T15:56:15Z DEBUG rustls::client::hs] No cached session for DnsName(DnsName(DnsName("chat.signal.org")))
[2022-08-04T15:56:15Z DEBUG rustls::client::hs] Not resuming any session
[2022-08-04T15:56:15Z TRACE rustls::client::hs] Sending ClientHello Message {
version: TLSv1_0,
payload: Handshake {
parsed: HandshakeMessagePayload {
typ: ClientHello,
payload: ClientHello(
ClientHelloPayload {
client_version: TLSv1_2,
random: CENSORED,
session_id: CENSORED,
cipher_suites: [
TLS13_AES_256_GCM_SHA384,
TLS13_AES_128_GCM_SHA256,
TLS13_CHACHA20_POLY1305_SHA256,
TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384,
TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256,
TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305_SHA256,
TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384,
TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256,
TLS_ECDHE_RSA_WITH_CHACHA20_POLY1305_SHA256,
TLS_EMPTY_RENEGOTIATION_INFO_SCSV,
],
compression_methods: [
Null,
],
extensions: [
SupportedVersions(
[
TLSv1_3,
TLSv1_2,
],
),
ECPointFormats(
[
Uncompressed,
],
),
NamedGroups(
[
X25519,
secp256r1,
secp384r1,
],
),
SignatureAlgorithms(
[
ECDSA_NISTP384_SHA384,
ECDSA_NISTP256_SHA256,
ED25519,
RSA_PSS_SHA512,
RSA_PSS_SHA384,
RSA_PSS_SHA256,
RSA_PKCS1_SHA512,
RSA_PKCS1_SHA384,
RSA_PKCS1_SHA256,
],
),
ExtendedMasterSecretRequest,
CertificateStatusRequest(
OCSP(
OCSPCertificateStatusRequest {
responder_ids: [],
extensions: ,
},
),
),
ServerName(
[
ServerName {
typ: HostName,
payload: HostName(
(
CENSORED,
DnsName(
"chat.signal.org",
),
),
),
},
],
),
SignedCertificateTimestampRequest,
KeyShare(
[
KeyShareEntry {
group: X25519,
payload: CENSORED,
},
],
),
PresharedKeyModes(
[
PSK_DHE_KE,
],
),
Protocols(
[
687474702f312e31,
],
),
SessionTicket(
Request,
),
],
},
),
},
encoded: CENSORED,
},
}
[2022-08-04T15:56:15Z TRACE rustls::client::hs] We got ServerHello ServerHelloPayload {
legacy_version: TLSv1_2,
random: CENSORED,
session_id: ,
cipher_suite: TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256,
compression_method: Null,
extensions: [
ServerNameAck,
RenegotiationInfo(
,
),
ECPointFormats(
[
Uncompressed,
ANSIX962CompressedPrime,
ANSIX962CompressedChar2,
],
),
Protocols(
[
687474702f312e31,
],
),
],
}
[2022-08-04T15:56:15Z DEBUG rustls::client::hs] ALPN protocol is Some(b"http/1.1")
[2022-08-04T15:56:15Z DEBUG rustls::client::hs] Using ciphersuite TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
[2022-08-04T15:56:15Z DEBUG rustls::client::tls12] ECDHE curve is ECParameters { curve_type: NamedCurve, named_group: secp256r1 }
[2022-08-04T15:56:15Z TRACE rustls::client::tls12] Server cert is [Certificate(b"CENSORED"), Certificate(b"CENSORED")]
[2022-08-04T15:56:15Z DEBUG rustls::client::tls12] Server DNS name is DnsName(DnsName(DnsName("chat.signal.org")))
[2022-08-04T15:56:15Z DEBUG rustls::client::tls12] Session not saved: server didn't allocate id or ticket
[2022-08-04T15:56:15Z TRACE want] signal: Want
[2022-08-04T15:56:15Z TRACE want] signal found waiting giver, notifying
[2022-08-04T15:56:15Z TRACE want] poll_want: taker wants!
[2022-08-04T15:56:16Z TRACE want] signal: Want
[2022-08-04T15:56:16Z TRACE want] signal: Want
[2022-08-04T15:56:16Z DEBUG libsignal_service_hyper::push_service] HTTP request GET https://storage.signal.org/v1/groups/
[2022-08-04T15:56:16Z TRACE want] signal: Want
[2022-08-04T15:56:16Z TRACE mio::poll] registering event source with poller: token=Token(1), interests=READABLE | WRITABLE
[2022-08-04T15:56:16Z DEBUG rustls::client::hs] No cached session for DnsName(DnsName(DnsName("storage.signal.org")))
[2022-08-04T15:56:16Z DEBUG rustls::client::hs] Not resuming any session
[2022-08-04T15:56:16Z TRACE rustls::client::hs] Sending ClientHello Message {
version: TLSv1_0,
payload: Handshake {
parsed: HandshakeMessagePayload {
typ: ClientHello,
payload: ClientHello(
ClientHelloPayload {
client_version: TLSv1_2,
random: CENSORED,
session_id: CENSORED,
cipher_suites: [
TLS13_AES_256_GCM_SHA384,
TLS13_AES_128_GCM_SHA256,
TLS13_CHACHA20_POLY1305_SHA256,
TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384,
TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256,
TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305_SHA256,
TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384,
TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256,
TLS_ECDHE_RSA_WITH_CHACHA20_POLY1305_SHA256,
TLS_EMPTY_RENEGOTIATION_INFO_SCSV,
],
compression_methods: [
Null,
],
extensions: [
SupportedVersions(
[
TLSv1_3,
TLSv1_2,
],
),
ECPointFormats(
[
Uncompressed,
],
),
NamedGroups(
[
X25519,
secp256r1,
secp384r1,
],
),
SignatureAlgorithms(
[
ECDSA_NISTP384_SHA384,
ECDSA_NISTP256_SHA256,
ED25519,
RSA_PSS_SHA512,
RSA_PSS_SHA384,
RSA_PSS_SHA256,
RSA_PKCS1_SHA512,
RSA_PKCS1_SHA384,
RSA_PKCS1_SHA256,
],
),
ExtendedMasterSecretRequest,
CertificateStatusRequest(
OCSP(
OCSPCertificateStatusRequest {
responder_ids: [],
extensions: ,
},
),
),
ServerName(
[
ServerName {
typ: HostName,
payload: HostName(
(
CENSORED,
DnsName(
"storage.signal.org",
),
),
),
},
],
),
SignedCertificateTimestampRequest,
KeyShare(
[
KeyShareEntry {
group: X25519,
payload: CENSORED,
},
],
),
PresharedKeyModes(
[
PSK_DHE_KE,
],
),
Protocols(
[
687474702f312e31,
],
),
SessionTicket(
Request,
),
],
},
),
},
encoded: CENSORED,
},
}
[2022-08-04T15:56:16Z TRACE rustls::client::hs] We got ServerHello ServerHelloPayload {
legacy_version: TLSv1_2,
random: CENSORED,
session_id: CENSORED,
cipher_suite: TLS13_AES_256_GCM_SHA384,
compression_method: Null,
extensions: [
KeyShare(
KeyShareEntry {
group: X25519,
payload: CENSORED,
},
),
SupportedVersions(
TLSv1_3,
),
],
}
[2022-08-04T15:56:16Z DEBUG rustls::client::hs] Using ciphersuite TLS13_AES_256_GCM_SHA384
[2022-08-04T15:56:16Z DEBUG rustls::client::tls13] Not resuming
[2022-08-04T15:56:16Z TRACE rustls::client::client_conn] EarlyData rejected
[2022-08-04T15:56:16Z TRACE rustls::conn] Dropping CCS
[2022-08-04T15:56:16Z DEBUG rustls::client::tls13] TLS1.3 encrypted extensions: [Protocols([687474702f312e31])]
[2022-08-04T15:56:16Z DEBUG rustls::client::hs] ALPN protocol is Some(b"http/1.1")
[2022-08-04T15:56:16Z TRACE rustls::client::tls13] Server cert is [Certificate(b"CENSORED")]
[2022-08-04T15:56:16Z TRACE want] signal: Want
[2022-08-04T15:56:16Z TRACE want] signal found waiting giver, notifying
[2022-08-04T15:56:16Z TRACE want] poll_want: taker wants!
[2022-08-04T15:56:16Z TRACE want] signal: Want
[2022-08-04T15:56:16Z TRACE want] signal: Want
[2022-08-04T15:56:16Z TRACE cli] Sending group message to UUID1
[2022-08-04T15:56:16Z TRACE cli] Sending group message to UUID2
[2022-08-04T15:56:16Z TRACE cli] Sending group message to UUID3
[2022-08-04T15:56:16Z TRACE cli] Sending group message to UUID4
[2022-08-04T15:56:16Z TRACE cli] Sending group message to UUID5
[2022-08-04T15:56:16Z TRACE cli] Sending group message to UUID6
[2022-08-04T15:56:16Z TRACE cli] Sending group message to UUID7
[2022-08-04T15:56:16Z TRACE libsignal_service::sender] sending message to default device
[2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.1
[2022-08-04T15:56:16Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID1", device_id: 1 }
[2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.1
[2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.1
[2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.1
[2022-08-04T15:56:16Z TRACE presage::config::sled] get identity-remote-UUID1.1
[2022-08-04T15:56:16Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:16Z TRACE presage::config::sled] inserting identity-remote-UUID1.1
[2022-08-04T15:56:16Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:16Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID1.1"
[2022-08-04T15:56:16Z INFO presage::config::sled] get_sub_device_sessions: session_prefix=session-UUID1.
[2022-08-04T15:56:16Z TRACE libsignal_service::sender] sending message to device 1
[2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.1
[2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.1
[2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.1
[2022-08-04T15:56:16Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID1", device_id: 1 }
[2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.1
[2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.1
[2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.1
[2022-08-04T15:56:16Z TRACE presage::config::sled] get identity-remote-UUID1.1
[2022-08-04T15:56:16Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:16Z TRACE presage::config::sled] inserting identity-remote-UUID1.1
[2022-08-04T15:56:16Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:16Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID1.1"
[2022-08-04T15:56:16Z TRACE libsignal_service::sender] sending message to device 2
[2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.2
[2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.2
[2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.2
[2022-08-04T15:56:16Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID1", device_id: 2 }
[2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.2
[2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.2
[2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.2
[2022-08-04T15:56:16Z INFO libsignal_protocol::session_cipher] Building PreKeyWhisperMessage for: UUID1.2 with preKeyId:
[2022-08-04T15:56:16Z TRACE presage::config::sled] get identity-remote-UUID1.2
[2022-08-04T15:56:16Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:16Z TRACE presage::config::sled] inserting identity-remote-UUID1.2
[2022-08-04T15:56:16Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:16Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID1.2"
[2022-08-04T15:56:16Z DEBUG libsignal_service_hyper::push_service] HTTP request PUT https://chat.signal.org/v1/messages/UUID1
[2022-08-04T15:56:16Z TRACE want] signal: Want
[2022-08-04T15:56:17Z TRACE want] signal: Want
[2022-08-04T15:56:17Z TRACE want] signal: Want
[2022-08-04T15:56:17Z DEBUG libsignal_service::sender] message sent!
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] sending message to default device
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID2.1
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID2", device_id: 1 }
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID2.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID2.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID2.1
[2022-08-04T15:56:17Z INFO libsignal_protocol::session_cipher] Building PreKeyWhisperMessage for: UUID2.1 with preKeyId:
[2022-08-04T15:56:17Z TRACE presage::config::sled] get identity-remote-UUID2.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] inserting identity-remote-UUID2.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID2.1"
[2022-08-04T15:56:17Z INFO presage::config::sled] get_sub_device_sessions: session_prefix=session-UUID2.
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] sending message to device 1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID2.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID2.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID2.1
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID2", device_id: 1 }
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID2.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID2.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID2.1
[2022-08-04T15:56:17Z INFO libsignal_protocol::session_cipher] Building PreKeyWhisperMessage for: UUID2.1 with preKeyId:
[2022-08-04T15:56:17Z TRACE presage::config::sled] get identity-remote-UUID2.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] inserting identity-remote-UUID2.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID2.1"
[2022-08-04T15:56:17Z DEBUG libsignal_service_hyper::push_service] HTTP request PUT https://chat.signal.org/v1/messages/UUID2
[2022-08-04T15:56:17Z TRACE want] signal: Want
[2022-08-04T15:56:17Z TRACE want] signal: Want
[2022-08-04T15:56:17Z DEBUG libsignal_service::sender] message sent!
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] sending message to default device
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID3.1
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID3", device_id: 1 }
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID3.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID3.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID3.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] get identity-remote-UUID3.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] inserting identity-remote-UUID3.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID3.1"
[2022-08-04T15:56:17Z INFO presage::config::sled] get_sub_device_sessions: session_prefix=session-UUID3.
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] sending message to device 1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID3.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID3.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID3.1
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID3", device_id: 1 }
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID3.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID3.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID3.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] get identity-remote-UUID3.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] inserting identity-remote-UUID3.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID3.1"
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] sending message to device 2
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID3.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID3.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID3.2
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID3", device_id: 2 }
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID3.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID3.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID3.2
[2022-08-04T15:56:17Z INFO libsignal_protocol::session_cipher] Building PreKeyWhisperMessage for: UUID3.2 with preKeyId: 29
[2022-08-04T15:56:17Z TRACE presage::config::sled] get identity-remote-UUID3.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] inserting identity-remote-UUID3.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID3.2"
[2022-08-04T15:56:17Z DEBUG libsignal_service_hyper::push_service] HTTP request PUT https://chat.signal.org/v1/messages/UUID3
[2022-08-04T15:56:17Z TRACE want] signal: Want
[2022-08-04T15:56:17Z TRACE want] signal: Want
[2022-08-04T15:56:17Z DEBUG libsignal_service::sender] message sent!
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] sending message to default device
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID4.1
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID4", device_id: 1 }
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID4.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID4.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID4.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] get identity-remote-UUID4.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] inserting identity-remote-UUID4.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID4.1"
[2022-08-04T15:56:17Z INFO presage::config::sled] get_sub_device_sessions: session_prefix=session-UUID4.
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] sending message to device 1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID4.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID4.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID4.1
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID4", device_id: 1 }
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID4.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID4.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID4.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] get identity-remote-UUID4.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] inserting identity-remote-UUID4.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID4.1"
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] sending message to device 2
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID4.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID4.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID4.2
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID4", device_id: 2 }
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID4.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID4.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID4.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] get identity-remote-UUID4.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] inserting identity-remote-UUID4.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID4.2"
[2022-08-04T15:56:17Z DEBUG libsignal_service_hyper::push_service] HTTP request PUT https://chat.signal.org/v1/messages/UUID4
[2022-08-04T15:56:17Z TRACE want] signal: Want
[2022-08-04T15:56:17Z TRACE want] signal: Want
[2022-08-04T15:56:17Z DEBUG libsignal_service::sender] message sent!
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] sending message to default device
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID5.1
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID5", device_id: 1 }
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID5.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID5.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID5.1
[2022-08-04T15:56:17Z INFO libsignal_protocol::session_cipher] Building PreKeyWhisperMessage for: UUID5.1 with preKeyId: 7
[2022-08-04T15:56:17Z TRACE presage::config::sled] get identity-remote-UUID5.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] inserting identity-remote-UUID5.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID5.1"
[2022-08-04T15:56:17Z INFO presage::config::sled] get_sub_device_sessions: session_prefix=session-UUID5.
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] sending message to device 1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID5.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID5.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID5.1
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID5", device_id: 1 }
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID5.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID5.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID5.1
[2022-08-04T15:56:17Z INFO libsignal_protocol::session_cipher] Building PreKeyWhisperMessage for: UUID5.1 with preKeyId: 7
[2022-08-04T15:56:17Z TRACE presage::config::sled] get identity-remote-UUID5.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] inserting identity-remote-UUID5.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID5.1"
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] sending message to device 2
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID5.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID5.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID5.2
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID5", device_id: 2 }
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID5.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID5.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID5.2
[2022-08-04T15:56:17Z INFO libsignal_protocol::session_cipher] Building PreKeyWhisperMessage for: UUID5.2 with preKeyId: 145
[2022-08-04T15:56:17Z TRACE presage::config::sled] get identity-remote-UUID5.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] inserting identity-remote-UUID5.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID5.2"
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] sending message to device 3
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID5.3
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID5.3
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID5.3
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID5", device_id: 3 }
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID5.3
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID5.3
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID5.3
[2022-08-04T15:56:17Z INFO libsignal_protocol::session_cipher] Building PreKeyWhisperMessage for: UUID5.3 with preKeyId: 143
[2022-08-04T15:56:17Z TRACE presage::config::sled] get identity-remote-UUID5.3
[2022-08-04T15:56:17Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] inserting identity-remote-UUID5.3
[2022-08-04T15:56:17Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID5.3"
[2022-08-04T15:56:17Z DEBUG libsignal_service_hyper::push_service] HTTP request PUT https://chat.signal.org/v1/messages/UUID5
[2022-08-04T15:56:17Z TRACE want] signal: Want
[2022-08-04T15:56:17Z TRACE want] signal: Want
[2022-08-04T15:56:17Z DEBUG libsignal_service::sender] message sent!
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] sending message to default device
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.1
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID6", device_id: 1 }
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] get identity-remote-UUID6.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] inserting identity-remote-UUID6.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID6.1"
[2022-08-04T15:56:17Z INFO presage::config::sled] get_sub_device_sessions: session_prefix=session-UUID6.
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] sending message to device 1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.1
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID6", device_id: 1 }
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] get identity-remote-UUID6.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] inserting identity-remote-UUID6.1
[2022-08-04T15:56:17Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID6.1"
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] sending message to device 2
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.2
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID6", device_id: 2 }
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] get identity-remote-UUID6.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] inserting identity-remote-UUID6.2
[2022-08-04T15:56:17Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID6.2"
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] sending message to device 3
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.3
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.3
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.3
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID6", device_id: 3 }
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.3
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.3
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.3
[2022-08-04T15:56:17Z TRACE presage::config::sled] get identity-remote-UUID6.3
[2022-08-04T15:56:17Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] inserting identity-remote-UUID6.3
[2022-08-04T15:56:17Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID6.3"
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] sending message to device 4
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.4
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.4
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.4
[2022-08-04T15:56:17Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID6", device_id: 4 }
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.4
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.4
[2022-08-04T15:56:17Z TRACE presage::config::sled] loading session from session-UUID6.4
[2022-08-04T15:56:17Z INFO libsignal_protocol::session_cipher] Building PreKeyWhisperMessage for: UUID6.4 with preKeyId: 34
[2022-08-04T15:56:17Z TRACE presage::config::sled] get identity-remote-UUID6.4
[2022-08-04T15:56:17Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] inserting identity-remote-UUID6.4
[2022-08-04T15:56:17Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:17Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID6.4"
[2022-08-04T15:56:17Z DEBUG libsignal_service_hyper::push_service] HTTP request PUT https://chat.signal.org/v1/messages/UUID6
[2022-08-04T15:56:18Z TRACE want] signal: Want
[2022-08-04T15:56:18Z TRACE want] signal: Want
[2022-08-04T15:56:18Z DEBUG libsignal_service::sender] message sent!
[2022-08-04T15:56:18Z INFO presage::config::sled] get_sub_device_sessions: session_prefix=session-UUID7.
[2022-08-04T15:56:18Z TRACE libsignal_service::sender] sending message to device 1
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.1
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.1
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.1
[2022-08-04T15:56:18Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID7", device_id: 1 }
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.1
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.1
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.1
[2022-08-04T15:56:18Z TRACE presage::config::sled] get identity-remote-UUID7.1
[2022-08-04T15:56:18Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:18Z TRACE presage::config::sled] inserting identity-remote-UUID7.1
[2022-08-04T15:56:18Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:18Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID7.1"
[2022-08-04T15:56:18Z TRACE libsignal_service::sender] sending message to device 2
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.2
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.2
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.2
[2022-08-04T15:56:18Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID7", device_id: 2 }
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.2
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.2
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.2
[2022-08-04T15:56:18Z TRACE presage::config::sled] get identity-remote-UUID7.2
[2022-08-04T15:56:18Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:18Z TRACE presage::config::sled] inserting identity-remote-UUID7.2
[2022-08-04T15:56:18Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:18Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID7.2"
[2022-08-04T15:56:18Z TRACE libsignal_service::sender] sending message to device 3
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.3
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.3
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.3
[2022-08-04T15:56:18Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID7", device_id: 3 }
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.3
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.3
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.3
[2022-08-04T15:56:18Z INFO libsignal_protocol::session_cipher] Building PreKeyWhisperMessage for: UUID7.3 with preKeyId: 15
[2022-08-04T15:56:18Z TRACE presage::config::sled] get identity-remote-UUID7.3
[2022-08-04T15:56:18Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:18Z TRACE presage::config::sled] inserting identity-remote-UUID7.3
[2022-08-04T15:56:18Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:18Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID7.3"
[2022-08-04T15:56:18Z TRACE libsignal_service::sender] sending message to device 4
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.4
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.4
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.4
[2022-08-04T15:56:18Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID7", device_id: 4 }
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.4
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.4
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.4
[2022-08-04T15:56:18Z TRACE presage::config::sled] get identity-remote-UUID7.4
[2022-08-04T15:56:18Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:18Z TRACE presage::config::sled] inserting identity-remote-UUID7.4
[2022-08-04T15:56:18Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:18Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID7.4"
[2022-08-04T15:56:18Z TRACE libsignal_service::sender] sending message to device 5
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.5
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.5
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.5
[2022-08-04T15:56:18Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID7", device_id: 5 }
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.5
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.5
[2022-08-04T15:56:18Z TRACE presage::config::sled] loading session from session-UUID7.5
[2022-08-04T15:56:18Z TRACE presage::config::sled] get identity-remote-UUID7.5
[2022-08-04T15:56:18Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:18Z TRACE presage::config::sled] inserting identity-remote-UUID7.5
[2022-08-04T15:56:18Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:18Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID7.5"
[2022-08-04T15:56:18Z DEBUG libsignal_service_hyper::push_service] HTTP request PUT https://chat.signal.org/v1/messages/UUID7
[2022-08-04T15:56:18Z TRACE want] signal: Want
[2022-08-04T15:56:18Z TRACE want] signal: Want
[2022-08-04T15:56:18Z DEBUG libsignal_service::sender] message sent!
[2022-08-04T15:56:18Z INFO presage::config::sled] get_sub_device_sessions: session_prefix=session-UUID7.
[2022-08-04T15:56:20Z INFO presage::config::sled] get_sub_device_sessions: session_prefix=session-+491759921168.
[2022-08-04T15:56:20Z TRACE libsignal_service::sender] sending message to device 1
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.1
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.1
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.1
[2022-08-04T15:56:20Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID7", device_id: 1 }
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.1
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.1
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.1
[2022-08-04T15:56:20Z TRACE presage::config::sled] get identity-remote-UUID7.1
[2022-08-04T15:56:20Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:20Z TRACE presage::config::sled] inserting identity-remote-UUID7.1
[2022-08-04T15:56:20Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:20Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID7.1"
[2022-08-04T15:56:20Z TRACE libsignal_service::sender] sending message to device 2
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.2
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.2
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.2
[2022-08-04T15:56:20Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID7", device_id: 2 }
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.2
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.2
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.2
[2022-08-04T15:56:20Z TRACE presage::config::sled] get identity-remote-UUID7.2
[2022-08-04T15:56:20Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:20Z TRACE presage::config::sled] inserting identity-remote-UUID7.2
[2022-08-04T15:56:20Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:20Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID7.2"
[2022-08-04T15:56:20Z TRACE libsignal_service::sender] sending message to device 3
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.3
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.3
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.3
[2022-08-04T15:56:20Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID7", device_id: 3 }
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.3
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.3
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.3
[2022-08-04T15:56:20Z INFO libsignal_protocol::session_cipher] Building PreKeyWhisperMessage for: UUID7.3 with preKeyId: 15
[2022-08-04T15:56:20Z TRACE presage::config::sled] get identity-remote-UUID7.3
[2022-08-04T15:56:20Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:20Z TRACE presage::config::sled] inserting identity-remote-UUID7.3
[2022-08-04T15:56:20Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:20Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID7.3"
[2022-08-04T15:56:20Z TRACE libsignal_service::sender] sending message to device 4
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.4
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.4
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.4
[2022-08-04T15:56:20Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID7", device_id: 4 }
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.4
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.4
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.4
[2022-08-04T15:56:20Z TRACE presage::config::sled] get identity-remote-UUID7.4
[2022-08-04T15:56:20Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:20Z TRACE presage::config::sled] inserting identity-remote-UUID7.4
[2022-08-04T15:56:20Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:20Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID7.4"
[2022-08-04T15:56:20Z TRACE libsignal_service::sender] sending message to device 5
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.5
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.5
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.5
[2022-08-04T15:56:20Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID7", device_id: 5 }
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.5
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.5
[2022-08-04T15:56:20Z TRACE presage::config::sled] loading session from session-UUID7.5
[2022-08-04T15:56:20Z TRACE presage::config::sled] get identity-remote-UUID7.5
[2022-08-04T15:56:20Z TRACE presage::config::sled] saving identity
[2022-08-04T15:56:20Z TRACE presage::config::sled] inserting identity-remote-UUID7.5
[2022-08-04T15:56:20Z TRACE presage::config::sled] saved identity
[2022-08-04T15:56:20Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID7.5"
[2022-08-04T15:56:20Z DEBUG libsignal_service_hyper::push_service] HTTP request PUT https://chat.signal.org/v1/messages/UUID7
[2022-08-04T15:56:20Z TRACE want] signal: Want
[2022-08-04T15:56:20Z TRACE want] signal: Want
[2022-08-04T15:56:20Z DEBUG libsignal_service::sender] message sent!
[2022-08-04T15:56:20Z TRACE mio::poll] deregistering event source from poller
[2022-08-04T15:56:20Z TRACE want] signal: Closed
[2022-08-04T15:56:20Z TRACE mio::poll] deregistering event source from poller
[2022-08-04T15:56:20Z TRACE want] signal: Closed
```
When sending a message to a group (as a secondary device), one can see in the main device that the message was sent (right side) but also that the same message was received from the own contact (left side). Additionally, other people in the chat also sometimes receive the message twice (see e.g. the Whisperfish Signal group).
This can be reproduced in the cli in the PR I made.
Also no need to hurry, just wanted to make sure it will not be forgotten.
Log (Censored, UUIDs replaced by UUID1 - UUID7)
``` [2022-08-04T15:56:15Z DEBUG cli] opening config database from CENSORED [2022-08-04T15:56:15Z DEBUG libsignal_service_hyper::push_service] HTTP request GET https://chat.signal.org/v1/certificate/group/CENSORED/CENSORED [2022-08-04T15:56:15Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE | WRITABLE [2022-08-04T15:56:15Z DEBUG rustls::client::hs] No cached session for DnsName(DnsName(DnsName("chat.signal.org"))) [2022-08-04T15:56:15Z DEBUG rustls::client::hs] Not resuming any session [2022-08-04T15:56:15Z TRACE rustls::client::hs] Sending ClientHello Message { version: TLSv1_0, payload: Handshake { parsed: HandshakeMessagePayload { typ: ClientHello, payload: ClientHello( ClientHelloPayload { client_version: TLSv1_2, random: CENSORED, session_id: CENSORED, cipher_suites: [ TLS13_AES_256_GCM_SHA384, TLS13_AES_128_GCM_SHA256, TLS13_CHACHA20_POLY1305_SHA256, TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305_SHA256, TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_RSA_WITH_CHACHA20_POLY1305_SHA256, TLS_EMPTY_RENEGOTIATION_INFO_SCSV, ], compression_methods: [ Null, ], extensions: [ SupportedVersions( [ TLSv1_3, TLSv1_2, ], ), ECPointFormats( [ Uncompressed, ], ), NamedGroups( [ X25519, secp256r1, secp384r1, ], ), SignatureAlgorithms( [ ECDSA_NISTP384_SHA384, ECDSA_NISTP256_SHA256, ED25519, RSA_PSS_SHA512, RSA_PSS_SHA384, RSA_PSS_SHA256, RSA_PKCS1_SHA512, RSA_PKCS1_SHA384, RSA_PKCS1_SHA256, ], ), ExtendedMasterSecretRequest, CertificateStatusRequest( OCSP( OCSPCertificateStatusRequest { responder_ids: [], extensions: , }, ), ), ServerName( [ ServerName { typ: HostName, payload: HostName( ( CENSORED, DnsName( "chat.signal.org", ), ), ), }, ], ), SignedCertificateTimestampRequest, KeyShare( [ KeyShareEntry { group: X25519, payload: CENSORED, }, ], ), PresharedKeyModes( [ PSK_DHE_KE, ], ), Protocols( [ 687474702f312e31, ], ), SessionTicket( Request, ), ], }, ), }, encoded: CENSORED, }, } [2022-08-04T15:56:15Z TRACE rustls::client::hs] We got ServerHello ServerHelloPayload { legacy_version: TLSv1_2, random: CENSORED, session_id: , cipher_suite: TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, compression_method: Null, extensions: [ ServerNameAck, RenegotiationInfo( , ), ECPointFormats( [ Uncompressed, ANSIX962CompressedPrime, ANSIX962CompressedChar2, ], ), Protocols( [ 687474702f312e31, ], ), ], } [2022-08-04T15:56:15Z DEBUG rustls::client::hs] ALPN protocol is Some(b"http/1.1") [2022-08-04T15:56:15Z DEBUG rustls::client::hs] Using ciphersuite TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256 [2022-08-04T15:56:15Z DEBUG rustls::client::tls12] ECDHE curve is ECParameters { curve_type: NamedCurve, named_group: secp256r1 } [2022-08-04T15:56:15Z TRACE rustls::client::tls12] Server cert is [Certificate(b"CENSORED"), Certificate(b"CENSORED")] [2022-08-04T15:56:15Z DEBUG rustls::client::tls12] Server DNS name is DnsName(DnsName(DnsName("chat.signal.org"))) [2022-08-04T15:56:15Z DEBUG rustls::client::tls12] Session not saved: server didn't allocate id or ticket [2022-08-04T15:56:15Z TRACE want] signal: Want [2022-08-04T15:56:15Z TRACE want] signal found waiting giver, notifying [2022-08-04T15:56:15Z TRACE want] poll_want: taker wants! [2022-08-04T15:56:16Z TRACE want] signal: Want [2022-08-04T15:56:16Z TRACE want] signal: Want [2022-08-04T15:56:16Z DEBUG libsignal_service_hyper::push_service] HTTP request GET https://storage.signal.org/v1/groups/ [2022-08-04T15:56:16Z TRACE want] signal: Want [2022-08-04T15:56:16Z TRACE mio::poll] registering event source with poller: token=Token(1), interests=READABLE | WRITABLE [2022-08-04T15:56:16Z DEBUG rustls::client::hs] No cached session for DnsName(DnsName(DnsName("storage.signal.org"))) [2022-08-04T15:56:16Z DEBUG rustls::client::hs] Not resuming any session [2022-08-04T15:56:16Z TRACE rustls::client::hs] Sending ClientHello Message { version: TLSv1_0, payload: Handshake { parsed: HandshakeMessagePayload { typ: ClientHello, payload: ClientHello( ClientHelloPayload { client_version: TLSv1_2, random: CENSORED, session_id: CENSORED, cipher_suites: [ TLS13_AES_256_GCM_SHA384, TLS13_AES_128_GCM_SHA256, TLS13_CHACHA20_POLY1305_SHA256, TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305_SHA256, TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_RSA_WITH_CHACHA20_POLY1305_SHA256, TLS_EMPTY_RENEGOTIATION_INFO_SCSV, ], compression_methods: [ Null, ], extensions: [ SupportedVersions( [ TLSv1_3, TLSv1_2, ], ), ECPointFormats( [ Uncompressed, ], ), NamedGroups( [ X25519, secp256r1, secp384r1, ], ), SignatureAlgorithms( [ ECDSA_NISTP384_SHA384, ECDSA_NISTP256_SHA256, ED25519, RSA_PSS_SHA512, RSA_PSS_SHA384, RSA_PSS_SHA256, RSA_PKCS1_SHA512, RSA_PKCS1_SHA384, RSA_PKCS1_SHA256, ], ), ExtendedMasterSecretRequest, CertificateStatusRequest( OCSP( OCSPCertificateStatusRequest { responder_ids: [], extensions: , }, ), ), ServerName( [ ServerName { typ: HostName, payload: HostName( ( CENSORED, DnsName( "storage.signal.org", ), ), ), }, ], ), SignedCertificateTimestampRequest, KeyShare( [ KeyShareEntry { group: X25519, payload: CENSORED, }, ], ), PresharedKeyModes( [ PSK_DHE_KE, ], ), Protocols( [ 687474702f312e31, ], ), SessionTicket( Request, ), ], }, ), }, encoded: CENSORED, }, } [2022-08-04T15:56:16Z TRACE rustls::client::hs] We got ServerHello ServerHelloPayload { legacy_version: TLSv1_2, random: CENSORED, session_id: CENSORED, cipher_suite: TLS13_AES_256_GCM_SHA384, compression_method: Null, extensions: [ KeyShare( KeyShareEntry { group: X25519, payload: CENSORED, }, ), SupportedVersions( TLSv1_3, ), ], } [2022-08-04T15:56:16Z DEBUG rustls::client::hs] Using ciphersuite TLS13_AES_256_GCM_SHA384 [2022-08-04T15:56:16Z DEBUG rustls::client::tls13] Not resuming [2022-08-04T15:56:16Z TRACE rustls::client::client_conn] EarlyData rejected [2022-08-04T15:56:16Z TRACE rustls::conn] Dropping CCS [2022-08-04T15:56:16Z DEBUG rustls::client::tls13] TLS1.3 encrypted extensions: [Protocols([687474702f312e31])] [2022-08-04T15:56:16Z DEBUG rustls::client::hs] ALPN protocol is Some(b"http/1.1") [2022-08-04T15:56:16Z TRACE rustls::client::tls13] Server cert is [Certificate(b"CENSORED")] [2022-08-04T15:56:16Z TRACE want] signal: Want [2022-08-04T15:56:16Z TRACE want] signal found waiting giver, notifying [2022-08-04T15:56:16Z TRACE want] poll_want: taker wants! [2022-08-04T15:56:16Z TRACE want] signal: Want [2022-08-04T15:56:16Z TRACE want] signal: Want [2022-08-04T15:56:16Z TRACE cli] Sending group message to UUID1 [2022-08-04T15:56:16Z TRACE cli] Sending group message to UUID2 [2022-08-04T15:56:16Z TRACE cli] Sending group message to UUID3 [2022-08-04T15:56:16Z TRACE cli] Sending group message to UUID4 [2022-08-04T15:56:16Z TRACE cli] Sending group message to UUID5 [2022-08-04T15:56:16Z TRACE cli] Sending group message to UUID6 [2022-08-04T15:56:16Z TRACE cli] Sending group message to UUID7 [2022-08-04T15:56:16Z TRACE libsignal_service::sender] sending message to default device [2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.1 [2022-08-04T15:56:16Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID1", device_id: 1 } [2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.1 [2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.1 [2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.1 [2022-08-04T15:56:16Z TRACE presage::config::sled] get identity-remote-UUID1.1 [2022-08-04T15:56:16Z TRACE presage::config::sled] saving identity [2022-08-04T15:56:16Z TRACE presage::config::sled] inserting identity-remote-UUID1.1 [2022-08-04T15:56:16Z TRACE presage::config::sled] saved identity [2022-08-04T15:56:16Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID1.1" [2022-08-04T15:56:16Z INFO presage::config::sled] get_sub_device_sessions: session_prefix=session-UUID1. [2022-08-04T15:56:16Z TRACE libsignal_service::sender] sending message to device 1 [2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.1 [2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.1 [2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.1 [2022-08-04T15:56:16Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID1", device_id: 1 } [2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.1 [2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.1 [2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.1 [2022-08-04T15:56:16Z TRACE presage::config::sled] get identity-remote-UUID1.1 [2022-08-04T15:56:16Z TRACE presage::config::sled] saving identity [2022-08-04T15:56:16Z TRACE presage::config::sled] inserting identity-remote-UUID1.1 [2022-08-04T15:56:16Z TRACE presage::config::sled] saved identity [2022-08-04T15:56:16Z TRACE presage::config::sled] storing session for ProtocolAddress { name: "UUID1.1" [2022-08-04T15:56:16Z TRACE libsignal_service::sender] sending message to device 2 [2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.2 [2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.2 [2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.2 [2022-08-04T15:56:16Z TRACE libsignal_service::sender] encrypting message for ProtocolAddress { name: "UUID1", device_id: 2 } [2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.2 [2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.2 [2022-08-04T15:56:16Z TRACE presage::config::sled] loading session from session-UUID1.2 [2022-08-04T15:56:16Z INFO libsignal_protocol::session_cipher] Building PreKeyWhisperMessage for: UUID1.2 with preKeyId:Investigating this issue closer, it seems like this was already noticed in gurk-rs: https://github.com/boxdot/gurk-rs/issues/56. They also proposed a fix, which was closed: https://github.com/whisperfish/libsignal-service-rs/pull/108.
Maybe something like
merge_and_fetch_recipient
is required before sending something to a group? Or maybe needed in libsignal-service-rs?Seems like https://github.com/whisperfish/libsignal-service-rs/pull/156 would fix it, along with https://github.com/whisperfish/libsignal-service-rs/pull/157 documentation. Probably only a small fix in the
get_sub_device_sessions
will be needed.Indeed, I just committed 559470cbb49bdb96dbec43e86e13c95c3f8cf113 which should fix the issue!
I noticed that commit and have tried something similar with Flare, but this broke everything without the upstream MR actually being merged.
Oops, sorry about that, I forgot to update the pointer to the upstream repository. EDIT: done now!
Thanks. Probably should point back to the master branch once it gets merged (and maybe also that libsignal-client update), but looks good for now.
(sidenote, I need to start versioning properly and introduce tags, I can't really guarantee that the
main
branch is functional at all times)I actually stopped pointing to the main branch a long time ago, as we kept breaking it.
I did not mean master, but a commit on the master. And yes, versioning would probably be good.