From 4249ce407e3e2825e0cc102bdf4a70accb889ced Mon Sep 17 00:00:00 2001 From: Antoine Pitrou Date: Thu, 13 Feb 2025 16:26:00 +0100 Subject: [PATCH] Add debug logs, hopefully we can diagnose this a bit more precisely --- .../parquet/encryption/key_management_test.cc | 9 +++++ .../encryption/read_configurations_test.cc | 33 ++++++++++--------- .../encryption/test_encryption_util.cc | 11 +++++++ 3 files changed, 37 insertions(+), 16 deletions(-) diff --git a/cpp/src/parquet/encryption/key_management_test.cc b/cpp/src/parquet/encryption/key_management_test.cc index 1506a00a14779..640b83281c942 100644 --- a/cpp/src/parquet/encryption/key_management_test.cc +++ b/cpp/src/parquet/encryption/key_management_test.cc @@ -57,12 +57,17 @@ class TestEncryptionKeyManagement : public ::testing::Test { #ifndef ARROW_WITH_SNAPPY GTEST_SKIP() << "Test requires Snappy compression"; #endif + ARROW_LOG(INFO) << "SetUp 1"; key_list_ = BuildKeyMap(kColumnMasterKeyIds, kColumnMasterKeys, kFooterMasterKeyId, kFooterMasterKey); + ARROW_LOG(INFO) << "SetUp 2"; new_key_list_ = BuildKeyMap(kColumnMasterKeyIds, kNewColumnMasterKeys, kFooterMasterKeyId, kNewFooterMasterKey); + ARROW_LOG(INFO) << "SetUp 3"; column_key_mapping_ = BuildColumnKeyMapping(); + ARROW_LOG(INFO) << "SetUp 4"; temp_dir_ = temp_data_dir().ValueOrDie(); + ARROW_LOG(INFO) << "SetUp 5"; } void SetupCryptoFactory(bool wrap_locally) { @@ -255,15 +260,19 @@ class TestEncryptionKeyManagementMultiThread : public TestEncryptionKeyManagemen }; TEST_F(TestEncryptionKeyManagement, WrapLocally) { + ARROW_LOG(INFO) << "WrapLocally 1"; this->SetupCryptoFactory(true); for (const bool internal_key_material : {false, true}) { for (const bool double_wrapping : {false, true}) { for (int encryption_no = 0; encryption_no < 4; encryption_no++) { + ARROW_LOG(INFO) << "WrapLocally 2"; this->WriteEncryptedParquetFile(double_wrapping, internal_key_material, encryption_no); + ARROW_LOG(INFO) << "WrapLocally 3"; this->ReadEncryptedParquetFile(double_wrapping, internal_key_material, encryption_no); + ARROW_LOG(INFO) << "WrapLocally 4"; } } } diff --git a/cpp/src/parquet/encryption/read_configurations_test.cc b/cpp/src/parquet/encryption/read_configurations_test.cc index f450f9274c261..ba60e10f508d3 100644 --- a/cpp/src/parquet/encryption/read_configurations_test.cc +++ b/cpp/src/parquet/encryption/read_configurations_test.cc @@ -23,6 +23,7 @@ #include "arrow/io/file.h" #include "arrow/testing/gtest_compat.h" #include "arrow/util/config.h" +#include "arrow/util/logging.h" #include "parquet/column_reader.h" #include "parquet/column_writer.h" @@ -172,11 +173,8 @@ class TestDecryptionConfiguration std::function&)> decrypt_func) { - std::string exception_msg; std::shared_ptr file_decryption_properties; - // if we get decryption_config_num = x then it means the actual number is x+1 - // and since we want decryption_config_num=4 we set the condition to 3 - if (decryption_config_num != 3) { + if (vector_of_decryption_configurations_[decryption_config_num]) { file_decryption_properties = vector_of_decryption_configurations_[decryption_config_num]->DeepClone(); } @@ -184,22 +182,18 @@ class TestDecryptionConfiguration decrypt_func(std::move(file), std::move(file_decryption_properties)); } + std::shared_ptr GetDecryptionProperties( + int decryption_config_num) { + const auto props = vector_of_decryption_configurations_[decryption_config_num]; + return props ? props->DeepClone() : nullptr; + } + void DecryptFile(const std::string& file, int decryption_config_num) { - DecryptFileInternal( - file, decryption_config_num, - [&](const std::string& file, - const std::shared_ptr& file_decryption_properties) { - decryptor_.DecryptFile(file, file_decryption_properties); - }); + decryptor_.DecryptFile(file, GetDecryptionProperties(decryption_config_num)); } void DecryptPageIndex(const std::string& file, int decryption_config_num) { - DecryptFileInternal( - file, decryption_config_num, - [&](const std::string& file, - const std::shared_ptr& file_decryption_properties) { - decryptor_.DecryptPageIndex(file, file_decryption_properties); - }); + decryptor_.DecryptPageIndex(file, GetDecryptionProperties(decryption_config_num)); } // Check that the decryption result is as expected. @@ -249,11 +243,14 @@ class TestDecryptionConfiguration // once the file is read and the second exists in parquet-testing/data folder. // The name of the files are passed as parameters to the unit-test. TEST_P(TestDecryptionConfiguration, TestDecryption) { + ARROW_LOG(INFO) << "TestDecryption 1"; int encryption_config_num = std::get<0>(GetParam()); const char* param_file_name = std::get<1>(GetParam()); // Decrypt parquet file that was generated in write_configurations_test.cc test. + ARROW_LOG(INFO) << "TestDecryption 2"; std::string tmp_file_name = "tmp_" + std::string(param_file_name); std::string file_name = temp_dir->path().ToString() + tmp_file_name; + ARROW_LOG(INFO) << "TestDecryption 3"; if (!fexists(file_name)) { std::stringstream ss; ss << "File " << file_name << " is missing from temporary dir."; @@ -263,8 +260,10 @@ TEST_P(TestDecryptionConfiguration, TestDecryption) { // Iterate over the decryption configurations and use each one to read the encrypted // parquet file. for (unsigned index = 0; index < vector_of_decryption_configurations_.size(); ++index) { + ARROW_LOG(INFO) << "TestDecryption 4"; unsigned decryption_config_num = index + 1; CheckResults(file_name, decryption_config_num, encryption_config_num); + ARROW_LOG(INFO) << "TestDecryption 5"; } // Delete temporary test file. ASSERT_EQ(std::remove(file_name.c_str()), 0); @@ -281,8 +280,10 @@ TEST_P(TestDecryptionConfiguration, TestDecryption) { // Iterate over the decryption configurations and use each one to read the encrypted // parquet file. for (unsigned index = 0; index < vector_of_decryption_configurations_.size(); ++index) { + ARROW_LOG(INFO) << "TestDecryption 6"; unsigned decryption_config_num = index + 1; CheckResults(file_name, decryption_config_num, encryption_config_num); + ARROW_LOG(INFO) << "TestDecryption 7"; } } diff --git a/cpp/src/parquet/encryption/test_encryption_util.cc b/cpp/src/parquet/encryption/test_encryption_util.cc index cf863da60a1d6..4cc722c025fb8 100644 --- a/cpp/src/parquet/encryption/test_encryption_util.cc +++ b/cpp/src/parquet/encryption/test_encryption_util.cc @@ -24,6 +24,7 @@ #include "arrow/io/file.h" #include "arrow/testing/future_util.h" +#include "arrow/util/logging.h" #include "arrow/util/unreachable.h" #include "parquet/encryption/test_encryption_util.h" @@ -346,6 +347,7 @@ void ReadAndVerifyColumn(RowGroupReader* rg_reader, RowGroupMetadata* rg_md, void FileDecryptor::DecryptFile( const std::string& file, const std::shared_ptr& file_decryption_properties) { + ARROW_LOG(INFO) << ".. DecryptFile 1"; std::string exception_msg; parquet::ReaderProperties reader_properties = parquet::default_reader_properties(); if (file_decryption_properties) { @@ -357,18 +359,23 @@ void FileDecryptor::DecryptFile( source, ::arrow::io::ReadableFile::Open(file, reader_properties.memory_pool())); auto file_reader = parquet::ParquetFileReader::Open(source, reader_properties); + ARROW_LOG(INFO) << ".. DecryptFile 2"; CheckFile(file_reader.get(), file_decryption_properties); + ARROW_LOG(INFO) << ".. DecryptFile 3"; if (file_decryption_properties) { reader_properties.file_decryption_properties(file_decryption_properties->DeepClone()); } auto fut = parquet::ParquetFileReader::OpenAsync(source, reader_properties); ASSERT_FINISHES_OK(fut); + ARROW_LOG(INFO) << ".. DecryptFile 4"; ASSERT_OK_AND_ASSIGN(file_reader, fut.MoveResult()); CheckFile(file_reader.get(), file_decryption_properties); + ARROW_LOG(INFO) << ".. DecryptFile 5"; file_reader->Close(); PARQUET_THROW_NOT_OK(source->Close()); + ARROW_LOG(INFO) << ".. DecryptFile 6"; } void FileDecryptor::CheckFile( @@ -517,6 +524,7 @@ void FileDecryptor::CheckFile( void FileDecryptor::DecryptPageIndex( const std::string& file, const std::shared_ptr& file_decryption_properties) { + ARROW_LOG(INFO) << ".. DecryptPageIndex 1"; std::string exception_msg; parquet::ReaderProperties reader_properties = parquet::default_reader_properties(); if (file_decryption_properties) { @@ -528,10 +536,13 @@ void FileDecryptor::DecryptPageIndex( source, ::arrow::io::ReadableFile::Open(file, reader_properties.memory_pool())); auto file_reader = parquet::ParquetFileReader::Open(source, reader_properties); + ARROW_LOG(INFO) << ".. DecryptPageIndex 2"; CheckPageIndex(file_reader.get(), file_decryption_properties); + ARROW_LOG(INFO) << ".. DecryptPageIndex 3"; ASSERT_NO_FATAL_FAILURE(file_reader->Close()); PARQUET_THROW_NOT_OK(source->Close()); + ARROW_LOG(INFO) << ".. DecryptPageIndex 4"; } template