Remove logging functionality

Concerns have been raised that including logging functionality makes it harder
to audit the implementation to ensure that no secret information is leaked. We
are therefore removing it from the master branch.
This commit is contained in:
Richard van der Hoff 2016-05-16 11:13:54 +01:00
parent b3db0e6ee1
commit 3965320a9c
7 changed files with 0 additions and 208 deletions

View file

@ -1,44 +0,0 @@
/* Copyright 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.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
#ifndef OLM_LOGGING_H_
#define OLM_LOGGING_H_
#include "olm/olm.hh"
#ifdef __cplusplus
extern "C" {
#endif
#define OLM_LOG_FATAL 1
#define OLM_LOG_ERROR 2
#define OLM_LOG_WARNING 3
#define OLM_LOG_INFO 4
#define OLM_LOG_DEBUG 5
#define OLM_LOG_TRACE 6
/* returns non-zero if logging is enabled for this level */
int olm_log_enabled_for(unsigned int level, const char *category);
__attribute__((__format__ (__printf__, 3, 4)))
void olm_logf(unsigned int level, const char *category,
const char *format, ...);
#ifdef __cplusplus
} // extern "C"
#endif
#endif /* OLM_LOGGING_H_ */

View file

@ -14,12 +14,9 @@
*/ */
#include "olm/account.hh" #include "olm/account.hh"
#include "olm/base64.hh" #include "olm/base64.hh"
#include "olm/logging.h"
#include "olm/pickle.hh" #include "olm/pickle.hh"
#include "olm/memory.hh" #include "olm/memory.hh"
static const char *LOG_CATEGORY = "olm::Account";
olm::Account::Account( olm::Account::Account(
) : next_one_time_key_id(0), ) : next_one_time_key_id(0),
last_error(olm::ErrorCode::SUCCESS) { last_error(olm::ErrorCode::SUCCESS) {
@ -45,11 +42,9 @@ std::size_t olm::Account::remove_key(
if (olm::array_equal(i->key.public_key, public_key.public_key)) { if (olm::array_equal(i->key.public_key, public_key.public_key)) {
std::uint32_t id = i->id; std::uint32_t id = i->id;
one_time_keys.erase(i); one_time_keys.erase(i);
olm_logf(OLM_LOG_INFO, LOG_CATEGORY, "removed key id %i", id);
return id; return id;
} }
} }
olm_logf(OLM_LOG_WARNING, LOG_CATEGORY, "Couldn't find key to remove");
return std::size_t(-1); return std::size_t(-1);
} }
@ -69,8 +64,6 @@ std::size_t olm::Account::new_account(
random += KEY_LENGTH; random += KEY_LENGTH;
olm::curve25519_generate_key(random, identity_keys.curve25519_key); olm::curve25519_generate_key(random, identity_keys.curve25519_key);
olm_logf(OLM_LOG_DEBUG, LOG_CATEGORY, "Created new account");
return 0; return 0;
} }

View file

@ -1,47 +0,0 @@
/* Copyright 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.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
#include "olm/logging.h"
#include <stdarg.h>
#include <stdio.h>
static unsigned int log_level = 1;
void olm_set_log_level(unsigned int level) {
log_level = level;
}
int olm_log_enabled_for(unsigned int level, const char *category)
{
return level <= log_level;
}
void olm_logf(unsigned int level, const char *category,
const char *format, ...) {
if (level > log_level) {
return;
}
fputs(category, stdout);
fputs(": ", stdout);
va_list ap;
va_start(ap, format);
vprintf(format, ap);
va_end(ap);
putchar('\n');
}

View file

@ -14,13 +14,10 @@
*/ */
#include "olm/message.hh" #include "olm/message.hh"
#include "olm/logging.h"
#include "olm/memory.hh" #include "olm/memory.hh"
namespace { namespace {
static const char *LOG_CATEGORY = "olm::Message";
template<typename T> template<typename T>
static std::size_t varint_length( static std::size_t varint_length(
T value T value
@ -239,13 +236,6 @@ void olm::decode_message(
} }
unknown = pos; 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()
);
} }
@ -334,14 +324,4 @@ void olm::decode_one_time_key_message(
} }
unknown = pos; 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()
);
} }

View file

@ -19,7 +19,6 @@
#include "olm/base64.hh" #include "olm/base64.hh"
#include "olm/cipher.hh" #include "olm/cipher.hh"
#include "olm/memory.hh" #include "olm/memory.hh"
#include "olm/logging.h"
#include <new> #include <new>
#include <cstring> #include <cstring>

View file

@ -17,14 +17,11 @@
#include "olm/memory.hh" #include "olm/memory.hh"
#include "olm/cipher.hh" #include "olm/cipher.hh"
#include "olm/pickle.hh" #include "olm/pickle.hh"
#include "olm/logging.h"
#include <cstring> #include <cstring>
namespace { namespace {
static const char *LOG_CATEGORY = "olm::Ratchet";
static const std::uint8_t PROTOCOL_VERSION = 3; static const std::uint8_t PROTOCOL_VERSION = 3;
static const std::uint8_t MESSAGE_KEY_SEED[1] = {0x01}; static const std::uint8_t MESSAGE_KEY_SEED[1] = {0x01};
static const std::uint8_t CHAIN_KEY_SEED[1] = {0x02}; static const std::uint8_t CHAIN_KEY_SEED[1] = {0x02};
@ -79,8 +76,6 @@ static void advance_chain_key(
new_chain_key.key new_chain_key.key
); );
new_chain_key.index = chain_key.index + 1; 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);
} }
@ -95,8 +90,6 @@ static void create_message_keys(
message_key.key message_key.key
); );
message_key.index = chain_key.index; 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);
} }
@ -176,9 +169,6 @@ static std::size_t verify_mac_and_decrypt_for_new_chain(
new_chain.ratchet_key, session.kdf_info, new_chain.ratchet_key, session.kdf_info,
new_root_key, new_chain.chain_key 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( std::size_t result = verify_mac_and_decrypt_for_existing_chain(
session, chain_index, new_chain.chain_key, reader, session, chain_index, new_chain.chain_key, reader,
plaintext, max_plaintext_length plaintext, max_plaintext_length
@ -219,7 +209,6 @@ void olm::Ratchet::initialise_as_bob(
receiver_chains[0].ratchet_key = their_ratchet_key; receiver_chains[0].ratchet_key = their_ratchet_key;
chain_index = 0; chain_index = 0;
olm::unset(derived_secrets); olm::unset(derived_secrets);
olm_logf(OLM_LOG_DEBUG, LOG_CATEGORY, "Initialised receiver chain R(0)");
} }
@ -242,7 +231,6 @@ void olm::Ratchet::initialise_as_alice(
sender_chain[0].ratchet_key = our_ratchet_key; sender_chain[0].ratchet_key = our_ratchet_key;
chain_index = 0; chain_index = 0;
olm::unset(derived_secrets); olm::unset(derived_secrets);
olm_logf(OLM_LOG_DEBUG, LOG_CATEGORY, "Initialised sender chain R(0)");
} }
namespace olm { namespace olm {
@ -450,9 +438,6 @@ std::size_t olm::Ratchet::encrypt(
if (sender_chain.empty()) { if (sender_chain.empty()) {
sender_chain.insert(); sender_chain.insert();
olm::curve25519_generate_key(random, sender_chain[0].ratchet_key); 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( create_chain_key(
root_key, root_key,
sender_chain[0].ratchet_key, sender_chain[0].ratchet_key,
@ -460,8 +445,6 @@ std::size_t olm::Ratchet::encrypt(
kdf_info, kdf_info,
root_key, sender_chain[0].chain_key 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++; chain_index++;
} }
@ -491,14 +474,6 @@ std::size_t olm::Ratchet::encrypt(
output, output_length 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); olm::unset(keys);
return output_length; return output_length;
} }
@ -525,10 +500,6 @@ std::size_t olm::Ratchet::decrypt(
std::uint8_t const * input, std::size_t input_length, std::uint8_t const * input, std::size_t input_length,
std::uint8_t * plaintext, std::size_t max_plaintext_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::MessageReader reader;
olm::decode_message( olm::decode_message(
reader, input, input_length, ratchet_cipher.mac_length() reader, input, input_length, ratchet_cipher.mac_length()
@ -580,8 +551,6 @@ std::size_t olm::Ratchet::decrypt(
std::size_t result = std::size_t(-1); std::size_t result = std::size_t(-1);
if (!chain) { 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( result = verify_mac_and_decrypt_for_new_chain(
*this, reader, plaintext, max_plaintext_length *this, reader, plaintext, max_plaintext_length
); );
@ -642,8 +611,6 @@ std::size_t olm::Ratchet::decrypt(
olm::unset(sender_chain[0]); olm::unset(sender_chain[0]);
sender_chain.erase(sender_chain.begin()); sender_chain.erase(sender_chain.begin());
receiver_chain_index = ++chain_index; 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) { while (chain->chain_key.index < reader.counter) {

View file

@ -16,7 +16,6 @@
#include "olm/cipher.hh" #include "olm/cipher.hh"
#include "olm/crypto.hh" #include "olm/crypto.hh"
#include "olm/account.hh" #include "olm/account.hh"
#include "olm/logging.h"
#include "olm/memory.hh" #include "olm/memory.hh"
#include "olm/message.hh" #include "olm/message.hh"
#include "olm/pickle.hh" #include "olm/pickle.hh"
@ -25,8 +24,6 @@
namespace { namespace {
static const char *LOG_CATEGORY = "olm::Session";
static const std::uint8_t PROTOCOL_VERSION = 0x3; static const std::uint8_t PROTOCOL_VERSION = 0x3;
static const std::uint8_t ROOT_KDF_INFO[] = "OLM_ROOT"; static const std::uint8_t ROOT_KDF_INFO[] = "OLM_ROOT";
@ -68,21 +65,11 @@ std::size_t olm::Session::new_outbound_session(
return std::size_t(-1); 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::Curve25519KeyPair base_key;
olm::curve25519_generate_key(random, 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::Curve25519KeyPair ratchet_key;
olm::curve25519_generate_key(random + olm::KEY_LENGTH, 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 = ( olm::Curve25519KeyPair const & alice_identity_key_pair = (
local_account.identity_keys.curve25519_key local_account.identity_keys.curve25519_key
@ -108,7 +95,6 @@ std::size_t olm::Session::new_outbound_session(
olm::unset(ratchet_key); olm::unset(ratchet_key);
olm::unset(secret); olm::unset(secret);
olm_logf(OLM_LOG_DEBUG, LOG_CATEGORY, "Initialised outbound session");
return std::size_t(0); return std::size_t(0);
} }
@ -151,13 +137,6 @@ std::size_t olm::Session::new_inbound_session(
their_identity_key->public_key, reader.identity_key, olm::KEY_LENGTH their_identity_key->public_key, reader.identity_key, olm::KEY_LENGTH
); );
if (!same) { 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; last_error = olm::ErrorCode::BAD_MESSAGE_KEY_ID;
return std::size_t(-1); return std::size_t(-1);
} }
@ -167,13 +146,6 @@ std::size_t olm::Session::new_inbound_session(
olm::load_array(alice_base_key.public_key, reader.base_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::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; olm::MessageReader message_reader;
decode_message( decode_message(
message_reader, reader.message, reader.message_length, message_reader, reader.message, reader.message_length,
@ -189,17 +161,11 @@ std::size_t olm::Session::new_inbound_session(
olm::Curve25519PublicKey ratchet_key; olm::Curve25519PublicKey ratchet_key;
olm::load_array(ratchet_key.public_key, message_reader.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( olm::OneTimeKey const * our_one_time_key = local_account.lookup_key(
bob_one_time_key bob_one_time_key
); );
if (!our_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; last_error = olm::ErrorCode::BAD_MESSAGE_KEY_ID;
return std::size_t(-1); return std::size_t(-1);
} }
@ -221,7 +187,6 @@ std::size_t olm::Session::new_inbound_session(
olm::unset(secret); olm::unset(secret);
olm_logf(OLM_LOG_DEBUG, LOG_CATEGORY, "Initialised inbound session");
return std::size_t(0); return std::size_t(0);
} }
@ -320,9 +285,6 @@ std::size_t olm::Session::encrypt(
std::uint8_t const * random, std::size_t random_length, std::uint8_t const * random, std::size_t random_length,
std::uint8_t * message, std::size_t message_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)) { if (message_length < encrypt_message_length(plaintext_length)) {
last_error = olm::ErrorCode::OUTPUT_BUFFER_TOO_SMALL; last_error = olm::ErrorCode::OUTPUT_BUFFER_TOO_SMALL;
return std::size_t(-1); return std::size_t(-1);
@ -349,16 +311,6 @@ std::size_t olm::Session::encrypt(
olm::store_array(writer.identity_key, alice_identity_key.public_key); olm::store_array(writer.identity_key, alice_identity_key.public_key);
olm::store_array(writer.base_key, alice_base_key.public_key); olm::store_array(writer.base_key, alice_base_key.public_key);
message_body = writer.message; 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( std::size_t result = ratchet.encrypt(
@ -373,9 +325,6 @@ std::size_t olm::Session::encrypt(
return result; return result;
} }
olm_logf(OLM_LOG_TRACE, LOG_CATEGORY, "Encrypted message %s",
olm::bytes_to_string(message_body, result).c_str());
return result; return result;
} }
@ -417,9 +366,6 @@ std::size_t olm::Session::decrypt(
std::uint8_t const * message, std::size_t message_length, std::uint8_t const * message, std::size_t message_length,
std::uint8_t * plaintext, std::size_t max_plaintext_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::uint8_t const * message_body;
std::size_t message_body_length; std::size_t message_body_length;
if (message_type == olm::MessageType::MESSAGE) { if (message_type == olm::MessageType::MESSAGE) {
@ -447,8 +393,6 @@ std::size_t olm::Session::decrypt(
} }
received_message = true; received_message = true;
olm_logf(OLM_LOG_DEBUG, LOG_CATEGORY, "Decrypted '%.*s'",
(int)result, plaintext);
return result; return result;
} }