Skip to content

Commit

Permalink
Merge pull request #1715 from Expensify/main
Browse files Browse the repository at this point in the history 
Update expensify_prod branch
  • Loading branch information
@AndrewGable
AndrewGable authored May 7, 2024
2 parents f1ac3f2 + 447ac96 commit ad1788e
Show file tree
Hide file tree
Showing 5 changed files with 34 additions and 29 deletions.
25 changes: 20 additions & 5 deletions BedrockCommand.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -132,11 +132,13 @@ void BedrockCommand::reset(BedrockCommand::STAGE stage) {

void BedrockCommand::finalizeTimingInfo() {
uint64_t prePeekTotal = 0;
uint64_t blockingPrePeekTotal = 0;
uint64_t peekTotal = 0;
uint64_t blockingPeekTotal = 0;
uint64_t processTotal = 0;
uint64_t postProcessTotal = 0;
uint64_t blockingProcessTotal = 0;
uint64_t postProcessTotal = 0;
uint64_t blockingPostProcessTotal = 0;
uint64_t commitWorkerTotal = 0;
uint64_t blockingCommitWorkerTotal = 0;
uint64_t commitSyncTotal = 0;
Expand All @@ -147,18 +149,24 @@ void BedrockCommand::finalizeTimingInfo() {
for (const auto& entry: timingInfo) {
if (get<0>(entry) == PREPEEK) {
prePeekTotal += get<2>(entry) - get<1>(entry);
} else if (get<0>(entry) == BLOCKING_PREPEEK) {
prePeekTotal += get<2>(entry) - get<1>(entry);
blockingPrePeekTotal += get<2>(entry) - get<1>(entry);
} else if (get<0>(entry) == PEEK) {
peekTotal += get<2>(entry) - get<1>(entry);
} else if (get<0>(entry) == BLOCKING_PEEK) {
peekTotal += get<2>(entry) - get<1>(entry);
blockingPeekTotal += get<2>(entry) - get<1>(entry);
} else if (get<0>(entry) == PROCESS) {
processTotal += get<2>(entry) - get<1>(entry);
} else if (get<0>(entry) == POSTPROCESS) {
postProcessTotal += get<2>(entry) - get<1>(entry);
} else if (get<0>(entry) == BLOCKING_PROCESS) {
processTotal += get<2>(entry) - get<1>(entry);
blockingProcessTotal += get<2>(entry) - get<1>(entry);
} else if (get<0>(entry) == POSTPROCESS) {
postProcessTotal += get<2>(entry) - get<1>(entry);
} else if (get<0>(entry) == BLOCKING_POSTPROCESS) {
postProcessTotal += get<2>(entry) - get<1>(entry);
blockingPostProcessTotal += get<2>(entry) - get<1>(entry);
} else if (get<0>(entry) == COMMIT_WORKER) {
commitWorkerTotal += get<2>(entry) - get<1>(entry);
} else if (get<0>(entry) == BLOCKING_COMMIT_WORKER) {
Expand All @@ -184,6 +192,9 @@ void BedrockCommand::finalizeTimingInfo() {
uint64_t unaccountedTime = totalTime - (prePeekTotal + peekTotal + processTotal + postProcessTotal + commitWorkerTotal + commitSyncTotal +
escalationTimeUS + queueWorkerTotal + queueBlockingTotal + queueSyncTotal + queuePageLockTotal);

uint64_t exclusiveTransactionLockTime = blockingPeekTotal + blockingProcessTotal + blockingCommitWorkerTotal;
uint64_t blockingCommitThreadTime = exclusiveTransactionLockTime + blockingPrePeekTotal + blockingPostProcessTotal;

// Build a map of the values we care about.
map<string, uint64_t> valuePairs = {
{"prePeekTime", prePeekTotal},
Expand Down Expand Up @@ -240,12 +251,14 @@ void BedrockCommand::finalizeTimingInfo() {
}

SINFO("command '" << methodName << "' timing info (ms): "
"prePeek: " << prePeekTotal/1000 << " (count: " << prePeekCount << "), "
"prePeek:" << prePeekTotal/1000 << " (count: " << prePeekCount << "), "
"peek:" << peekTotal/1000 << " (count:" << peekCount << "), "
"process:" << processTotal/1000 << " (count:" << processCount << "), "
"postProcess:" << postProcessTotal/1000 << " (count:" << postProcessCount << "), "
"total:" << totalTime/1000 << ", "
"unaccounted:" << unaccountedTime/1000 <<
"unaccounted:" << unaccountedTime/1000 << ", "
"blockingCommitThreadTime:" << blockingCommitThreadTime/1000 << ", "
"exclusiveTransactionLockTime:" << exclusiveTransactionLockTime/1000 <<
". Commit: "
"worker:" << commitWorkerTotal/1000 << ", "
"sync:"<< commitSyncTotal/1000 <<
Expand All @@ -256,8 +269,10 @@ void BedrockCommand::finalizeTimingInfo() {
"pageLock:" << queuePageLockTotal/1000 << ", "
"escalation:" << escalationTimeUS/1000 <<
". Blocking: "
"prePeek:" << blockingPrePeekTotal/1000 << ", "
"peek:" << blockingPeekTotal/1000 << ", "
"process:" << blockingProcessTotal/1000 << ", "
"postProcess:" << blockingPostProcessTotal/1000 << ", "
"commit:" << blockingCommitWorkerTotal/1000 <<
". Upstream: "
"peek:" << upstreamPeekTime/1000 << ", "
Expand Down
4 changes: 4 additions & 0 deletions BedrockCommand.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -26,8 +26,12 @@ class BedrockCommand : public SQLiteCommand {
QUEUE_SYNC,
QUEUE_BLOCKING,
QUEUE_PAGE_LOCK,

// Time spent in the blockingCommit thread (not the same as "commit lock time")
BLOCKING_PREPEEK,
BLOCKING_PEEK,
BLOCKING_PROCESS,
BLOCKING_POSTPROCESS,
BLOCKING_COMMIT_WORKER,
};

Expand Down
22 changes: 4 additions & 18 deletions BedrockCore.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -64,8 +64,8 @@ bool BedrockCore::isTimedOut(unique_ptr<BedrockCommand>& command) {
return false;
}

void BedrockCore::prePeekCommand(unique_ptr<BedrockCommand>& command) {
AutoTimer timer(command, BedrockCommand::PREPEEK);
void BedrockCore::prePeekCommand(unique_ptr<BedrockCommand>& command, bool isBlockingCommitThread) {
AutoTimer timer(command, isBlockingCommitThread ? BedrockCommand::BLOCKING_PREPEEK : BedrockCommand::PREPEEK);

// Convenience references to commonly used properties.
const SData& request = command->request;
Expand All @@ -78,10 +78,6 @@ void BedrockCore::prePeekCommand(unique_ptr<BedrockCommand>& command) {
command->prePeekCount++;
_db.setTimeout(_getRemainingTime(command, false));

if (!_db.beginTransaction(SQLite::TRANSACTION_TYPE::SHARED)) {
STHROW("501 Failed to begin shared prePeek transaction");
}

// Make sure no writes happen while in prePeek command
_db.setQueryOnly(true);

Expand Down Expand Up @@ -115,9 +111,6 @@ void BedrockCore::prePeekCommand(unique_ptr<BedrockCommand>& command) {
command->response.methodLine = "500 Unhandled Exception";
command->complete = true;
}

// Back out of the current transaction, it doesn't need to do anything.
_db.rollback();
_db.clearTimeout();

// Reset, we can write now.
Expand Down Expand Up @@ -313,8 +306,8 @@ BedrockCore::RESULT BedrockCore::processCommand(unique_ptr<BedrockCommand>& comm
return needsCommit ? RESULT::NEEDS_COMMIT : RESULT::NO_COMMIT_REQUIRED;
}

void BedrockCore::postProcessCommand(unique_ptr<BedrockCommand>& command) {
AutoTimer timer(command, BedrockCommand::POSTPROCESS);
void BedrockCore::postProcessCommand(unique_ptr<BedrockCommand>& command, bool isBlockingCommitThread) {
AutoTimer timer(command, isBlockingCommitThread ? BedrockCommand::BLOCKING_POSTPROCESS : BedrockCommand::POSTPROCESS);

// Convenience references to commonly used properties.
const SData& request = command->request;
Expand All @@ -328,10 +321,6 @@ void BedrockCore::postProcessCommand(unique_ptr<BedrockCommand>& command) {
command->postProcessCount++;
_db.setTimeout(_getRemainingTime(command, false));

if (!_db.beginTransaction(SQLite::TRANSACTION_TYPE::SHARED)) {
STHROW("501 Failed to begin shared postProcess transaction");
}

// Make sure no writes happen while in postProcess command
_db.setQueryOnly(true);

Expand Down Expand Up @@ -367,9 +356,6 @@ void BedrockCore::postProcessCommand(unique_ptr<BedrockCommand>& command) {

// The command is complete.
command->complete = true;

// Back out of the current transaction, it doesn't need to do anything.
_db.rollback();
_db.clearTimeout();

// Reset, we can write now.
Expand Down
4 changes: 2 additions & 2 deletions BedrockCore.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -36,7 +36,7 @@ class BedrockCore : public SQLiteCore {
// the command hasn't timed out.
bool isTimedOut(unique_ptr<BedrockCommand>& command);

void prePeekCommand(unique_ptr<BedrockCommand>& command);
void prePeekCommand(unique_ptr<BedrockCommand>& command, bool isBlockingCommitThread);

// Peek lets you pre-process a command. It will be called on each command before `process` is called on the same
// command, and it *may be called multiple times*. Preventing duplicate actions on calling peek multiple times is
Expand All @@ -59,7 +59,7 @@ class BedrockCore : public SQLiteCore {
// this command *will be passed to process again in the future to retry*.
RESULT processCommand(unique_ptr<BedrockCommand>& command, bool exclusive = false);

void postProcessCommand(unique_ptr<BedrockCommand>& command);
void postProcessCommand(unique_ptr<BedrockCommand>& command, bool isBlockingCommitThread);

private:
// When called in the context of handling an exception, returns the demangled (if possible) name of the exception.
Expand Down
8 changes: 4 additions & 4 deletions BedrockServer.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -380,7 +380,7 @@ void BedrockServer::sync()

if (command->shouldPostProcess() && command->response.methodLine == "200 OK") {
// PostProcess if the command should run postProcess, and there have been no errors thrown thus far.
core.postProcessCommand(command);
core.postProcessCommand(command, false);
}

if (_syncNode->commitSucceeded()) {
Expand Down Expand Up @@ -478,7 +478,7 @@ void BedrockServer::sync()
// re-verify that any checks made in peek are still valid in process.
if (!command->httpsRequests.size()) {
if (command->shouldPrePeek() && !command->repeek) {
core.prePeekCommand(command);
core.prePeekCommand(command, false);
}

// This command finsihed in prePeek, which likely means it threw.
Expand Down Expand Up @@ -868,7 +868,7 @@ void BedrockServer::runCommand(unique_ptr<BedrockCommand>&& _command, bool isBlo

// If the command should run prePeek, do that now .
if (!command->repeek && !command->httpsRequests.size() && command->shouldPrePeek()) {
core.prePeekCommand(command);
core.prePeekCommand(command, isBlocking);

if (command->complete) {
_reply(command);
Expand Down Expand Up @@ -1027,7 +1027,7 @@ void BedrockServer::runCommand(unique_ptr<BedrockCommand>&& _command, bool isBlo
if (command->complete) {
if (command->shouldPostProcess() && command->response.methodLine == "200 OK") {
// PostProcess if the command should run postProcess, and there have been no errors thrown thus far.
core.postProcessCommand(command);
core.postProcessCommand(command, isBlocking);
}
_reply(command);

Expand Down

0 comments on commit ad1788e

Please sign in to comment.