Skip to content

Commit b3fd2c2

Browse files
lexnvlexnv
authored
crypto/noise: Show peerIDs that fail to decode (#392)
This PR enriches the errors coming from the crypto/noise decryption by providing peer IDs. This is useful for debugging: - paritytech/polkadot-sdk#8525 --------- Signed-off-by: Alexandru Vasile <alexandru.vasile@parity.io>
1 parent db7cbb0 commit b3fd2c2

File tree

6 files changed

+102
-14
lines changed

6 files changed

+102
-14
lines changed

‎src/codec/identity.rs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -102,7 +102,7 @@ mod tests {
102102
let bytes = [3u8; 64];
103103
let mut bytes = BytesMut::from(&bytes[..]);
104104

105-
let decoded = codec.decode(&mut bytes);
105+
assert!(codec.decode(&mut bytes).unwrap().is_none());
106106
}
107107

108108
#[test]

‎src/crypto/noise/mod.rs

Lines changed: 87 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -350,6 +350,8 @@ pub struct NoiseSocket<S: AsyncRead + AsyncWrite + Unpin> {
350350
read_buffer: Vec<u8>,
351351
canonical_max_read: usize,
352352
decrypt_buffer: Option<Vec<u8>>,
353+
peer: PeerId,
354+
ty: HandshakeTransport,
353355
}
354356

355357
impl<S: AsyncRead + AsyncWrite + Unpin> NoiseSocket<S> {
@@ -358,6 +360,8 @@ impl<S: AsyncRead + AsyncWrite + Unpin> NoiseSocket<S> {
358360
noise: NoiseContext,
359361
max_read_ahead_factor: usize,
360362
max_write_buffer_size: usize,
363+
peer: PeerId,
364+
ty: HandshakeTransport,
361365
) -> Self {
362366
Self {
363367
io,
@@ -380,6 +384,8 @@ impl<S: AsyncRead + AsyncWrite + Unpin> NoiseSocket<S> {
380384
max_read: max_read_ahead_factor * MAX_NOISE_MSG_LEN,
381385
},
382386
canonical_max_read: max_read_ahead_factor * MAX_NOISE_MSG_LEN,
387+
peer,
388+
ty,
383389
}
384390
}
385391

@@ -424,7 +430,13 @@ impl<S: AsyncRead + AsyncWrite + Unpin> AsyncRead for NoiseSocket<S> {
424430
},
425431
};
426432

427-
tracing::trace!(target: LOG_TARGET, ?nread, "read data from socket");
433+
tracing::trace!(
434+
target: LOG_TARGET,
435+
?nread,
436+
ty = ?this.ty,
437+
peer = ?this.peer,
438+
"read data from socket"
439+
);
428440

429441
this.nread += nread;
430442
this.read_state = ReadState::ReadFrameLen;
@@ -433,13 +445,25 @@ impl<S: AsyncRead + AsyncWrite + Unpin> AsyncRead for NoiseSocket<S> {
433445
let mut remaining = match this.nread.checked_sub(this.offset) {
434446
Some(remaining) => remaining,
435447
None => {
436-
tracing::error!(target: LOG_TARGET, "offset is larger than the number of bytes read");
448+
tracing::error!(
449+
target: LOG_TARGET,
450+
ty = ?this.ty,
451+
peer = ?this.peer,
452+
nread = ?this.nread,
453+
offset = ?this.offset,
454+
"offset is larger than the number of bytes read"
455+
);
437456
return Poll::Ready(Err(io::ErrorKind::PermissionDenied.into()));
438457
}
439458
};
440459

441460
if remaining < 2 {
442-
tracing::trace!(target: LOG_TARGET, "reset read buffer");
461+
tracing::trace!(
462+
target: LOG_TARGET,
463+
ty = ?this.ty,
464+
peer = ?this.peer,
465+
"reset read buffer"
466+
);
443467
this.reset_read_state(remaining);
444468
continue;
445469
}
@@ -456,13 +480,20 @@ impl<S: AsyncRead + AsyncWrite + Unpin> AsyncRead for NoiseSocket<S> {
456480
}
457481
};
458482

459-
tracing::trace!(target: LOG_TARGET, "current frame size = {frame_size}");
483+
tracing::trace!(
484+
target: LOG_TARGET,
485+
ty = ?this.ty,
486+
peer = ?this.peer,
487+
"current frame size = {frame_size}"
488+
);
460489

461490
if remaining < frame_size {
462491
// `read_buffer` can fit the full frame size.
463492
if this.nread + frame_size < this.canonical_max_read {
464493
tracing::trace!(
465494
target: LOG_TARGET,
495+
ty = ?this.ty,
496+
peer = ?this.peer,
466497
max_size = ?this.canonical_max_read,
467498
next_frame_size = ?(this.nread + frame_size),
468499
"read buffer can fit the full frame",
@@ -475,7 +506,12 @@ impl<S: AsyncRead + AsyncWrite + Unpin> AsyncRead for NoiseSocket<S> {
475506
continue;
476507
}
477508

478-
tracing::trace!(target: LOG_TARGET, "use auxiliary buffer extension");
509+
tracing::trace!(
510+
target: LOG_TARGET,
511+
ty = ?this.ty,
512+
peer = ?this.peer,
513+
"use auxiliary buffer extension"
514+
);
479515

480516
// use the auxiliary memory at the end of the read buffer for reading the
481517
// frame
@@ -489,6 +525,8 @@ impl<S: AsyncRead + AsyncWrite + Unpin> AsyncRead for NoiseSocket<S> {
489525
if frame_size <= NOISE_EXTRA_ENCRYPT_SPACE {
490526
tracing::error!(
491527
target: LOG_TARGET,
528+
ty = ?this.ty,
529+
peer = ?this.peer,
492530
?frame_size,
493531
max_size = ?NOISE_EXTRA_ENCRYPT_SPACE,
494532
"invalid frame size",
@@ -542,7 +580,16 @@ impl<S: AsyncRead + AsyncWrite + Unpin> AsyncRead for NoiseSocket<S> {
542580
buf,
543581
) {
544582
Err(error) => {
545-
tracing::error!(target: LOG_TARGET, ?error, "failed to decrypt message");
583+
tracing::error!(
584+
target: LOG_TARGET,
585+
ty = ?this.ty,
586+
peer = ?this.peer,
587+
buf_len = ?buf.len(),
588+
frame_size = ?frame_size,
589+
?error,
590+
"failed to decrypt message"
591+
);
592+
546593
return Poll::Ready(Err(io::ErrorKind::InvalidData.into()));
547594
}
548595
Ok(nread) => {
@@ -560,7 +607,16 @@ impl<S: AsyncRead + AsyncWrite + Unpin> AsyncRead for NoiseSocket<S> {
560607
&mut buffer,
561608
) {
562609
Err(error) => {
563-
tracing::error!(target: LOG_TARGET, ?error, "failed to decrypt message");
610+
tracing::error!(
611+
target: LOG_TARGET,
612+
ty = ?this.ty,
613+
peer = ?this.peer,
614+
buf_len = ?buf.len(),
615+
frame_size = ?frame_size,
616+
?error,
617+
"failed to decrypt message for smaller buffer"
618+
);
619+
564620
return Poll::Ready(Err(io::ErrorKind::InvalidData.into()));
565621
}
566622
Ok(nread) => {
@@ -605,7 +661,14 @@ impl<S: AsyncRead + AsyncWrite + Unpin> AsyncWrite for NoiseSocket<S> {
605661

606662
match this.noise.write_message(chunk, &mut this.encrypt_buffer[offset + 2..]) {
607663
Err(error) => {
608-
tracing::error!(target: LOG_TARGET, ?error, "failed to encrypt message");
664+
tracing::error!(
665+
target: LOG_TARGET,
666+
?error,
667+
ty = ?this.ty,
668+
peer = ?this.peer,
669+
"failed to encrypt message"
670+
);
671+
609672
return Poll::Ready(Err(io::ErrorKind::InvalidData.into()));
610673
}
611674
Ok(nwritten) => {
@@ -701,6 +764,15 @@ fn parse_and_verify_peer_id(
701764
Ok(peer_id)
702765
}
703766

767+
/// The type of the transport used for the crypto/noise protocol.
768+
///
769+
/// This is used for logging purposes.
770+
#[derive(Debug, Clone, Copy, PartialEq, Eq)]
771+
pub enum HandshakeTransport {
772+
Tcp,
773+
WebSocket,
774+
}
775+
704776
/// Perform Noise handshake.
705777
pub async fn handshake<S: AsyncRead + AsyncWrite + Unpin>(
706778
mut io: S,
@@ -709,9 +781,10 @@ pub async fn handshake<S: AsyncRead + AsyncWrite + Unpin>(
709781
max_read_ahead_factor: usize,
710782
max_write_buffer_size: usize,
711783
timeout: std::time::Duration,
784+
ty: HandshakeTransport,
712785
) -> Result<(NoiseSocket<S>, PeerId), NegotiationError> {
713786
let handle_handshake = async move {
714-
tracing::debug!(target: LOG_TARGET, ?role, "start noise handshake");
787+
tracing::debug!(target: LOG_TARGET, ?role, ?ty, "start noise handshake");
715788

716789
let mut noise = NoiseContext::new(keypair, role)?;
717790
let payload = match role {
@@ -727,7 +800,7 @@ pub async fn handshake<S: AsyncRead + AsyncWrite + Unpin>(
727800
let payload = handshake_schema::NoiseHandshakePayload::decode(message)
728801
.map_err(ParseError::from)
729802
.map_err(|err| {
730-
tracing::error!(target: LOG_TARGET, ?err, "failed to decode remote identity message");
803+
tracing::error!(target: LOG_TARGET, ?err, ?ty, "failed to decode remote identity message");
731804
err
732805
})?;
733806

@@ -764,6 +837,8 @@ pub async fn handshake<S: AsyncRead + AsyncWrite + Unpin>(
764837
noise.into_transport()?,
765838
max_read_ahead_factor,
766839
max_write_buffer_size,
840+
peer,
841+
ty,
767842
),
768843
peer,
769844
))
@@ -818,6 +893,7 @@ mod tests {
818893
MAX_READ_AHEAD_FACTOR,
819894
MAX_WRITE_BUFFER_SIZE,
820895
std::time::Duration::from_secs(10),
896+
HandshakeTransport::Tcp,
821897
),
822898
handshake(
823899
io2,
@@ -826,6 +902,7 @@ mod tests {
826902
MAX_READ_AHEAD_FACTOR,
827903
MAX_WRITE_BUFFER_SIZE,
828904
std::time::Duration::from_secs(10),
905+
HandshakeTransport::Tcp,
829906
)
830907
);
831908
let (mut res1, mut res2) = (res1.unwrap(), res2.unwrap());

‎src/protocol/libp2p/kademlia/bucket.rs

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -128,7 +128,7 @@ mod tests {
128128
.collect::<Vec<_>>();
129129

130130
let target = Key::from(PeerId::random());
131-
let mut iter = bucket.closest_iter(&target);
131+
let iter = bucket.closest_iter(&target);
132132
let mut prev = None;
133133

134134
for node in iter {
@@ -173,7 +173,7 @@ mod tests {
173173
.collect::<Vec<_>>();
174174

175175
let target = Key::from(PeerId::random());
176-
let mut iter = bucket.closest_iter(&target);
176+
let iter = bucket.closest_iter(&target);
177177
let mut prev = None;
178178
let mut num_peers = 0usize;
179179

‎src/transport/tcp/connection.rs

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -438,6 +438,7 @@ impl TcpConnection {
438438
max_read_ahead_factor,
439439
max_write_buffer_size,
440440
substream_open_timeout,
441+
noise::HandshakeTransport::Tcp,
441442
)
442443
.await?;
443444

@@ -1154,6 +1155,7 @@ mod tests {
11541155
5,
11551156
2,
11561157
std::time::Duration::from_secs(10),
1158+
noise::HandshakeTransport::Tcp,
11571159
)
11581160
.await
11591161
.unwrap();
@@ -1212,6 +1214,7 @@ mod tests {
12121214
5,
12131215
2,
12141216
std::time::Duration::from_secs(10),
1217+
noise::HandshakeTransport::Tcp,
12151218
)
12161219
.await
12171220
.unwrap();
@@ -1286,6 +1289,7 @@ mod tests {
12861289
5,
12871290
2,
12881291
std::time::Duration::from_secs(10),
1292+
noise::HandshakeTransport::Tcp,
12891293
)
12901294
.await
12911295
.unwrap();
@@ -1339,6 +1343,7 @@ mod tests {
13391343
5,
13401344
2,
13411345
std::time::Duration::from_secs(10),
1346+
noise::HandshakeTransport::Tcp,
13421347
)
13431348
.await
13441349
.unwrap();

‎src/transport/websocket/connection.rs

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -323,6 +323,7 @@ impl WebSocketConnection {
323323
max_read_ahead_factor,
324324
max_write_buffer_size,
325325
substream_open_timeout,
326+
noise::HandshakeTransport::WebSocket,
326327
)
327328
.await?;
328329

@@ -887,6 +888,7 @@ mod tests {
887888
5,
888889
2,
889890
std::time::Duration::from_secs(10),
891+
noise::HandshakeTransport::WebSocket,
890892
)
891893
.await
892894
.unwrap();
@@ -1094,6 +1096,7 @@ mod tests {
10941096
5,
10951097
2,
10961098
std::time::Duration::from_secs(10),
1099+
noise::HandshakeTransport::WebSocket,
10971100
)
10981101
.await
10991102
.unwrap();
@@ -1162,6 +1165,7 @@ mod tests {
11621165
5,
11631166
2,
11641167
std::time::Duration::from_secs(10),
1168+
noise::HandshakeTransport::WebSocket,
11651169
)
11661170
.await
11671171
.unwrap();
@@ -1261,6 +1265,7 @@ mod tests {
12611265
5,
12621266
2,
12631267
std::time::Duration::from_secs(10),
1268+
noise::HandshakeTransport::WebSocket,
12641269
)
12651270
.await
12661271
.unwrap();
@@ -1320,6 +1325,7 @@ mod tests {
13201325
5,
13211326
2,
13221327
std::time::Duration::from_secs(10),
1328+
noise::HandshakeTransport::WebSocket,
13231329
)
13241330
.await
13251331
.unwrap();

‎tests/conformance/rust/kademlia.rs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -24,7 +24,7 @@ use libp2p::{
2424
identify, identity,
2525
kad::{
2626
self, store::RecordStore, AddProviderOk, GetProvidersOk, InboundRequest,
27-
KademliaEvent as Libp2pKademliaEvent, QueryResult, RecordKey as Libp2pRecordKey,
27+
KademliaEvent as Libp2pKademliaEvent, QueryResult,
2828
},
2929
swarm::{keep_alive, AddressScore, NetworkBehaviour, SwarmBuilder, SwarmEvent},
3030
PeerId, Swarm,

0 commit comments

Comments
 (0)