Improve error reporting and logging.

Bug: 19603049
Bug: 19509317
Change-Id: I041c973802e6c567adc5b1f280fc5bac27ba28d6
diff --git a/Android.mk b/Android.mk
index e1eee5b..a8f76ad 100644
--- a/Android.mk
+++ b/Android.mk
@@ -25,6 +25,7 @@
 		google_keymaster_messages.cpp \
 		google_keymaster_utils.cpp \
 		key_blob.cpp \
+		logger.cpp \
 		serializable.cpp
 LOCAL_C_INCLUDES := \
 	$(LOCAL_PATH)/include
diff --git a/Makefile b/Makefile
index 1c2a514..10dfda8 100644
--- a/Makefile
+++ b/Makefile
@@ -123,6 +123,7 @@
 authorization_set_test: authorization_set_test.o \
 	authorization_set.o \
 	google_keymaster_test_utils.o \
+	logger.o \
 	serializable.o \
 	$(GTEST)/src/gtest-all.o
 
@@ -142,6 +143,7 @@
 	google_keymaster_messages.o \
 	google_keymaster_test_utils.o \
 	google_keymaster_utils.o \
+	logger.o \
 	serializable.o \
 	$(GTEST)/src/gtest-all.o
 
@@ -176,6 +178,7 @@
 	$(GTEST)/src/gtest-all.o
 
 abstract_factory_registry_test: abstract_factory_registry_test.o \
+	logger.o \
 	$(GTEST)/src/gtest-all.o
 
 keymaster_enforcement_test: keymaster_enforcement_test.o \
@@ -184,6 +187,7 @@
 	google_keymaster_utils.o \
 	google_keymaster_messages.o \
 	google_keymaster_test_utils.o \
+	logger.o \
 	serializable.o \
 	$(GTEST)/src/gtest-all.o
 
diff --git a/abstract_factory_registry.h b/abstract_factory_registry.h
index 954bc7d..000ec81 100644
--- a/abstract_factory_registry.h
+++ b/abstract_factory_registry.h
@@ -23,6 +23,7 @@
 #include <UniquePtr.h>
 
 #include <keymaster/google_keymaster_utils.h>
+#include <keymaster/logger.h>
 
 namespace keymaster {
 
@@ -182,7 +183,7 @@
         size_t new_capacity = capacity_ * 2;
         UniquePtr<AbstractFactoryType* []> new_entries(new AbstractFactoryType* [new_capacity]);
         if (!new_entries.get()) {
-            // TODO(swillden): Log an error here.
+            LOG_S("Tried to register multiple abstract factories for the same type", 0);
             return;
         }
         memcpy(new_entries.get(), entries_.get(), sizeof(AbstractFactoryType*) * size_);
diff --git a/aead_mode_operation.cpp b/aead_mode_operation.cpp
index bf6f33a..f7fc18f 100644
--- a/aead_mode_operation.cpp
+++ b/aead_mode_operation.cpp
@@ -137,8 +137,7 @@
             error = ExtractNonce(input_params);
         else {
             if (input_params.find(TAG_NONCE) != -1)
-                /* TODO(swillden): Create and return a better error code */
-                return KM_ERROR_INVALID_ARGUMENT;
+                return KM_ERROR_INVALID_NONCE;
             error = GenerateNonce();
         }
 
@@ -169,12 +168,12 @@
 keymaster_error_t AeadModeOperation::ExtractNonce(const AuthorizationSet& input_params) {
     keymaster_blob_t nonce_blob;
     if (!input_params.GetTagValue(TAG_NONCE, &nonce_blob))
-        /* TODO(swillden): Add a better error return code for this case. */
-        return KM_ERROR_INVALID_ARGUMENT;
+        return KM_ERROR_MISSING_NONCE;
 
-    if (nonce_blob.data_length != nonce_length_)
-        /* TODO(swillden): Add a better error return code for this case. */
-        return KM_ERROR_INVALID_ARGUMENT;
+    if (nonce_blob.data_length != nonce_length_) {
+        LOG_E("Expected %d-byte nonce, got %d bytes", nonce_length_, nonce_blob.data_length);
+        return KM_ERROR_INVALID_NONCE;
+    }
 
     memcpy(nonce_, nonce_blob.data, nonce_length_);
     return KM_ERROR_OK;
diff --git a/aes_operation.cpp b/aes_operation.cpp
index 804d9b3..79ba248 100644
--- a/aes_operation.cpp
+++ b/aes_operation.cpp
@@ -53,12 +53,7 @@
 
 Operation* AesOperationFactory::CreateOperation(const Key& key, keymaster_error_t* error) {
     *error = KM_ERROR_OK;
-
     const SymmetricKey* symmetric_key = static_cast<const SymmetricKey*>(&key);
-    if (!symmetric_key) {
-        *error = KM_ERROR_UNKNOWN_ERROR;
-        return NULL;
-    }
 
     switch (symmetric_key->key_data_size()) {
     case 16:
@@ -105,14 +100,12 @@
     uint32_t chunk_length;
     if (!key.authorizations().GetTagValue(TAG_CHUNK_LENGTH, &chunk_length) ||
         chunk_length > AeadModeOperation::MAX_CHUNK_LENGTH)
-        // TODO(swillden): Create and use a better return code.
-        *error = KM_ERROR_INVALID_ARGUMENT;
+        *error = KM_ERROR_UNSUPPORTED_CHUNK_LENGTH;
 
     uint32_t tag_length;
     if (!key.authorizations().GetTagValue(TAG_MAC_LENGTH, &tag_length) ||
         tag_length > AeadModeOperation::MAX_TAG_LENGTH)
-        // TODO(swillden): Create and use a better return code.
-        *error = KM_ERROR_INVALID_ARGUMENT;
+        *error = KM_ERROR_UNSUPPORTED_MAC_LENGTH;
 
     keymaster_padding_t padding;
     if (key.authorizations().GetTagValue(TAG_PADDING, &padding) && padding != KM_PAD_NONE)
@@ -291,7 +284,7 @@
         EVP_CipherInit_ex(&ctx_, cipher, NULL /* engine */, key_, iv_.get(), evp_encrypt_mode());
 
     if (!init_result)
-        return KM_ERROR_UNKNOWN_ERROR;
+        return TranslateLastOpenSslError();
 
     switch (padding_) {
     case KM_PAD_NONE:
diff --git a/asymmetric_key.cpp b/asymmetric_key.cpp
index 06f5e8f..1af58ca 100644
--- a/asymmetric_key.cpp
+++ b/asymmetric_key.cpp
@@ -64,9 +64,8 @@
     EVP_PKEY* tmp_pkey = evp_key.get();
     const uint8_t* key_material = blob.unencrypted_key_material();
     if (d2i_PrivateKey(evp_key_type(), &tmp_pkey, &key_material, blob.key_material_length()) ==
-        NULL) {
-        return KM_ERROR_INVALID_KEY_BLOB;
-    }
+        NULL)
+        return TranslateLastOpenSslError();
     if (!EvpToInternal(evp_key.get()))
         return TranslateLastOpenSslError();
 
diff --git a/authorization_set.cpp b/authorization_set.cpp
index 5a50e2d..3c4a113 100644
--- a/authorization_set.cpp
+++ b/authorization_set.cpp
@@ -22,6 +22,7 @@
 
 #include <keymaster/authorization_set.h>
 #include <keymaster/google_keymaster_utils.h>
+#include <keymaster/logger.h>
 
 namespace keymaster {
 
@@ -369,6 +370,7 @@
 bool AuthorizationSet::DeserializeIndirectData(const uint8_t** buf_ptr, const uint8_t* end) {
     UniquePtr<uint8_t[]> indirect_buf;
     if (!copy_size_and_data_from_buf(buf_ptr, end, &indirect_data_size_, &indirect_buf)) {
+        LOG_E("Malformed data found in AuthorizationSet deserialization", 0);
         set_invalid(MALFORMED_DATA);
         return false;
     }
@@ -381,6 +383,7 @@
     uint32_t elements_size;
     if (!copy_uint32_from_buf(buf_ptr, end, &elements_count) ||
         !copy_uint32_from_buf(buf_ptr, end, &elements_size)) {
+        LOG_E("Malformed data found in AuthorizationSet deserialization", 0);
         set_invalid(MALFORMED_DATA);
         return false;
     }
@@ -389,6 +392,7 @@
     // elems_ arrays which are clearly too large to be reasonable.
     if (static_cast<ptrdiff_t>(elements_size) > end - *buf_ptr ||
         elements_count * sizeof(uint32_t) > elements_size) {
+        LOG_E("Malformed data found in AuthorizationSet deserialization", 0);
         set_invalid(MALFORMED_DATA);
         return false;
     }
@@ -400,6 +404,7 @@
     const uint8_t* elements_end = *buf_ptr + elements_size;
     for (size_t i = 0; i < elements_count; ++i) {
         if (!deserialize(elems_ + i, buf_ptr, elements_end, indirect_data_, indirect_end)) {
+            LOG_E("Malformed data found in AuthorizationSet deserialization", 0);
             set_invalid(MALFORMED_DATA);
             return false;
         }
@@ -415,6 +420,7 @@
         return false;
 
     if (indirect_data_size_ != ComputeIndirectDataSize(elems_, elems_size_)) {
+        LOG_E("Malformed data found in AuthorizationSet deserialization", 0);
         set_invalid(MALFORMED_DATA);
         return false;
     }
diff --git a/ec_key.cpp b/ec_key.cpp
index c58140c..bd159ac 100644
--- a/ec_key.cpp
+++ b/ec_key.cpp
@@ -51,6 +51,7 @@
     UniquePtr<EC_GROUP, EC_GROUP_Delete> group(choose_group(key_size));
     if (group.get() == NULL) {
         // Technically, could also have been a memory allocation problem.
+        LOG_E("Unable to get EC group for key of size %d", key_size);
         *error = KM_ERROR_UNSUPPORTED_KEY_SIZE;
         return NULL;
     }
diff --git a/google_keymaster.cpp b/google_keymaster.cpp
index 334dd8f..25ea7ab 100644
--- a/google_keymaster.cpp
+++ b/google_keymaster.cpp
@@ -199,7 +199,6 @@
                                             GetKeyCharacteristicsResponse* response) {
     if (response == NULL)
         return;
-    response->error = KM_ERROR_UNKNOWN_ERROR;
 
     UniquePtr<KeyBlob> blob(
         LoadKeyBlob(request.key_blob, request.additional_params, &(response->error)));
@@ -208,7 +207,6 @@
 
     response->enforced.Reinitialize(blob->enforced());
     response->unenforced.Reinitialize(blob->unenforced());
-    response->error = KM_ERROR_OK;
 }
 
 void GoogleKeymaster::BeginOperation(const BeginOperationRequest& request,
@@ -224,8 +222,7 @@
         return;
 
     if (key->rescopable()) {
-        // TODO(swillden): Create a better error code for this.
-        response->error = KM_ERROR_INVALID_KEY_BLOB;
+        response->error = KM_ERROR_RESCOPABLE_KEY_NOT_USABLE;
         return;
     }
 
@@ -459,10 +456,12 @@
         // These cannot be specified by the client.
         case KM_TAG_ROOT_OF_TRUST:
         case KM_TAG_ORIGIN:
+            LOG_E("Root of trust and origin tags may not be specified", 0);
             return KM_ERROR_INVALID_TAG;
 
         // These don't work.
         case KM_TAG_ROLLBACK_RESISTANT:
+            LOG_E("KM_TAG_ROLLBACK_RESISTANT not supported", 0);
             return KM_ERROR_UNSUPPORTED_TAG;
 
         // These are hidden.
diff --git a/google_keymaster_test.cpp b/google_keymaster_test.cpp
index 946c5fd..036b499 100644
--- a/google_keymaster_test.cpp
+++ b/google_keymaster_test.cpp
@@ -1378,7 +1378,7 @@
     string ciphertext(15, 'a');
     AuthorizationSet input_params;
     input_params.push_back(TAG_NONCE, "aaaaaaaaaaa", 11);
-    EXPECT_EQ(KM_ERROR_INVALID_ARGUMENT, BeginOperation(KM_PURPOSE_DECRYPT, input_params));
+    EXPECT_EQ(KM_ERROR_INVALID_NONCE, BeginOperation(KM_PURPOSE_DECRYPT, input_params));
 }
 
 TEST_F(EncryptionOperationsTest, AesOcbRoundTripEmptySuccess) {
@@ -1469,7 +1469,7 @@
                                            .AesEncryptionKey(128)
                                            .Authorization(TAG_BLOCK_MODE, KM_MODE_OCB)
                                            .Authorization(TAG_MAC_LENGTH, 16)));
-    EXPECT_EQ(KM_ERROR_INVALID_ARGUMENT, BeginOperation(KM_PURPOSE_ENCRYPT));
+    EXPECT_EQ(KM_ERROR_UNSUPPORTED_CHUNK_LENGTH, BeginOperation(KM_PURPOSE_ENCRYPT));
 }
 
 TEST_F(EncryptionOperationsTest, AesOcbPaddingUnsupported) {
@@ -1483,7 +1483,7 @@
 TEST_F(EncryptionOperationsTest, AesOcbInvalidMacLength) {
     ASSERT_EQ(KM_ERROR_OK,
               GenerateKey(AuthorizationSetBuilder().AesEncryptionKey(128).OcbMode(4096, 17)));
-    EXPECT_EQ(KM_ERROR_INVALID_ARGUMENT, BeginOperation(KM_PURPOSE_ENCRYPT));
+    EXPECT_EQ(KM_ERROR_UNSUPPORTED_MAC_LENGTH, BeginOperation(KM_PURPOSE_ENCRYPT));
 }
 
 uint8_t rfc_7523_test_key_data[] = {
@@ -1940,7 +1940,7 @@
         GenerateKey(AuthorizationSetBuilder().AesEncryptionKey(128).OcbMode(4096, 16).Authorization(
             TAG_RESCOPING_ADD, KM_TAG_MAC_LENGTH)));
     // TODO(swillden): Add a better error code for this.
-    EXPECT_EQ(KM_ERROR_INVALID_KEY_BLOB, BeginOperation(KM_PURPOSE_ENCRYPT));
+    EXPECT_EQ(KM_ERROR_RESCOPABLE_KEY_NOT_USABLE, BeginOperation(KM_PURPOSE_ENCRYPT));
 }
 
 TEST_F(RescopingTest, RescopeSymmetric) {
diff --git a/hmac_operation.cpp b/hmac_operation.cpp
index b4b46e8..b773920 100644
--- a/hmac_operation.cpp
+++ b/hmac_operation.cpp
@@ -60,11 +60,6 @@
         return NULL;
 
     const SymmetricKey* symmetric_key = static_cast<const SymmetricKey*>(&key);
-    if (!symmetric_key) {
-        *error = KM_ERROR_UNKNOWN_ERROR;
-        return NULL;
-    }
-
     Operation* op = new HmacOperation(purpose(), symmetric_key->key_data(),
                                       symmetric_key->key_data_size(), digest, tag_length);
     if (!op)
diff --git a/include/keymaster/soft_keymaster_logger.h b/include/keymaster/soft_keymaster_logger.h
index d8d343b..fbbcf46 100644
--- a/include/keymaster/soft_keymaster_logger.h
+++ b/include/keymaster/soft_keymaster_logger.h
@@ -24,10 +24,7 @@
 class SoftKeymasterLogger : public Logger
 {
 public:
-    virtual int debug(const char* fmt, ...) const;
-    virtual int info(const char* fmt, ...) const;
-    virtual int error(const char* fmt, ...) const;
-    virtual int severe(const char* fmt, ...) const;
+    virtual int log_msg(LogLevel level, const char* fmt, va_list args) const;
 };
 
 } // namespace keymaster
diff --git a/key_blob.cpp b/key_blob.cpp
index 0197958..5705197 100644
--- a/key_blob.cpp
+++ b/key_blob.cpp
@@ -18,6 +18,7 @@
 
 #include <keymaster/google_keymaster_utils.h>
 #include <keymaster/key_blob.h>
+#include <keymaster/logger.h>
 
 namespace keymaster {
 
@@ -93,6 +94,7 @@
         // Based on those two checks alone, the probability of interpreting an unversioned blob as a
         // version 0 blob is 1/2^40.  That's small enough to be negligible, but there are additional
         // checks which lower it further.
+        LOG_I("Failed to deserialize versioned key blob.  Assuming unversioned.");
         *buf_ptr = start;
         if (!DeserializeUnversionedBlob(buf_ptr, end))
             return false;
@@ -114,6 +116,7 @@
         !copy_from_buf(buf_ptr, end, tag_.get(), TAG_LENGTH) ||
         !enforced_.Deserialize(buf_ptr, end) || !unenforced_.Deserialize(buf_ptr, end)) {
         encrypted_key_material_.reset();
+        LOG_E("Failed to deserialize unversioned blob", 0);
         error_ = KM_ERROR_INVALID_KEY_BLOB;
         return false;
     }
diff --git a/openssl_err.cpp b/openssl_err.cpp
index 4584716..b9c6153 100644
--- a/openssl_err.cpp
+++ b/openssl_err.cpp
@@ -62,11 +62,12 @@
         return TranslateX509v3Error(reason);
 #else
     case ERR_LIB_ASN1:
-        // TODO(swillden): Consider a better return code.
+        LOG_E("ASN.1 parsing error %d", reason);
         return KM_ERROR_INVALID_ARGUMENT;
 #endif
     }
 
+    LOG_E("Openssl error %d, %d", ERR_GET_LIB(error), reason);
     return KM_ERROR_UNKNOWN_ERROR;
 }
 
diff --git a/soft_keymaster_device.cpp b/soft_keymaster_device.cpp
index e5c3e5d..0aa9457 100644
--- a/soft_keymaster_device.cpp
+++ b/soft_keymaster_device.cpp
@@ -41,15 +41,15 @@
 struct keystore_module soft_keymaster_device_module = {
     .common =
         {
-         .tag = HARDWARE_MODULE_TAG,
-         .module_api_version = KEYMASTER_MODULE_API_VERSION_1_0,
-         .hal_api_version = HARDWARE_HAL_API_VERSION,
-         .id = KEYSTORE_HARDWARE_MODULE_ID,
-         .name = "Keymaster OpenSSL HAL",
-         .author = "The Android Open Source Project",
-         .methods = NULL,
-         .dso = 0,
-         .reserved = {},
+            .tag = HARDWARE_MODULE_TAG,
+            .module_api_version = KEYMASTER_MODULE_API_VERSION_1_0,
+            .hal_api_version = HARDWARE_HAL_API_VERSION,
+            .id = KEYSTORE_HARDWARE_MODULE_ID,
+            .name = "Keymaster OpenSSL HAL",
+            .author = "The Android Open Source Project",
+            .methods = NULL,
+            .dso = 0,
+            .reserved = {},
         },
 };
 
@@ -160,6 +160,11 @@
                                           const void* key_params, uint8_t** key_blob,
                                           size_t* key_blob_length) {
     LOG_D("%s", "Device received generate_keypair");
+    if (!dev || !key_params)
+        return KM_ERROR_UNEXPECTED_NULL_POINTER;
+
+    if (!key_blob || !key_blob_length)
+        return KM_ERROR_OUTPUT_PARAMETER_NULL;
 
     GenerateKeyRequest req;
     StoreDefaultNewKeyParams(&req.key_description);
@@ -215,6 +220,12 @@
                                         size_t* key_blob_length) {
     LOG_D("Device received import_keypair");
 
+    if (!dev || !key)
+        return KM_ERROR_UNEXPECTED_NULL_POINTER;
+
+    if (!key_blob || !key_blob_length)
+        return KM_ERROR_OUTPUT_PARAMETER_NULL;
+
     ImportKeyRequest request;
     StoreDefaultNewKeyParams(&request.key_description);
     request.SetKeyMaterial(key, key_length);
@@ -245,6 +256,12 @@
                                             uint8_t** x509_data, size_t* x509_data_length) {
     LOG_D("Device received get_keypair_public");
 
+    if (!dev || !key_blob)
+        return KM_ERROR_UNEXPECTED_NULL_POINTER;
+
+    if (!x509_data || !x509_data_length)
+        return KM_ERROR_OUTPUT_PARAMETER_NULL;
+
     ExportKeyRequest req;
     req.SetKeyMaterial(key_blob, key_blob_length);
     req.key_format = KM_KEY_FORMAT_X509;
@@ -273,6 +290,12 @@
                                    uint8_t** signed_data, size_t* signed_data_length) {
     LOG_D("Device received sign_data");
 
+    if (!dev || !params || !key_blob)
+        return KM_ERROR_UNEXPECTED_NULL_POINTER;
+
+    if (!signed_data || !signed_data_length)
+        return KM_ERROR_OUTPUT_PARAMETER_NULL;
+
     *signed_data_length = 0;
 
     BeginOperationRequest begin_request;
@@ -325,6 +348,9 @@
                                      const uint8_t* signature, const size_t signature_length) {
     LOG_D("Device received verify_data");
 
+    if (!dev || !params || !key_blob || !signed_data || !signature)
+        return KM_ERROR_UNEXPECTED_NULL_POINTER;
+
     BeginOperationRequest begin_request;
     begin_request.purpose = KM_PURPOSE_VERIFY;
     begin_request.SetKeyMaterial(key_blob, key_blob_length);
@@ -368,6 +394,9 @@
 keymaster_error_t SoftKeymasterDevice::get_supported_algorithms(const keymaster1_device_t* dev,
                                                                 keymaster_algorithm_t** algorithms,
                                                                 size_t* algorithms_length) {
+    if (!dev)
+        return KM_ERROR_UNEXPECTED_NULL_POINTER;
+
     if (!algorithms || !algorithms_length)
         return KM_ERROR_OUTPUT_PARAMETER_NULL;
 
@@ -394,6 +423,9 @@
                                                                  keymaster_purpose_t purpose,
                                                                  keymaster_block_mode_t** modes,
                                                                  size_t* modes_length) {
+    if (!dev)
+        return KM_ERROR_UNEXPECTED_NULL_POINTER;
+
     if (!modes || !modes_length)
         return KM_ERROR_OUTPUT_PARAMETER_NULL;
 
@@ -420,6 +452,9 @@
                                                                    keymaster_purpose_t purpose,
                                                                    keymaster_padding_t** modes,
                                                                    size_t* modes_length) {
+    if (!dev)
+        return KM_ERROR_UNEXPECTED_NULL_POINTER;
+
     if (!modes || !modes_length)
         return KM_ERROR_OUTPUT_PARAMETER_NULL;
 
@@ -445,6 +480,9 @@
                                                              keymaster_purpose_t purpose,
                                                              keymaster_digest_t** digests,
                                                              size_t* digests_length) {
+    if (!dev)
+        return KM_ERROR_UNEXPECTED_NULL_POINTER;
+
     if (!digests || !digests_length)
         return KM_ERROR_OUTPUT_PARAMETER_NULL;
 
@@ -468,6 +506,9 @@
 keymaster_error_t SoftKeymasterDevice::get_supported_import_formats(
     const keymaster1_device_t* dev, keymaster_algorithm_t algorithm,
     keymaster_key_format_t** formats, size_t* formats_length) {
+    if (!dev)
+        return KM_ERROR_UNEXPECTED_NULL_POINTER;
+
     if (!formats || !formats_length)
         return KM_ERROR_OUTPUT_PARAMETER_NULL;
 
@@ -492,6 +533,9 @@
 keymaster_error_t SoftKeymasterDevice::get_supported_export_formats(
     const keymaster1_device_t* dev, keymaster_algorithm_t algorithm,
     keymaster_key_format_t** formats, size_t* formats_length) {
+    if (!dev)
+        return KM_ERROR_UNEXPECTED_NULL_POINTER;
+
     if (!formats || !formats_length)
         return KM_ERROR_OUTPUT_PARAMETER_NULL;
 
@@ -515,6 +559,9 @@
 /* static */
 keymaster_error_t SoftKeymasterDevice::add_rng_entropy(const keymaster1_device_t* dev,
                                                        const uint8_t* data, size_t data_length) {
+    if (!dev)
+        return KM_ERROR_UNEXPECTED_NULL_POINTER;
+
     AddEntropyRequest request;
     request.random_data.Reinitialize(data, data_length);
     return convert_device(dev)->impl_->AddRngEntropy(request);
@@ -524,6 +571,8 @@
 keymaster_error_t SoftKeymasterDevice::generate_key(
     const keymaster1_device_t* dev, const keymaster_key_param_t* params, size_t params_count,
     keymaster_key_blob_t* key_blob, keymaster_key_characteristics_t** characteristics) {
+    if (!dev || !params)
+        return KM_ERROR_UNEXPECTED_NULL_POINTER;
 
     if (!key_blob)
         return KM_ERROR_OUTPUT_PARAMETER_NULL;
@@ -557,8 +606,8 @@
     const keymaster1_device_t* dev, const keymaster_key_blob_t* key_blob,
     const keymaster_blob_t* client_id, const keymaster_blob_t* app_data,
     keymaster_key_characteristics_t** characteristics) {
-    if (!key_blob)
-        return KM_ERROR_INVALID_KEY_BLOB;
+    if (!dev || !key_blob || !key_blob->key_material)
+        return KM_ERROR_UNEXPECTED_NULL_POINTER;
 
     if (!characteristics)
         return KM_ERROR_OUTPUT_PARAMETER_NULL;
@@ -584,10 +633,7 @@
     size_t new_params_count, const keymaster_key_blob_t* key_blob,
     const keymaster_blob_t* client_id, const keymaster_blob_t* app_data,
     keymaster_key_blob_t* rescoped_key_blob, keymaster_key_characteristics_t** characteristics) {
-    if (!key_blob)
-        return KM_ERROR_INVALID_KEY_BLOB;
-
-    if (!new_params)
+    if (!key_blob || !key_blob->key_material || !new_params)
         return KM_ERROR_UNEXPECTED_NULL_POINTER;
 
     if (!rescoped_key_blob)
@@ -658,7 +704,7 @@
     const keymaster_key_blob_t* key_to_export, const keymaster_blob_t* client_id,
     const keymaster_blob_t* app_data, uint8_t** export_data, size_t* export_data_length) {
     if (!key_to_export || !key_to_export->key_material)
-        return KM_ERROR_INVALID_KEY_BLOB;
+        return KM_ERROR_UNEXPECTED_NULL_POINTER;
 
     if (!export_data || !export_data_length)
         return KM_ERROR_OUTPUT_PARAMETER_NULL;
@@ -690,7 +736,7 @@
     const keymaster_key_param_t* params, size_t params_count, keymaster_key_param_t** out_params,
     size_t* out_params_count, keymaster_operation_handle_t* operation_handle) {
     if (!key || !key->key_material)
-        return KM_ERROR_INVALID_KEY_BLOB;
+        return KM_ERROR_UNEXPECTED_NULL_POINTER;
 
     if (!operation_handle || !out_params || !out_params_count)
         return KM_ERROR_OUTPUT_PARAMETER_NULL;
diff --git a/soft_keymaster_logger.cpp b/soft_keymaster_logger.cpp
index 27d9355..3c55a64 100644
--- a/soft_keymaster_logger.cpp
+++ b/soft_keymaster_logger.cpp
@@ -24,36 +24,28 @@
 
 namespace keymaster {
 
-int SoftKeymasterLogger::debug(const char* fmt, ...) const {
-    va_list args;
-    va_start(args, fmt);
-    int retval = LOG_PRI_VA(LOG_DEBUG, LOG_TAG, fmt, args);
-    va_end(args);
-    return retval;
-}
+int SoftKeymasterLogger::log_msg(LogLevel level, const char* fmt, va_list args) const {
 
-int SoftKeymasterLogger::info(const char* fmt, ...) const {
-    va_list args;
-    va_start(args, fmt);
-    int retval = LOG_PRI_VA(LOG_INFO, LOG_TAG, fmt, args);
-    va_end(args);
-    return retval;
-}
+    int android_log_level = ANDROID_LOG_ERROR;
+    switch (level) {
+    case DEBUG_LVL:
+        android_log_level = ANDROID_LOG_DEBUG;
+        break;
+    case INFO_LVL:
+        android_log_level = ANDROID_LOG_INFO;
+        break;
+    case WARNING_LVL:
+        android_log_level = ANDROID_LOG_WARN;
+        break;
+    case ERROR_LVL:
+        android_log_level = ANDROID_LOG_ERROR;
+        break;
+    case SEVERE_LVL:
+        android_log_level = ANDROID_LOG_ERROR;
+        break;
+    }
 
-int SoftKeymasterLogger::error(const char* fmt, ...) const {
-    va_list args;
-    va_start(args, fmt);
-    int retval = LOG_PRI_VA(LOG_ERR, LOG_TAG, fmt, args);
-    va_end(args);
-    return retval;
-}
-
-int SoftKeymasterLogger::severe(const char* fmt, ...) const {
-    va_list args;
-    va_start(args, fmt);
-    int retval = LOG_PRI_VA(LOG_CRIT, LOG_TAG, fmt, args);
-    va_end(args);
-    return retval;
+    return LOG_PRI_VA(android_log_level, LOG_TAG, fmt, args);
 }
 
 }  // namespace keymaster
diff --git a/symmetric_key.cpp b/symmetric_key.cpp
index 680c08a..8b84dd7 100644
--- a/symmetric_key.cpp
+++ b/symmetric_key.cpp
@@ -60,6 +60,8 @@
     }
 
     if (key->key_data_size_ != key_material_length) {
+        LOG_E("Expected %d byte key data but got %d bytes", key->key_data_size_,
+              key_material_length);
         *error = KM_ERROR_INVALID_KEY_BLOB;
         return NULL;
     }
@@ -92,6 +94,7 @@
     *error = key->set_size(key_size_bits / 8);
     if (*error != KM_ERROR_OK)
         return NULL;
+
     return key.release();
 }
 
diff --git a/unencrypted_key_blob.cpp b/unencrypted_key_blob.cpp
index a153eca..3857f37 100644
--- a/unencrypted_key_blob.cpp
+++ b/unencrypted_key_blob.cpp
@@ -90,6 +90,7 @@
                    NULL /* additional data */, 0 /* additional data length */,
                    encrypted_key_material.get(), tag.get(), 1 /* final */);
     if (ae_err < 0) {
+        LOG_E("Error %d while encrypting key", ae_err);
         error_ = KM_ERROR_UNKNOWN_ERROR;
         return;
     }
@@ -113,9 +114,11 @@
         // Authentication failed!  Decryption probably succeeded(ish), but we don't want to return
         // any data when the authentication fails, so clear it.
         memset_s(unencrypted_key_material_.get(), 0, unencrypted_key_material_length());
+        LOG_E("Failed to validate authentication tag during key decryption", 0);
         error_ = KM_ERROR_INVALID_KEY_BLOB;
         return;
     } else if (ae_err < 0) {
+        LOG_E("Failed to decrypt key, error: %d", ae_err);
         error_ = KM_ERROR_UNKNOWN_ERROR;
         return;
     }