Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Logging improvements #2378

Merged
merged 2 commits into from
Jul 26, 2022
Merged

Logging improvements #2378

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
3d91ccf
Log connection identifier for statements. Append to log file rather t…
JohnMcPMS Jul 22, 2022
8a6ea48
Spelling
JohnMcPMS Jul 26, 2022
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions .github/actions/spelling/expect.txt
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -291,6 +291,7 @@ NX
objbase
objidl
ofile
openmode
Outptr
packageinuse
PACL
Expand Down
5 changes: 3 additions & 2 deletions src/AppInstallerCommonCore/FileLogger.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,7 @@ namespace AppInstaller::Logging

static constexpr std::string_view s_fileLoggerDefaultFilePrefix = "WinGet"sv;
static constexpr std::string_view s_fileLoggerDefaultFileExt = ".log"sv;
static constexpr std::ios_base::openmode s_fileLoggerDefaultOpenMode = std::ios_base::out | std::ios_base::app;

FileLogger::FileLogger() : FileLogger(s_fileLoggerDefaultFilePrefix) {}

Expand All @@ -23,7 +24,7 @@ namespace AppInstaller::Logging
m_name = GetNameForPath(filePath);
m_filePath = filePath;

m_stream.open(m_filePath);
m_stream.open(m_filePath, s_fileLoggerDefaultOpenMode);
}

FileLogger::FileLogger(const std::string_view fileNamePrefix)
Expand All @@ -32,7 +33,7 @@ namespace AppInstaller::Logging
m_filePath = Runtime::GetPathTo(Runtime::PathName::DefaultLogLocation);
m_filePath /= fileNamePrefix.data() + ('-' + Utility::GetCurrentTimeForFilename() + s_fileLoggerDefaultFileExt.data());

m_stream.open(m_filePath);
m_stream.open(m_filePath, s_fileLoggerDefaultOpenMode);
}

FileLogger::~FileLogger()
Expand Down
25 changes: 19 additions & 6 deletions src/AppInstallerRepositoryCore/SQLiteWrapper.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -37,6 +37,12 @@ namespace AppInstaller::Repository::SQLite

namespace
{
size_t GetNextConnectionId()
{
static std::atomic_size_t connectionId(0);
return ++connectionId;
}

size_t GetNextStatementId()
{
static std::atomic_size_t statementId(0);
Expand Down Expand Up @@ -141,7 +147,8 @@ namespace AppInstaller::Repository::SQLite

Connection::Connection(const std::string& target, OpenDisposition disposition, OpenFlags flags)
{
AICLI_LOG(SQL, Info, << "Opening SQLite connection: '" << target << "' [" << std::hex << static_cast<int>(disposition) << ", " << std::hex << static_cast<int>(flags) << "]");
m_id = GetNextConnectionId();
AICLI_LOG(SQL, Info, << "Opening SQLite connection #" << m_id << ": '" << target << "' [" << std::hex << static_cast<int>(disposition) << ", " << std::hex << static_cast<int>(flags) << "]");
// Always force connection serialization until we determine that there are situations where it is not needed
int resultingFlags = static_cast<int>(disposition) | static_cast<int>(flags) | SQLITE_OPEN_FULLMUTEX;
THROW_IF_SQLITE_FAILED(sqlite3_open_v2(target.c_str(), &m_dbconn, resultingFlags, nullptr), nullptr);
Expand Down Expand Up @@ -172,10 +179,16 @@ namespace AppInstaller::Repository::SQLite
return sqlite3_changes(m_dbconn.get());
}

size_t Connection::GetID() const
{
return m_id;
}

Statement::Statement(const Connection& connection, std::string_view sql)
{
m_connectionId = connection.GetID();
m_id = GetNextStatementId();
AICLI_LOG(SQL, Verbose, << "Preparing statement #" << m_id << ": " << sql);
AICLI_LOG(SQL, Verbose, << "Preparing statement #" << m_connectionId << '-' << m_id << ": " << sql);
// SQL string size should include the null terminator (https://www.sqlite.org/c3ref/prepare.html)
assert(sql.data()[sql.size()] == '\0');
THROW_IF_SQLITE_FAILED(sqlite3_prepare_v2(connection, sql.data(), static_cast<int>(sql.size() + 1), &m_stmt, nullptr), connection);
Expand Down Expand Up @@ -241,18 +254,18 @@ namespace AppInstaller::Repository::SQLite

bool Statement::Step(bool failFastOnError)
{
AICLI_LOG(SQL, Verbose, << "Stepping statement #" << m_id);
AICLI_LOG(SQL, Verbose, << "Stepping statement #" << m_connectionId << '-' << m_id);
int result = sqlite3_step(m_stmt.get());

if (result == SQLITE_ROW)
{
AICLI_LOG(SQL, Verbose, << "Statement #" << m_id << " has data");
AICLI_LOG(SQL, Verbose, << "Statement #" << m_connectionId << '-' << m_id << " has data");
m_state = State::HasRow;
return true;
}
else if (result == SQLITE_DONE)
{
AICLI_LOG(SQL, Verbose, << "Statement #" << m_id << " has completed");
AICLI_LOG(SQL, Verbose, << "Statement #" << m_connectionId << '-' << m_id << " has completed");
m_state = State::Completed;
return false;
}
Expand Down Expand Up @@ -283,7 +296,7 @@ namespace AppInstaller::Repository::SQLite

void Statement::Reset()
{
AICLI_LOG(SQL, Verbose, << "Reset statement #" << m_id);
AICLI_LOG(SQL, Verbose, << "Reset statement #" << m_connectionId << '-' << m_id);
// Ignore return value from reset, as if it is an error, it was the error from the last call to step.
sqlite3_reset(m_stmt.get());
m_state = State::Prepared;
Expand Down
7 changes: 6 additions & 1 deletion src/AppInstallerRepositoryCore/SQLiteWrapper.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -177,11 +177,15 @@ namespace AppInstaller::Repository::SQLite
// Gets the count of changed rows for the last executed statement.
int GetChanges() const;

//. Gets the (fixed but arbitrary) identifier for this connection.
size_t GetID() const;

operator sqlite3* () const { return m_dbconn.get(); }

private:
Connection(const std::string& target, OpenDisposition disposition, OpenFlags flags);

size_t m_id = 0;
wil::unique_any<sqlite3*, decltype(sqlite3_close_v2), sqlite3_close_v2> m_dbconn;
};

Expand Down Expand Up @@ -223,7 +227,7 @@ namespace AppInstaller::Repository::SQLite
template <typename Value>
void Bind(int index, Value&& v)
{
AICLI_LOG(SQL, Verbose, << "Binding statement #" << m_id << ": " << index << " => " << details::ParameterSpecifics<Value>::ToLog(std::forward<Value>(v)));
AICLI_LOG(SQL, Verbose, << "Binding statement #" << m_connectionId << '-' << m_id << ": " << index << " => " << details::ParameterSpecifics<Value>::ToLog(std::forward<Value>(v)));
details::ParameterSpecifics<Value>::Bind(m_stmt.get(), index, std::forward<Value>(v));
}

Expand Down Expand Up @@ -278,6 +282,7 @@ namespace AppInstaller::Repository::SQLite
return std::make_tuple(details::ParameterSpecifics<Values>::GetColumn(m_stmt.get(), I)...);
}

size_t m_connectionId = 0;
size_t m_id = 0;
wil::unique_any<sqlite3_stmt*, decltype(sqlite3_finalize), sqlite3_finalize> m_stmt;
State m_state = State::Prepared;
Expand Down