Enable Driver Logging

Add todo to update logging system later

Add logs

Author: alinaliBQ

cpp/src/arrow/flight/sql/odbc/flight_sql/address_info.h

@@ -19,7 +19,8 @@
 
 #include <string>
 
-#include <arrow/flight/sql/odbc/odbcabstraction/include/odbcabstraction/platform.h>
+#include "arrow/flight/sql/odbc/odbcabstraction/include/odbcabstraction/platform.h"
+
 #include <sys/types.h>
 #include <cstdint>
 #if !_WIN32

cpp/src/arrow/flight/sql/odbc/flight_sql/flight_sql_driver.cc

@@ -20,9 +20,11 @@
 #include "arrow/flight/sql/odbc/odbcabstraction/include/odbcabstraction/platform.h"
 #include "arrow/flight/sql/odbc/odbcabstraction/include/odbcabstraction/spd_logger.h"
 #include "arrow/flight/sql/odbc/odbcabstraction/include/odbcabstraction/utils.h"
+#include "arrow/util/io_util.h"
 
 #define DEFAULT_MAXIMUM_FILE_SIZE 16777216
 #define CONFIG_FILE_NAME "arrow-odbc.ini"
+#define CONFIG_FILE_PATH "CONFIG_FILE_PATH"
 
 namespace driver {
 namespace flight_sql {
@@ -52,7 +54,9 @@ LogLevel ToLogLevel(int64_t level) {
 }  // namespace
 
 FlightSqlDriver::FlightSqlDriver()
-    : diagnostics_("Apache Arrow", "Flight SQL", OdbcVersion::V_3), version_("0.9.0.0") {}
+    : diagnostics_("Apache Arrow", "Flight SQL", OdbcVersion::V_3), version_("0.9.0.0") {
+  RegisterLog();
+}
 
 std::shared_ptr<Connection> FlightSqlDriver::CreateConnection(OdbcVersion odbc_version) {
   return std::make_shared<FlightSqlConnection>(odbc_version, version_);
@@ -63,14 +67,19 @@ odbcabstraction::Diagnostics& FlightSqlDriver::GetDiagnostics() { return diagnos
 void FlightSqlDriver::SetVersion(std::string version) { version_ = std::move(version); }
 
 void FlightSqlDriver::RegisterLog() {
+  std::string config_path = arrow::internal::GetEnvVar(CONFIG_FILE_PATH).ValueOr("");
+  if (config_path.empty()) {
+    return;
+  }
+
   odbcabstraction::PropertyMap propertyMap;
-  driver::odbcabstraction::ReadConfigFile(propertyMap, CONFIG_FILE_NAME);
+  driver::odbcabstraction::ReadConfigFile(propertyMap, config_path, CONFIG_FILE_NAME);
 
   auto log_enable_iterator = propertyMap.find(std::string(SPDLogger::LOG_ENABLED));
   auto log_enabled = log_enable_iterator != propertyMap.end()
                          ? odbcabstraction::AsBool(log_enable_iterator->second)
                          : false;
-  if (!log_enabled) {
+  if (!log_enabled.get()) {
     return;
   }
 

cpp/src/arrow/flight/sql/odbc/flight_sql/win_system_dsn.cc

@@ -29,6 +29,7 @@
 #include "arrow/flight/sql/odbc/flight_sql/include/flight_sql/ui/window.h"
 #include "arrow/flight/sql/odbc/flight_sql/system_dsn.h"
 #include "arrow/flight/sql/odbc/odbcabstraction/include/odbcabstraction/exceptions.h"
+#include "arrow/flight/sql/odbc/odbcabstraction/include/odbcabstraction/logger.h"
 
 #include <odbcinst.h>
 #include <codecvt>
@@ -87,7 +88,7 @@ bool DisplayConnectionWindow(void* windowParent, Configuration& config,
     properties = config.GetProperties();
     return true;
   } else {
-    // TODO: log cancelled dialog after logging is enabled.
+    LOG_INFO("Dialog is cancelled by user");
     return false;
   }
 }

cpp/src/arrow/flight/sql/odbc/odbc_api.cc

@@ -18,15 +18,15 @@
 // flight_sql_connection.h needs to be included first due to conflicts with windows.h
 #include "arrow/flight/sql/odbc/flight_sql/flight_sql_connection.h"
 
-#include <arrow/flight/sql/odbc/flight_sql/include/flight_sql/flight_sql_driver.h>
-#include <arrow/flight/sql/odbc/odbcabstraction/include/odbcabstraction/diagnostics.h>
-#include <arrow/flight/sql/odbc/odbcabstraction/include/odbcabstraction/odbc_impl/encoding_utils.h>
-#include <arrow/flight/sql/odbc/odbcabstraction/include/odbcabstraction/odbc_impl/odbc_connection.h>
-#include <arrow/flight/sql/odbc/odbcabstraction/include/odbcabstraction/odbc_impl/odbc_environment.h>
-#include <arrow/flight/sql/odbc/odbcabstraction/include/odbcabstraction/spi/connection.h>
-
 #include "arrow/flight/sql/odbc/flight_sql/include/flight_sql/config/configuration.h"
+#include "arrow/flight/sql/odbc/flight_sql/include/flight_sql/flight_sql_driver.h"
+#include "arrow/flight/sql/odbc/odbcabstraction/include/odbcabstraction/diagnostics.h"
+#include "arrow/flight/sql/odbc/odbcabstraction/include/odbcabstraction/logger.h"
 #include "arrow/flight/sql/odbc/odbcabstraction/include/odbcabstraction/odbc_impl/attribute_utils.h"
+#include "arrow/flight/sql/odbc/odbcabstraction/include/odbcabstraction/odbc_impl/encoding_utils.h"
+#include "arrow/flight/sql/odbc/odbcabstraction/include/odbcabstraction/odbc_impl/odbc_connection.h"
+#include "arrow/flight/sql/odbc/odbcabstraction/include/odbcabstraction/odbc_impl/odbc_environment.h"
+#include "arrow/flight/sql/odbc/odbcabstraction/include/odbcabstraction/spi/connection.h"
 
 #if defined _WIN32 || defined _WIN64
 // For displaying DSN Window
@@ -35,10 +35,13 @@
 
 // odbc_api includes windows.h, which needs to be put behind winsock2.h.
 // odbc_environment.h includes winsock2.h
-#include <arrow/flight/sql/odbc/odbc_api.h>
+#include "arrow/flight/sql/odbc/odbc_api.h"
 
 namespace arrow {
 SQLRETURN SQLAllocHandle(SQLSMALLINT type, SQLHANDLE parent, SQLHANDLE* result) {
+  LOG_DEBUG("SQLAllocHandle called with type: {}, parent: {}, result: {}", type, parent,
+            fmt::ptr(result));
+
   *result = nullptr;
 
   switch (type) {
@@ -93,6 +96,8 @@ SQLRETURN SQLAllocHandle(SQLSMALLINT type, SQLHANDLE parent, SQLHANDLE* result)
 }
 
 SQLRETURN SQLFreeHandle(SQLSMALLINT type, SQLHANDLE handle) {
+  LOG_DEBUG("SQLFreeHandle called with type: {}, handle: {}", type, handle);
+
   switch (type) {
     case SQL_HANDLE_ENV: {
       using ODBC::ODBCEnvironment;
@@ -160,6 +165,12 @@ SQLRETURN SQLGetDiagFieldW(SQLSMALLINT handleType, SQLHANDLE handle,
   using ODBC::ODBCConnection;
   using ODBC::ODBCEnvironment;
 
+  LOG_DEBUG(
+      "SQLGetDiagFieldW called with handleType: {}, handle: {}, recNumber: {}, "
+      "diagIdentifier: {}, diagInfoPtr: {}, bufferLength: {}, stringLengthPtr: {}",
+      handleType, handle, recNumber, diagIdentifier, diagInfoPtr, bufferLength,
+      fmt::ptr(stringLengthPtr));
+
   if (!handle) {
     return SQL_INVALID_HANDLE;
   }
@@ -369,6 +380,13 @@ SQLRETURN SQLGetDiagRecW(SQLSMALLINT handleType, SQLHANDLE handle, SQLSMALLINT r
   using ODBC::ODBCConnection;
   using ODBC::ODBCEnvironment;
 
+  LOG_DEBUG(
+      "SQLGetDiagRecW called with handleType: {}, handle: {}, recNumber: {}, "
+      "sqlState: {}, nativeErrorPtr: {}, messageText: {}, bufferLength: {}, "
+      "textLengthPtr: {}",
+      handleType, handle, recNumber, fmt::ptr(sqlState), fmt::ptr(nativeErrorPtr),
+      fmt::ptr(messageText), bufferLength, fmt::ptr(textLengthPtr));
+
   if (!handle) {
     return SQL_INVALID_HANDLE;
   }
@@ -438,10 +456,15 @@ SQLRETURN SQLGetDiagRecW(SQLSMALLINT handleType, SQLHANDLE handle, SQLSMALLINT r
 }
 
 SQLRETURN SQLGetEnvAttr(SQLHENV env, SQLINTEGER attr, SQLPOINTER valuePtr,
-                        SQLINTEGER bufferLen, SQLINTEGER* strLenPtr) {
+                        SQLINTEGER bufferLength, SQLINTEGER* strLenPtr) {
   using driver::odbcabstraction::DriverException;
   using ODBC::ODBCEnvironment;
 
+  LOG_DEBUG(
+      "SQLGetEnvAttr called with env: {}, attr: {}, valuePtr: {}, "
+      "bufferLength: {}, strLenPtr: {}",
+      env, attr, valuePtr, bufferLength, fmt::ptr(strLenPtr));
+
   ODBCEnvironment* environment = reinterpret_cast<ODBCEnvironment*>(env);
 
   return ODBCEnvironment::ExecuteWithDiagnostics(environment, SQL_ERROR, [=]() {
@@ -498,6 +521,11 @@ SQLRETURN SQLSetEnvAttr(SQLHENV env, SQLINTEGER attr, SQLPOINTER valuePtr,
   using driver::odbcabstraction::DriverException;
   using ODBC::ODBCEnvironment;
 
+  LOG_DEBUG(
+      "SQLSetEnvAttr called with env: {}, attr: {}, valuePtr: {}, "
+      "strLen: {}",
+      env, attr, valuePtr, strLen);
+
   ODBCEnvironment* environment = reinterpret_cast<ODBCEnvironment*>(env);
 
   return ODBCEnvironment::ExecuteWithDiagnostics(environment, SQL_ERROR, [=]() {
@@ -557,6 +585,14 @@ SQLRETURN SQLDriverConnectW(SQLHDBC conn, SQLHWND windowHandle,
   using driver::odbcabstraction::DriverException;
   using ODBC::ODBCConnection;
 
+  LOG_DEBUG(
+      "SQLDriverConnectW called with conn: {}, windowHandle: {}, inConnectionString: {}, "
+      "inConnectionStringLen: {}, outConnectionString: {}, outConnectionStringBufferLen: "
+      "{}, outConnectionStringLen: {}, driverCompletion: {}",
+      conn, fmt::ptr(windowHandle), fmt::ptr(inConnectionString), inConnectionStringLen,
+      fmt::ptr(outConnectionString), outConnectionStringBufferLen,
+      fmt::ptr(outConnectionStringLen), driverCompletion);
+
   return ODBCConnection::ExecuteWithDiagnostics(conn, SQL_ERROR, [=]() {
     ODBCConnection* connection = reinterpret_cast<ODBCConnection*>(conn);
     std::string connection_string =
@@ -621,6 +657,12 @@ SQLRETURN SQLConnectW(SQLHDBC conn, SQLWCHAR* dsnName, SQLSMALLINT dsnNameLen,
 
   using ODBC::SqlWcharToString;
 
+  LOG_DEBUG(
+      "SQLConnectW called with conn: {}, dsnName: {}, dsnNameLen: {}, userName: {}, "
+      "userNameLen: {}, password: {}, passwordLen: {}",
+      conn, fmt::ptr(dsnName), dsnNameLen, fmt::ptr(userName), userNameLen,
+      fmt::ptr(password), passwordLen);
+
   return ODBCConnection::ExecuteWithDiagnostics(conn, SQL_ERROR, [=]() {
     ODBCConnection* connection = reinterpret_cast<ODBCConnection*>(conn);
     std::string dsn = SqlWcharToString(dsnName, dsnNameLen);
@@ -649,6 +691,8 @@ SQLRETURN SQLConnectW(SQLHDBC conn, SQLWCHAR* dsnName, SQLSMALLINT dsnNameLen,
 SQLRETURN SQLDisconnect(SQLHDBC conn) {
   using ODBC::ODBCConnection;
 
+  LOG_DEBUG("SQLDisconnect called with conn: {}", conn);
+
   return ODBCConnection::ExecuteWithDiagnostics(conn, SQL_ERROR, [=]() {
     ODBCConnection* connection = reinterpret_cast<ODBCConnection*>(conn);
 
@@ -663,6 +707,11 @@ SQLRETURN SQLGetInfoW(SQLHDBC conn, SQLUSMALLINT infoType, SQLPOINTER infoValueP
   // TODO: complete implementation of SQLGetInfoW and write tests
   using ODBC::ODBCConnection;
 
+  LOG_DEBUG(
+      "SQLGetInfoW called with conn: {}, infoType: {}, infoValuePtr: {}, bufLen: {}, "
+      "length: {}",
+      conn, infoType, infoValuePtr, bufLen, fmt::ptr(length));
+
   return ODBCConnection::ExecuteWithDiagnostics(conn, SQL_ERROR, [=]() {
     ODBCConnection* connection = reinterpret_cast<ODBCConnection*>(conn);
 

cpp/src/arrow/flight/sql/odbc/odbcabstraction/include/odbcabstraction/logger.h

@@ -20,7 +20,10 @@
 #include <functional>
 #include <string>
 
-#include <spdlog/fmt/bundled/format.h>
+#include <spdlog/fmt/fmt.h>
+
+// The logger using spdlog is deprecated and will be replaced.
+// TODO: mirgate logging to use Arrow's internal logging system
 
 #define __LAZY_LOG(LEVEL, ...)                                         \
   do {                                                                 \

cpp/src/arrow/flight/sql/odbc/odbcabstraction/include/odbcabstraction/utils.h

@@ -52,7 +52,8 @@ boost::optional<int32_t> AsInt32(int32_t min_value,
                                  const Connection::ConnPropertyMap& connPropertyMap,
                                  const std::string_view& property_name);
 
-void ReadConfigFile(PropertyMap& properties, const std::string& configFileName);
+void ReadConfigFile(PropertyMap& properties, const std::string& configPath,
+                    const std::string& configFileName);
 
 }  // namespace odbcabstraction
 }  // namespace driver

cpp/src/arrow/flight/sql/odbc/odbcabstraction/utils.cc

@@ -81,9 +81,8 @@ std::string GetModulePath() {
   return std::string(path.begin(), path.begin() + dirname_length);
 }
 
-void ReadConfigFile(PropertyMap& properties, const std::string& config_file_name) {
-  auto config_path = GetModulePath();
-
+void ReadConfigFile(PropertyMap& properties, const std::string& config_path,
+                    const std::string& config_file_name) {
   std::ifstream config_file;
   auto config_file_path = config_path + "/" + config_file_name;
   config_file.open(config_file_path);