Code Monkey home page Code Monkey logo

Comments (8)

prabhpreet avatar prabhpreet commented on September 27, 2024

Noticed peer id 21, can you share your configuration/steps and logs?

from rosenpass.

aparcar avatar aparcar commented on September 27, 2024

It's a bit lengthy

public_key = "dut-public-key"
secret_key = "dut-secret-key"
listen = ["0.0.0.0:9999"]
verbosity = "Quiet"

[[peers]] # ATE-0
public_key = "ate-0-public-key"
endpoint = "192.168.2.1:50000"
key_out = "key_out_0"

[[peers]] # ATE-1
public_key = "ate-1-public-key"
endpoint = "192.168.2.1:50001"
key_out = "key_out_1"

[[peers]] # ATE-2
public_key = "ate-2-public-key"
endpoint = "192.168.2.1:50002"
key_out = "key_out_2"

[[peers]] # ATE-3
public_key = "ate-3-public-key"
endpoint = "192.168.2.1:50003"
key_out = "key_out_3"

[[peers]] # ATE-4
public_key = "ate-4-public-key"
endpoint = "192.168.2.1:50004"
key_out = "key_out_4"

[[peers]] # ATE-5
public_key = "ate-5-public-key"
endpoint = "192.168.2.1:50005"
key_out = "key_out_5"

[[peers]] # ATE-6
public_key = "ate-6-public-key"
endpoint = "192.168.2.1:50006"
key_out = "key_out_6"

[[peers]] # ATE-7
public_key = "ate-7-public-key"
endpoint = "192.168.2.1:50007"
key_out = "key_out_7"

[[peers]] # ATE-8
public_key = "ate-8-public-key"
endpoint = "192.168.2.1:50008"
key_out = "key_out_8"

[[peers]] # ATE-9
public_key = "ate-9-public-key"
endpoint = "192.168.2.1:50009"
key_out = "key_out_9"

[[peers]] # ATE-10
public_key = "ate-10-public-key"
endpoint = "192.168.2.1:50010"
key_out = "key_out_10"

[[peers]] # ATE-11
public_key = "ate-11-public-key"
endpoint = "192.168.2.1:50011"
key_out = "key_out_11"

[[peers]] # ATE-12
public_key = "ate-12-public-key"
endpoint = "192.168.2.1:50012"
key_out = "key_out_12"

[[peers]] # ATE-13
public_key = "ate-13-public-key"
endpoint = "192.168.2.1:50013"
key_out = "key_out_13"

[[peers]] # ATE-14
public_key = "ate-14-public-key"
endpoint = "192.168.2.1:50014"
key_out = "key_out_14"

[[peers]] # ATE-15
public_key = "ate-15-public-key"
endpoint = "192.168.2.1:50015"
key_out = "key_out_15"

[[peers]] # ATE-16
public_key = "ate-16-public-key"
endpoint = "192.168.2.1:50016"
key_out = "key_out_16"

[[peers]] # ATE-17
public_key = "ate-17-public-key"
endpoint = "192.168.2.1:50017"
key_out = "key_out_17"

[[peers]] # ATE-18
public_key = "ate-18-public-key"
endpoint = "192.168.2.1:50018"
key_out = "key_out_18"

[[peers]] # ATE-19
public_key = "ate-19-public-key"
endpoint = "192.168.2.1:50019"
key_out = "key_out_19"

[[peers]] # ATE-20
public_key = "ate-20-public-key"
endpoint = "192.168.2.1:50020"
key_out = "key_out_20"

[[peers]] # ATE-21
public_key = "ate-21-public-key"
endpoint = "192.168.2.1:50021"
key_out = "key_out_21"

[[peers]] # ATE-22
public_key = "ate-22-public-key"
endpoint = "192.168.2.1:50022"
key_out = "key_out_22"

[[peers]] # ATE-23
public_key = "ate-23-public-key"
endpoint = "192.168.2.1:50023"
key_out = "key_out_23"

[[peers]] # ATE-24
public_key = "ate-24-public-key"
endpoint = "192.168.2.1:50024"
key_out = "key_out_24"

[[peers]] # ATE-25
public_key = "ate-25-public-key"
endpoint = "192.168.2.1:50025"
key_out = "key_out_25"

[[peers]] # ATE-26
public_key = "ate-26-public-key"
endpoint = "192.168.2.1:50026"
key_out = "key_out_26"

[[peers]] # ATE-27
public_key = "ate-27-public-key"
endpoint = "192.168.2.1:50027"
key_out = "key_out_27"

[[peers]] # ATE-28
public_key = "ate-28-public-key"
endpoint = "192.168.2.1:50028"
key_out = "key_out_28"

[[peers]] # ATE-29
public_key = "ate-29-public-key"
endpoint = "192.168.2.1:50029"
key_out = "key_out_29"

[[peers]] # ATE-30
public_key = "ate-30-public-key"
endpoint = "192.168.2.1:50030"
key_out = "key_out_30"

[[peers]] # ATE-31
public_key = "ate-31-public-key"
endpoint = "192.168.2.1:50031"
key_out = "key_out_31"

[[peers]] # ATE-32
public_key = "ate-32-public-key"
endpoint = "192.168.2.1:50032"
key_out = "key_out_32"

[[peers]] # ATE-33
public_key = "ate-33-public-key"
endpoint = "192.168.2.1:50033"
key_out = "key_out_33"

[[peers]] # ATE-34
public_key = "ate-34-public-key"
endpoint = "192.168.2.1:50034"
key_out = "key_out_34"

[[peers]] # ATE-35
public_key = "ate-35-public-key"
endpoint = "192.168.2.1:50035"
key_out = "key_out_35"

[[peers]] # ATE-36
public_key = "ate-36-public-key"
endpoint = "192.168.2.1:50036"
key_out = "key_out_36"

[[peers]] # ATE-37
public_key = "ate-37-public-key"
endpoint = "192.168.2.1:50037"
key_out = "key_out_37"

[[peers]] # ATE-38
public_key = "ate-38-public-key"
endpoint = "192.168.2.1:50038"
key_out = "key_out_38"

[[peers]] # ATE-39
public_key = "ate-39-public-key"
endpoint = "192.168.2.1:50039"
key_out = "key_out_39"

[[peers]] # ATE-40
public_key = "ate-40-public-key"
endpoint = "192.168.2.1:50040"
key_out = "key_out_40"

[[peers]] # ATE-41
public_key = "ate-41-public-key"
endpoint = "192.168.2.1:50041"
key_out = "key_out_41"

[[peers]] # ATE-42
public_key = "ate-42-public-key"
endpoint = "192.168.2.1:50042"
key_out = "key_out_42"

[[peers]] # ATE-43
public_key = "ate-43-public-key"
endpoint = "192.168.2.1:50043"
key_out = "key_out_43"

[[peers]] # ATE-44
public_key = "ate-44-public-key"
endpoint = "192.168.2.1:50044"
key_out = "key_out_44"

[[peers]] # ATE-45
public_key = "ate-45-public-key"
endpoint = "192.168.2.1:50045"
key_out = "key_out_45"

[[peers]] # ATE-46
public_key = "ate-46-public-key"
endpoint = "192.168.2.1:50046"
key_out = "key_out_46"

[[peers]] # ATE-47
public_key = "ate-47-public-key"
endpoint = "192.168.2.1:50047"
key_out = "key_out_47"

[[peers]] # ATE-48
public_key = "ate-48-public-key"
endpoint = "192.168.2.1:50048"
key_out = "key_out_48"

[[peers]] # ATE-49
public_key = "ate-49-public-key"
endpoint = "192.168.2.1:50049"
key_out = "key_out_49"

from rosenpass.

prabhpreet avatar prabhpreet commented on September 27, 2024

Is there an older commit with the same setup where it did not show these duplicated warnings?

Can you please share complete logs of the exchange as well (with logging enabled of log::debug)

from rosenpass.

aparcar avatar aparcar commented on September 27, 2024

I can even reproduce it with a single peer:

[2024-06-03T16:38:40Z DEBUG rosenpass::protocol] Rx Ok(RespHello), processing
[2024-06-03T16:38:40Z WARN  rosenpass::app_server] No broker peer found for peer 0
[2024-06-03T16:38:41Z DEBUG rosenpass::protocol] Rx Ok(EmptyData), processing
[2024-06-03T16:38:54Z DEBUG rosenpass::protocol] Rx Ok(InitHello), processing
[2024-06-03T16:38:55Z DEBUG rosenpass::protocol] Rx Ok(InitHello) from 192.168.2.1:50000 under load, tx cookie reply message
[2024-06-03T16:38:55Z DEBUG rosenpass::protocol] Rx Ok(InitConf) from 192.168.2.1:50000 under load, skip cookie validation
[2024-06-03T16:38:55Z DEBUG rosenpass::protocol] Rx Ok(InitConf), processing
[2024-06-03T16:38:55Z WARN  rosenpass::app_server] No broker peer found for peer 0
[2024-06-03T16:38:55Z DEBUG rosenpass::protocol] Rx Ok(InitConf), processing
[2024-06-03T16:38:56Z WARN  rosenpass::app_server] No broker peer found for peer 0
[2024-06-03T16:40:56Z DEBUG rosenpass::protocol] Rx Ok(RespHello), processing
[2024-06-03T16:40:57Z WARN  rosenpass::app_server] No broker peer found for peer 0
[2024-06-03T16:40:58Z DEBUG rosenpass::protocol] Rx Ok(EmptyData), processing
[2024-06-03T16:42:57Z DEBUG rosenpass::protocol] Rx Ok(InitHello), processing
[2024-06-03T16:42:58Z DEBUG rosenpass::protocol] Rx Ok(InitHello) from 192.168.2.1:50000 under load, tx cookie reply message
[2024-06-03T16:42:58Z DEBUG rosenpass::protocol] Rx Ok(InitConf) from 192.168.2.1:50000 under load, skip cookie validation
[2024-06-03T16:42:58Z DEBUG rosenpass::protocol] Rx Ok(InitConf), processing
[2024-06-03T16:42:58Z WARN  rosenpass::app_server] No broker peer found for peer 0
[2024-06-03T16:42:58Z DEBUG rosenpass::protocol] Rx Ok(InitConf), processing
[2024-06-03T16:42:59Z WARN  rosenpass::app_server] No broker peer found for peer 0

from rosenpass.

prabhpreet avatar prabhpreet commented on September 27, 2024

Thanks for sharing, will look into this tommorow

from rosenpass.

prabhpreet avatar prabhpreet commented on September 27, 2024

Looked into this, and was able to reproduce/understand it:

ThreadId(3) 52:48.795191995Z: Rx:Ok(InitHello), Tx Ok(RespHello)
ThreadId(4) 52:48.878947710Z: Rx:Ok(RespHello), Tx Ok(InitConf)
ThreadId(3) 52:48.879091514Z: Rx Ok(InitConf) from [::1]:43794 under load, skip cookie validation
ThreadId(4) 52:48.909892158Z: Exchanged key with peer Exf82UPv1I6SOFrAVW5W9Cu3bhznmjJjUHkUivp7s3M=
ThreadId(4) 52:48.910392368Z: output-key
ThreadId(3) 52:48.960614622Z: Rx:Ok(InitConf), Tx Ok(EmptyData)
ThreadId(4) 52:48.960714287Z: error processing incoming message from [::1]:1025: Rx Ok(EmptyData) from [::1]:1025 is not processed under load disabled backtrace
ThreadId(3) 52:48.980541176Z: Exchanged key with peer QVZF/+B88dThALdJqb56pQWH4zH31QMxfX9kjU3X5RE=
ThreadId(3) 52:48.980754109Z: output-key
ThreadId(4) 52:49.211140355Z: Retransmitting Ok(InitConf) to 0
ThreadId(3) 52:49.291937497Z: Rx:Ok(InitConf), Tx Ok(EmptyData)
ThreadId(4) 52:49.326802537Z: Rx Ok(EmptyData), processing
ThreadId(3) 52:49.333510321Z: Exchanged key with peer QVZF/+B88dThALdJqb56pQWH4zH31QMxfX9kjU3X5RE=
ThreadId(3) 52:49.333881879Z: output-key

This is caused due to multiple conditions coming together:

  1. We have introduced a cookie mechanism which detects an under load condition if 50% of the polled events were non-blocking (i.e we were busy enough to not wait for anything come in). On an initiator, we discard incoming messages under load (for RespHello and EmptyData messages)
  2. For retransmissions of InitConf messages, we process it and issue a PSK again.

The combination of 1 and 2 causes the initiator to discard the last EmptyData message, while the responder has already set its PSK. The initiator then retransmits InitConf, and the responder processes and sets the PSK again.

from rosenpass.

prabhpreet avatar prabhpreet commented on September 27, 2024

Looked into this, and was able to reproduce/understand it:

ThreadId(3) 52:48.795191995Z: Rx:Ok(InitHello), Tx Ok(RespHello)
ThreadId(4) 52:48.878947710Z: Rx:Ok(RespHello), Tx Ok(InitConf)
ThreadId(3) 52:48.879091514Z: Rx Ok(InitConf) from [::1]:43794 under load, skip cookie validation
ThreadId(4) 52:48.909892158Z: Exchanged key with peer Exf82UPv1I6SOFrAVW5W9Cu3bhznmjJjUHkUivp7s3M=
ThreadId(4) 52:48.910392368Z: output-key
ThreadId(3) 52:48.960614622Z: Rx:Ok(InitConf), Tx Ok(EmptyData)
ThreadId(4) 52:48.960714287Z: error processing incoming message from [::1]:1025: Rx Ok(EmptyData) from [::1]:1025 is not processed under load disabled backtrace
ThreadId(3) 52:48.980541176Z: Exchanged key with peer QVZF/+B88dThALdJqb56pQWH4zH31QMxfX9kjU3X5RE=
ThreadId(3) 52:48.980754109Z: output-key
ThreadId(4) 52:49.211140355Z: Retransmitting Ok(InitConf) to 0
ThreadId(3) 52:49.291937497Z: Rx:Ok(InitConf), Tx Ok(EmptyData)
ThreadId(4) 52:49.326802537Z: Rx Ok(EmptyData), processing
ThreadId(3) 52:49.333510321Z: Exchanged key with peer QVZF/+B88dThALdJqb56pQWH4zH31QMxfX9kjU3X5RE=
ThreadId(3) 52:49.333881879Z: output-key

This is caused due to multiple conditions coming together:

  1. We have introduced a cookie mechanism which detects an under load condition if 50% of the polled events were non-blocking (i.e we were busy enough to not wait for anything come in). On an initiator, we discard incoming messages under load (for RespHello and EmptyData messages)
  2. For retransmissions of InitConf messages, we process it and issue a PSK again.

The combination of 1 and 2 causes the initiator to discard the last EmptyData message, while the responder has already set its PSK. The initiator then retransmits InitConf, and the responder processes and sets the PSK again.

I tried a quick test and we can fix condition 2 in the comment above by using the indication to only exchange PSK when biscuit number exceeds the last used biscuit number. Everything else can remain the same

rosenpass/rosenpass/src/protocol.rs

Lines 1961 to 1984 in 63ef621

pub fn handle_init_conf(&mut self, ic: &InitConf, rc: &mut EmptyData) -> Result<(PeerPtr, bool)> {
let mut exchanged = false;
// (peer, bn) ← LoadBiscuit(InitConf.biscuit)
// ICR1
let (peer, biscuit_no, mut core) = HandshakeState::load_biscuit(
self,
&ic.biscuit,
SessionId::from_slice(&ic.sidi),
SessionId::from_slice(&ic.sidr),
)?;
// ICR2
core.encrypt_and_mix(&mut [0u8; aead::TAG_LEN], &[])?;
// ICR3
core.mix(&ic.sidi)?.mix(&ic.sidr)?;
// ICR4
core.decrypt_and_mix(&mut [0u8; 0], &ic.auth)?;
// ICR5
if constant_time::compare(&*biscuit_no, &*peer.get(self).biscuit_used) > 0 {
exchanged = true;
// ICR6

rosenpass/rosenpass/src/protocol.rs

Lines 1112 to 1122 in 63ef621

Ok(MsgType::InitConf) => {
let msg_in: Ref<&[u8], Envelope<InitConf>> =
Ref::new(rx_buf).ok_or(RosenpassError::BufferSizeMismatch)?;
ensure!(msg_in.check_seal(self)?, seal_broken);
let mut msg_out = truncating_cast_into::<Envelope<EmptyData>>(tx_buf)?;
let (peer, if_exchange) = self.handle_init_conf(&msg_in.payload, &mut msg_out.payload)?;
len = self.seal_and_commit_msg(peer, MsgType::EmptyData, &mut msg_out)?;
exchanged = if_exchange;
peer
}

What do you think @koraa , @aparcar ?

from rosenpass.

prabhpreet avatar prabhpreet commented on September 27, 2024

@aparcar Github closed this issue by using "fixes". Please let me know if you are still seeing the issue on your end and reopen the issue

from rosenpass.

Related Issues (20)

Recommend Projects

  • React photo React

    A declarative, efficient, and flexible JavaScript library for building user interfaces.

  • Vue.js photo Vue.js

    🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.

  • Typescript photo Typescript

    TypeScript is a superset of JavaScript that compiles to clean JavaScript output.

  • TensorFlow photo TensorFlow

    An Open Source Machine Learning Framework for Everyone

  • Django photo Django

    The Web framework for perfectionists with deadlines.

  • D3 photo D3

    Bring data to life with SVG, Canvas and HTML. 📊📈🎉

Recommend Topics

  • javascript

    JavaScript (JS) is a lightweight interpreted programming language with first-class functions.

  • web

    Some thing interesting about web. New door for the world.

  • server

    A server is a program made to process requests and deliver data to clients.

  • Machine learning

    Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.

  • Game

    Some thing interesting about game, make everyone happy.

Recommend Org

  • Facebook photo Facebook

    We are working to build community through open source technology. NB: members must have two-factor auth.

  • Microsoft photo Microsoft

    Open source projects and samples from Microsoft.

  • Google photo Google

    Google ❤️ Open Source for everyone.

  • D3 photo D3

    Data-Driven Documents codes.