aboutsummaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorRichard van der Hoff <richard@matrix.org>2016-04-26 11:44:32 +0100
committerRichard van der Hoff <richard@matrix.org>2016-04-26 17:55:26 +0100
commit9848f8445292ad3f7ff92bd4abfeb8f2d08ec32d (patch)
tree36f1f030f71bd16b85e0fe1aa77c42f457a3b168
parente7a2af1ede768589e612bad1c61b10186a1bb686 (diff)
Add some logging to help understand what's going on
-rw-r--r--include/olm/crypto.hh2
-rw-r--r--include/olm/logging.hh1
-rw-r--r--include/olm/memory.hh24
-rw-r--r--include/olm/ratchet.hh13
-rw-r--r--javascript/demo.html3
-rw-r--r--src/account.cpp9
-rw-r--r--src/crypto.cpp4
-rw-r--r--src/message.cpp22
-rw-r--r--src/ratchet.cpp95
-rw-r--r--src/session.cpp74
10 files changed, 220 insertions, 27 deletions
diff --git a/include/olm/crypto.hh b/include/olm/crypto.hh
index 7a05f8d..159bac7 100644
--- a/include/olm/crypto.hh
+++ b/include/olm/crypto.hh
@@ -17,6 +17,7 @@
#include <cstdint>
#include <cstddef>
+#include <string>
namespace olm {
@@ -26,6 +27,7 @@ static const std::size_t IV_LENGTH = 16;
struct Curve25519PublicKey {
std::uint8_t public_key[KEY_LENGTH];
+ std::string to_string() const;
};
diff --git a/include/olm/logging.hh b/include/olm/logging.hh
index 76c8053..f174712 100644
--- a/include/olm/logging.hh
+++ b/include/olm/logging.hh
@@ -23,6 +23,7 @@ const unsigned int LOG_ERROR = 2;
const unsigned int LOG_WARNING = 3;
const unsigned int LOG_INFO = 4;
const unsigned int LOG_DEBUG = 5;
+const unsigned int LOG_TRACE = 6;
void set_log_level(unsigned int log_level);
diff --git a/include/olm/memory.hh b/include/olm/memory.hh
index 128990a..89afd99 100644
--- a/include/olm/memory.hh
+++ b/include/olm/memory.hh
@@ -1,4 +1,4 @@
-/* Copyright 2015 OpenMarket Ltd
+/* Copyright 2015, 2016 OpenMarket Ltd
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
@@ -15,6 +15,9 @@
#include <cstddef>
#include <cstdint>
#include <cstring>
+#include <iomanip>
+#include <iostream>
+#include <sstream>
#include <type_traits>
namespace olm {
@@ -84,4 +87,23 @@ std::uint8_t * store_array(
return destination + sizeof(T);
}
+/** convert an array of bytes to a string representation */
+template<typename T>
+std::string bytes_to_string(T start, T end) {
+ std::ostringstream ss;
+ ss << std::hex << std::setfill('0');
+ while (start != end) {
+ ss << std::setw(2) << static_cast<int>(*start++);
+ if (start != end) {
+ ss << ":";
+ }
+ }
+ return ss.str();
+}
+
+template<typename T>
+std::string bytes_to_string(T start, size_t len) {
+ return bytes_to_string(start, start+len);
+}
+
} // namespace olm
diff --git a/include/olm/ratchet.hh b/include/olm/ratchet.hh
index 2393e5b..071e349 100644
--- a/include/olm/ratchet.hh
+++ b/include/olm/ratchet.hh
@@ -29,7 +29,6 @@ struct ChainKey {
SharedKey key;
};
-
struct MessageKey {
std::uint32_t index;
SharedKey key;
@@ -82,8 +81,18 @@ struct Ratchet {
/** The last error that happened encrypting or decrypting a message. */
ErrorCode last_error;
+ /**
+ * A count of the number of times the root key has been advanced; this is
+ * maintained purely for diagnostics.
+ *
+ * If sender_chain is empty, this will be the index of the current receiver
+ * chain (odd for Alice, even for Bob); otherwise, the index of the current
+ * sender chain (even for Alice, odd for Bob).
+ */
+ std::uint32_t chain_index;
+
/** The root key is used to generate chain keys from the ephemeral keys.
- * A new root_key derived each time a chain key is derived. */
+ * A new root_key derived each time a new chain is started. */
SharedKey root_key;
/** The sender chain is used to send messages. Each time a new ephemeral
diff --git a/javascript/demo.html b/javascript/demo.html
index 20e780b..bebf918 100644
--- a/javascript/demo.html
+++ b/javascript/demo.html
@@ -1,8 +1,7 @@
<html>
<head>
-<script src="../build/olm.js"></script>
+<script src="olm.js"></script>
<script>
-
document.addEventListener("DOMContentLoaded", function (event) {
function progress(who, message) {
var message_element = document.createElement("pre");
diff --git a/src/account.cpp b/src/account.cpp
index 43033c8..4fca953 100644
--- a/src/account.cpp
+++ b/src/account.cpp
@@ -1,4 +1,4 @@
-/* Copyright 2015 OpenMarket Ltd
+/* Copyright 2015, 2016 OpenMarket Ltd
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
@@ -14,9 +14,12 @@
*/
#include "olm/account.hh"
#include "olm/base64.hh"
+#include "olm/logging.hh"
#include "olm/pickle.hh"
#include "olm/memory.hh"
+static const char *LOG_CATEGORY = "olm::Account";
+
olm::Account::Account(
) : next_one_time_key_id(0),
last_error(olm::ErrorCode::SUCCESS) {
@@ -42,9 +45,11 @@ std::size_t olm::Account::remove_key(
if (olm::array_equal(i->key.public_key, public_key.public_key)) {
std::uint32_t id = i->id;
one_time_keys.erase(i);
+ olm::logf(olm::LOG_INFO, LOG_CATEGORY, "removed key id %i", id);
return id;
}
}
+ olm::logf(olm::LOG_WARNING, LOG_CATEGORY, "Couldn't find key to remove");
return std::size_t(-1);
}
@@ -64,6 +69,8 @@ std::size_t olm::Account::new_account(
random += KEY_LENGTH;
olm::curve25519_generate_key(random, identity_keys.curve25519_key);
+ olm::logf(olm::LOG_DEBUG, LOG_CATEGORY, "Created new account");
+
return 0;
}
diff --git a/src/crypto.cpp b/src/crypto.cpp
index 8867688..3801e93 100644
--- a/src/crypto.cpp
+++ b/src/crypto.cpp
@@ -101,6 +101,10 @@ inline static void hmac_sha256_final(
} // namespace
+std::string olm::Curve25519PublicKey::to_string() const {
+ return olm::bytes_to_string(std::begin(public_key),
+ std::end(public_key));
+};
void olm::curve25519_generate_key(
std::uint8_t const * random_32_bytes,
diff --git a/src/message.cpp b/src/message.cpp
index 05f707f..30abd9c 100644
--- a/src/message.cpp
+++ b/src/message.cpp
@@ -14,8 +14,13 @@
*/
#include "olm/message.hh"
+#include "olm/logging.hh"
+#include "olm/memory.hh"
+
namespace {
+static const char *LOG_CATEGORY = "olm::Message";
+
template<typename T>
static std::size_t varint_length(
T value
@@ -234,6 +239,13 @@ void olm::decode_message(
}
unknown = pos;
}
+ olm::logf(olm::LOG_TRACE, LOG_CATEGORY,
+ "Decoded message ver=%i ratchet_key=%s chain_idx=%i ciphertext=%s",
+ reader.version,
+ olm::bytes_to_string(reader.ratchet_key, reader.ratchet_key_length).c_str(),
+ reader.has_counter ? reader.counter : -1,
+ olm::bytes_to_string(reader.ciphertext, reader.ciphertext_length).c_str()
+ );
}
@@ -322,4 +334,14 @@ void olm::decode_one_time_key_message(
}
unknown = pos;
}
+
+ olm::logf(olm::LOG_TRACE, LOG_CATEGORY,
+ "Decoded pre-key message ver=%i one_time_key[Eb]=%s "
+ "base_key[Ea]=%s identity_key[Ia]=%s message=%s",
+ reader.version,
+ olm::bytes_to_string(reader.one_time_key, reader.one_time_key_length).c_str(),
+ olm::bytes_to_string(reader.base_key, reader.base_key_length).c_str(),
+ olm::bytes_to_string(reader.identity_key, reader.identity_key_length).c_str(),
+ olm::bytes_to_string(reader.message, reader.message_length).c_str()
+ );
}
diff --git a/src/ratchet.cpp b/src/ratchet.cpp
index 5ef1e56..03a0478 100644
--- a/src/ratchet.cpp
+++ b/src/ratchet.cpp
@@ -1,4 +1,4 @@
-/* Copyright 2015 OpenMarket Ltd
+/* Copyright 2015, 2016 OpenMarket Ltd
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
@@ -17,17 +17,31 @@
#include "olm/memory.hh"
#include "olm/cipher.hh"
#include "olm/pickle.hh"
-
+#include "olm/logging.hh"
#include <cstring>
namespace {
+static const char *LOG_CATEGORY = "olm::Ratchet";
+
static const std::uint8_t PROTOCOL_VERSION = 3;
static const std::uint8_t MESSAGE_KEY_SEED[1] = {0x01};
static const std::uint8_t CHAIN_KEY_SEED[1] = {0x02};
static const std::size_t MAX_MESSAGE_GAP = 2000;
+
+/**
+ * Advance the root key, creating a new message chain.
+ *
+ * @param root_key previous root key R(n-1)
+ * @param our_key our new ratchet key T(n)
+ * @param their_key their most recent ratchet key T(n-1)
+ * @param info table of constants for the ratchet function
+ * @param new_root_key[out] returns the new root key R(n)
+ * @param new_chain_key[out] returns the first chain key in the new chain
+ * C(n,0)
+ */
static void create_chain_key(
olm::SharedKey const & root_key,
olm::Curve25519KeyPair const & our_key,
@@ -55,6 +69,7 @@ static void create_chain_key(
static void advance_chain_key(
+ std::uint32_t chain_index,
olm::ChainKey const & chain_key,
olm::ChainKey & new_chain_key
) {
@@ -64,20 +79,24 @@ static void advance_chain_key(
new_chain_key.key
);
new_chain_key.index = chain_key.index + 1;
+ olm::logf(olm::LOG_DEBUG, LOG_CATEGORY, "Derived chain key C(%i,%i)",
+ chain_index, new_chain_key.index);
}
static void create_message_keys(
+ std::uint32_t chain_index,
olm::ChainKey const & chain_key,
olm::KdfInfo const & info,
- olm::MessageKey & message_key
-) {
+ olm::MessageKey & message_key) {
olm::hmac_sha256(
chain_key.key, sizeof(chain_key.key),
MESSAGE_KEY_SEED, sizeof(MESSAGE_KEY_SEED),
message_key.key
);
message_key.index = chain_key.index;
+ olm::logf(olm::LOG_DEBUG, LOG_CATEGORY, "Created message key with chain key C(%i,%i)",
+ chain_index, message_key.index);
}
@@ -98,6 +117,7 @@ static std::size_t verify_mac_and_decrypt(
static std::size_t verify_mac_and_decrypt_for_existing_chain(
olm::Ratchet const & session,
+ std::uint32_t chain_index,
olm::ChainKey const & chain,
olm::MessageReader const & reader,
std::uint8_t * plaintext, std::size_t max_plaintext_length
@@ -114,11 +134,11 @@ static std::size_t verify_mac_and_decrypt_for_existing_chain(
olm::ChainKey new_chain = chain;
while (new_chain.index < reader.counter) {
- advance_chain_key(new_chain, new_chain);
+ advance_chain_key(chain_index, new_chain, new_chain);
}
olm::MessageKey message_key;
- create_message_keys(new_chain, session.kdf_info, message_key);
+ create_message_keys(chain_index, new_chain, session.kdf_info, message_key);
std::size_t result = verify_mac_and_decrypt(
session.ratchet_cipher, message_key, reader,
@@ -150,14 +170,17 @@ static std::size_t verify_mac_and_decrypt_for_new_chain(
}
olm::load_array(new_chain.ratchet_key.public_key, reader.ratchet_key);
+ std::uint32_t chain_index = session.chain_index + 1;
create_chain_key(
session.root_key, session.sender_chain[0].ratchet_key,
new_chain.ratchet_key, session.kdf_info,
new_root_key, new_chain.chain_key
);
+ olm::logf(olm::LOG_DEBUG, LOG_CATEGORY, "Calculated new receiver chain R(%i)",
+ chain_index);
std::size_t result = verify_mac_and_decrypt_for_existing_chain(
- session, new_chain.chain_key, reader,
+ session, chain_index, new_chain.chain_key, reader,
plaintext, max_plaintext_length
);
olm::unset(new_root_key);
@@ -194,7 +217,9 @@ void olm::Ratchet::initialise_as_bob(
pos = olm::load_array(root_key, pos);
pos = olm::load_array(receiver_chains[0].chain_key.key, pos);
receiver_chains[0].ratchet_key = their_ratchet_key;
+ chain_index = 0;
olm::unset(derived_secrets);
+ olm::logf(olm::LOG_DEBUG, LOG_CATEGORY, "Initialised receiver chain R(0)");
}
@@ -215,7 +240,9 @@ void olm::Ratchet::initialise_as_alice(
pos = olm::load_array(root_key, pos);
pos = olm::load_array(sender_chain[0].chain_key.key, pos);
sender_chain[0].ratchet_key = our_ratchet_key;
+ chain_index = 0;
olm::unset(derived_secrets);
+ olm::logf(olm::LOG_DEBUG, LOG_CATEGORY, "Initialised sender chain R(0)");
}
namespace olm {
@@ -353,6 +380,7 @@ std::size_t olm::pickle_length(
length += olm::pickle_length(value.sender_chain);
length += olm::pickle_length(value.receiver_chains);
length += olm::pickle_length(value.skipped_message_keys);
+ length += olm::pickle_length(value.chain_index);
return length;
}
@@ -364,6 +392,7 @@ std::uint8_t * olm::pickle(
pos = pickle(pos, value.sender_chain);
pos = pickle(pos, value.receiver_chains);
pos = pickle(pos, value.skipped_message_keys);
+ pos = pickle(pos, value.chain_index);
return pos;
}
@@ -376,6 +405,7 @@ std::uint8_t const * olm::unpickle(
pos = unpickle(pos, end, value.sender_chain);
pos = unpickle(pos, end, value.receiver_chains);
pos = unpickle(pos, end, value.skipped_message_keys);
+ pos = unpickle(pos, end, value.chain_index);
return pos;
}
@@ -420,6 +450,9 @@ std::size_t olm::Ratchet::encrypt(
if (sender_chain.empty()) {
sender_chain.insert();
olm::curve25519_generate_key(random, sender_chain[0].ratchet_key);
+ olm::logf(olm::LOG_DEBUG, LOG_CATEGORY, "Created new ratchet key T(%i) %s",
+ chain_index + 1,
+ sender_chain[0].ratchet_key.to_string().c_str());
create_chain_key(
root_key,
sender_chain[0].ratchet_key,
@@ -427,11 +460,14 @@ std::size_t olm::Ratchet::encrypt(
kdf_info,
root_key, sender_chain[0].chain_key
);
+ olm::logf(olm::LOG_DEBUG, LOG_CATEGORY, "Initialised new sender chain R(%i)",
+ chain_index + 1);
+ chain_index++;
}
MessageKey keys;
- create_message_keys(sender_chain[0].chain_key, kdf_info, keys);
- advance_chain_key(sender_chain[0].chain_key, sender_chain[0].chain_key);
+ create_message_keys(chain_index, sender_chain[0].chain_key, kdf_info, keys);
+ advance_chain_key(chain_index, sender_chain[0].chain_key, sender_chain[0].chain_key);
std::size_t ciphertext_length = ratchet_cipher.encrypt_ciphertext_length(
plaintext_length
@@ -455,6 +491,14 @@ std::size_t olm::Ratchet::encrypt(
output, output_length
);
+ olm::logf(olm::LOG_TRACE, LOG_CATEGORY,
+ "Encoded message ver=%i ratchet_key=%s chain_idx=%i ciphertext=%s",
+ PROTOCOL_VERSION,
+ olm::bytes_to_string(writer.ratchet_key, olm::KEY_LENGTH).c_str(),
+ counter,
+ olm::bytes_to_string(writer.ciphertext, ciphertext_length).c_str()
+ );
+
olm::unset(keys);
return output_length;
}
@@ -481,6 +525,10 @@ std::size_t olm::Ratchet::decrypt(
std::uint8_t const * input, std::size_t input_length,
std::uint8_t * plaintext, std::size_t max_plaintext_length
) {
+ olm::logf(olm::LOG_TRACE, LOG_CATEGORY,
+ "Decrypting message %s",
+ olm::bytes_to_string(input, input_length).c_str());
+
olm::MessageReader reader;
olm::decode_message(
reader, input, input_length, ratchet_cipher.mac_length()
@@ -511,6 +559,13 @@ std::size_t olm::Ratchet::decrypt(
}
ReceiverChain * chain = nullptr;
+ auto receiver_chain_index = chain_index;
+ if (!sender_chain.empty()) {
+ // we've already advanced to the next (sender) chain; decrement to
+ // get back to the receiver chains
+ receiver_chain_index --;
+ }
+
for (olm::ReceiverChain & receiver_chain : receiver_chains) {
if (0 == std::memcmp(
receiver_chain.ratchet_key.public_key, reader.ratchet_key,
@@ -519,11 +574,14 @@ std::size_t olm::Ratchet::decrypt(
chain = &receiver_chain;
break;
}
+ receiver_chain_index -= 2;
}
std::size_t result = std::size_t(-1);
if (!chain) {
+ olm::logf(olm::LOG_DEBUG, LOG_CATEGORY,
+ "Sender ratchet key does not match known chain; starting new one");
result = verify_mac_and_decrypt_for_new_chain(
*this, reader, plaintext, max_plaintext_length
);
@@ -555,7 +613,8 @@ std::size_t olm::Ratchet::decrypt(
}
} else {
result = verify_mac_and_decrypt_for_existing_chain(
- *this, chain->chain_key, reader, plaintext, max_plaintext_length
+ *this, receiver_chain_index, chain->chain_key,
+ reader, plaintext, max_plaintext_length
);
}
@@ -565,28 +624,36 @@ std::size_t olm::Ratchet::decrypt(
}
if (!chain) {
- /* They have started using a new empheral ratchet key.
+ /* They have started using a new ephemeral ratchet key.
* We need to derive a new set of chain keys.
* We can discard our previous empheral ratchet key.
* We will generate a new key when we send the next message. */
+
chain = receiver_chains.insert();
olm::load_array(chain->ratchet_key.public_key, reader.ratchet_key);
+
+ // TODO: we've already done this once, in
+ // verify_mac_and_decrypt_for_new_chain(). we could reuse the result.
create_chain_key(
root_key, sender_chain[0].ratchet_key, chain->ratchet_key,
kdf_info, root_key, chain->chain_key
);
+
olm::unset(sender_chain[0]);
sender_chain.erase(sender_chain.begin());
+ receiver_chain_index = ++chain_index;
+ olm::logf(olm::LOG_DEBUG, LOG_CATEGORY, "Initialised new receiver chain R(%i)",
+ chain_index);
}
while (chain->chain_key.index < reader.counter) {
olm::SkippedMessageKey & key = *skipped_message_keys.insert();
- create_message_keys(chain->chain_key, kdf_info, key.message_key);
+ create_message_keys(receiver_chain_index, chain->chain_key, kdf_info, key.message_key);
key.ratchet_key = chain->ratchet_key;
- advance_chain_key(chain->chain_key, chain->chain_key);
+ advance_chain_key(receiver_chain_index, chain->chain_key, chain->chain_key);
}
- advance_chain_key(chain->chain_key, chain->chain_key);
+ advance_chain_key(receiver_chain_index, chain->chain_key, chain->chain_key);
return result;
}
diff --git a/src/session.cpp b/src/session.cpp
index 71c80e4..6a9bb7e 100644
--- a/src/session.cpp
+++ b/src/session.cpp
@@ -1,4 +1,4 @@
-/* Copyright 2015 OpenMarket Ltd
+/* Copyright 2015, 2016 OpenMarket Ltd
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
@@ -16,6 +16,7 @@
#include "olm/cipher.hh"
#include "olm/crypto.hh"
#include "olm/account.hh"
+#include "olm/logging.hh"
#include "olm/memory.hh"
#include "olm/message.hh"
#include "olm/pickle.hh"
@@ -24,6 +25,8 @@
namespace {
+static const char *LOG_CATEGORY = "olm::Session";
+
static const std::uint8_t PROTOCOL_VERSION = 0x3;
static const std::uint8_t ROOT_KDF_INFO[] = "OLM_ROOT";
@@ -65,11 +68,21 @@ std::size_t olm::Session::new_outbound_session(
return std::size_t(-1);
}
+ olm::logf(olm::LOG_DEBUG, LOG_CATEGORY,
+ "Creating new outbound session to receiver identity IB %s, "
+ "receiver ephemeral EB %s", identity_key.to_string().c_str(),
+ one_time_key.to_string().c_str()
+ );
+
olm::Curve25519KeyPair base_key;
olm::curve25519_generate_key(random, base_key);
+ olm::logf(olm::LOG_DEBUG, LOG_CATEGORY, "Created new ephemeral key EA %s",
+ base_key.to_string().c_str());
olm::Curve25519KeyPair ratchet_key;
olm::curve25519_generate_key(random + olm::KEY_LENGTH, ratchet_key);
+ olm::logf(olm::LOG_DEBUG, LOG_CATEGORY, "Created new ratchet key T(0) %s",
+ ratchet_key.to_string().c_str());
olm::Curve25519KeyPair const & alice_identity_key_pair = (
local_account.identity_keys.curve25519_key
@@ -95,6 +108,7 @@ std::size_t olm::Session::new_outbound_session(
olm::unset(ratchet_key);
olm::unset(secret);
+ olm::logf(olm::LOG_DEBUG, LOG_CATEGORY, "Initialised outbound session");
return std::size_t(0);
}
@@ -137,11 +151,29 @@ std::size_t olm::Session::new_inbound_session(
their_identity_key->public_key, reader.identity_key, olm::KEY_LENGTH
);
if (!same) {
+ olm::logf(olm::LOG_INFO, LOG_CATEGORY,
+ "Identity key on received message is incorrect "
+ "(expected %s, got %s)",
+ their_identity_key->to_string().c_str(),
+ olm::bytes_to_string(reader.identity_key,
+ reader.identity_key + olm::KEY_LENGTH)
+ .c_str());
last_error = olm::ErrorCode::BAD_MESSAGE_KEY_ID;
return std::size_t(-1);
}
}
+ olm::load_array(alice_identity_key.public_key, reader.identity_key);
+ olm::load_array(alice_base_key.public_key, reader.base_key);
+ olm::load_array(bob_one_time_key.public_key, reader.one_time_key);
+
+ olm::logf(olm::LOG_DEBUG, LOG_CATEGORY,
+ "Creating new inbound session from sender identity IA %s, "
+ "sender ephemeral EA %s, our ephemeral EB %s",
+ alice_identity_key.to_string().c_str(),
+ alice_base_key.to_string().c_str(),
+ bob_one_time_key.to_string().c_str());
+
olm::MessageReader message_reader;
decode_message(
message_reader, reader.message, reader.message_length,
@@ -154,17 +186,20 @@ std::size_t olm::Session::new_inbound_session(
return std::size_t(-1);
}
- olm::load_array(alice_identity_key.public_key, reader.identity_key);
- olm::load_array(alice_base_key.public_key, reader.base_key);
- olm::load_array(bob_one_time_key.public_key, reader.one_time_key);
olm::Curve25519PublicKey ratchet_key;
olm::load_array(ratchet_key.public_key, message_reader.ratchet_key);
+ olm::logf(olm::LOG_DEBUG, LOG_CATEGORY,
+ "Received ratchet key T(0) %s", ratchet_key.to_string().c_str());
+
olm::OneTimeKey const * our_one_time_key = local_account.lookup_key(
bob_one_time_key
);
if (!our_one_time_key) {
+ olm::logf(olm::LOG_INFO, LOG_CATEGORY,
+ "Session uses unknown ephemeral key %s",
+ bob_one_time_key.to_string().c_str());
last_error = olm::ErrorCode::BAD_MESSAGE_KEY_ID;
return std::size_t(-1);
}
@@ -185,6 +220,8 @@ std::size_t olm::Session::new_inbound_session(
ratchet.initialise_as_bob(secret, sizeof(secret), ratchet_key);
olm::unset(secret);
+
+ olm::logf(olm::LOG_DEBUG, LOG_CATEGORY, "Initialised inbound session");
return std::size_t(0);
}
@@ -283,6 +320,9 @@ std::size_t olm::Session::encrypt(
std::uint8_t const * random, std::size_t random_length,
std::uint8_t * message, std::size_t message_length
) {
+ olm::logf(olm::LOG_DEBUG, LOG_CATEGORY, "Encrypting '%.*s'",
+ (int)plaintext_length, plaintext);
+
if (message_length < encrypt_message_length(plaintext_length)) {
last_error = olm::ErrorCode::OUTPUT_BUFFER_TOO_SMALL;
return std::size_t(-1);
@@ -309,6 +349,16 @@ std::size_t olm::Session::encrypt(
olm::store_array(writer.identity_key, alice_identity_key.public_key);
olm::store_array(writer.base_key, alice_base_key.public_key);
message_body = writer.message;
+
+
+ olm::logf(olm::LOG_DEBUG, LOG_CATEGORY,
+ "Encoded pre-key message ver=%i one_time_key[Eb]=%s "
+ "base_key[Ea]=%s identity_key[Ia]=%s",
+ PROTOCOL_VERSION,
+ olm::bytes_to_string(writer.one_time_key, olm::KEY_LENGTH).c_str(),
+ olm::bytes_to_string(writer.base_key, olm::KEY_LENGTH).c_str(),
+ olm::bytes_to_string(writer.identity_key, olm::KEY_LENGTH).c_str()
+ );
}
std::size_t result = ratchet.encrypt(
@@ -320,7 +370,12 @@ std::size_t olm::Session::encrypt(
if (result == std::size_t(-1)) {
last_error = ratchet.last_error;
ratchet.last_error = olm::ErrorCode::SUCCESS;
+ return result;
}
+
+ olm::logf(olm::LOG_TRACE, LOG_CATEGORY, "Encrypted message %s",
+ olm::bytes_to_string(message_body, result).c_str());
+
return result;
}
@@ -362,6 +417,9 @@ std::size_t olm::Session::decrypt(
std::uint8_t const * message, std::size_t message_length,
std::uint8_t * plaintext, std::size_t max_plaintext_length
) {
+ olm::logf(olm::LOG_TRACE, LOG_CATEGORY, "Decrypting %smessage",
+ message_type == olm::MessageType::MESSAGE ? "" : "pre-key ");
+
std::uint8_t const * message_body;
std::size_t message_body_length;
if (message_type == olm::MessageType::MESSAGE) {
@@ -385,9 +443,12 @@ std::size_t olm::Session::decrypt(
if (result == std::size_t(-1)) {
last_error = ratchet.last_error;
ratchet.last_error = olm::ErrorCode::SUCCESS;
- } else {
- received_message = true;
+ return result;
}
+
+ received_message = true;
+ olm::logf(olm::LOG_DEBUG, LOG_CATEGORY, "Decrypted '%.*s'",
+ (int)result, plaintext);
return result;
}
@@ -440,4 +501,3 @@ std::uint8_t const * olm::unpickle(
pos = olm::unpickle(pos, end, value.ratchet);
return pos;
}
-