Merge pull request #976 from alexmiller-apple/jsonlogs

Allow trace logs to be output as JSON instead of XML
This commit is contained in:
A.J. Beamon 2019-01-09 17:04:50 -05:00 committed by GitHub
commit 7c5b2ab330
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
8 changed files with 200 additions and 4 deletions

View File

@ -110,7 +110,9 @@ enum {
//DB constants
OPT_SOURCE_CLUSTER,
OPT_DEST_CLUSTER,
OPT_CLEANUP
OPT_CLEANUP,
OPT_TRACE_FORMAT
};
CSimpleOpt::SOption g_rgAgentOptions[] = {
@ -127,6 +129,7 @@ CSimpleOpt::SOption g_rgAgentOptions[] = {
{ OPT_QUIET, "--quiet", SO_NONE },
{ OPT_TRACE, "--log", SO_NONE },
{ OPT_TRACE_DIR, "--logdir", SO_REQ_SEP },
{ OPT_TRACE_FORMAT, "--trace_format", SO_REQ_SEP },
{ OPT_CRASHONERROR, "--crash", SO_NONE },
{ OPT_LOCALITY, "--locality_", SO_REQ_SEP },
{ OPT_MEMLIMIT, "-m", SO_REQ_SEP },
@ -162,6 +165,7 @@ CSimpleOpt::SOption g_rgBackupStartOptions[] = {
{ OPT_DRYRUN, "--dryrun", SO_NONE },
{ OPT_TRACE, "--log", SO_NONE },
{ OPT_TRACE_DIR, "--logdir", SO_REQ_SEP },
{ OPT_TRACE_FORMAT, "--trace_format", SO_REQ_SEP },
{ OPT_QUIET, "-q", SO_NONE },
{ OPT_QUIET, "--quiet", SO_NONE },
{ OPT_VERSION, "--version", SO_NONE },
@ -191,6 +195,7 @@ CSimpleOpt::SOption g_rgBackupStatusOptions[] = {
{ OPT_TAGNAME, "--tagname", SO_REQ_SEP },
{ OPT_TRACE, "--log", SO_NONE },
{ OPT_TRACE_DIR, "--logdir", SO_REQ_SEP },
{ OPT_TRACE_FORMAT, "--trace_format", SO_REQ_SEP },
{ OPT_VERSION, "--version", SO_NONE },
{ OPT_VERSION, "-v", SO_NONE },
{ OPT_QUIET, "-q", SO_NONE },
@ -216,6 +221,7 @@ CSimpleOpt::SOption g_rgBackupAbortOptions[] = {
{ OPT_TAGNAME, "--tagname", SO_REQ_SEP },
{ OPT_TRACE, "--log", SO_NONE },
{ OPT_TRACE_DIR, "--logdir", SO_REQ_SEP },
{ OPT_TRACE_FORMAT, "--trace_format", SO_REQ_SEP },
{ OPT_QUIET, "-q", SO_NONE },
{ OPT_QUIET, "--quiet", SO_NONE },
{ OPT_VERSION, "--version", SO_NONE },
@ -243,6 +249,7 @@ CSimpleOpt::SOption g_rgBackupDiscontinueOptions[] = {
{ OPT_WAITFORDONE, "--waitfordone", SO_NONE },
{ OPT_TRACE, "--log", SO_NONE },
{ OPT_TRACE_DIR, "--logdir", SO_REQ_SEP },
{ OPT_TRACE_FORMAT, "--trace_format", SO_REQ_SEP },
{ OPT_QUIET, "-q", SO_NONE },
{ OPT_QUIET, "--quiet", SO_NONE },
{ OPT_VERSION, "--version", SO_NONE },
@ -270,6 +277,7 @@ CSimpleOpt::SOption g_rgBackupWaitOptions[] = {
{ OPT_NOSTOPWHENDONE, "--no-stop-when-done",SO_NONE },
{ OPT_TRACE, "--log", SO_NONE },
{ OPT_TRACE_DIR, "--logdir", SO_REQ_SEP },
{ OPT_TRACE_FORMAT, "--trace_format", SO_REQ_SEP },
{ OPT_QUIET, "-q", SO_NONE },
{ OPT_QUIET, "--quiet", SO_NONE },
{ OPT_VERSION, "--version", SO_NONE },
@ -293,6 +301,7 @@ CSimpleOpt::SOption g_rgBackupPauseOptions[] = {
{ OPT_CLUSTERFILE, "--cluster_file", SO_REQ_SEP },
{ OPT_TRACE, "--log", SO_NONE },
{ OPT_TRACE_DIR, "--logdir", SO_REQ_SEP },
{ OPT_TRACE_FORMAT, "--trace_format", SO_REQ_SEP },
{ OPT_QUIET, "-q", SO_NONE },
{ OPT_QUIET, "--quiet", SO_NONE },
{ OPT_VERSION, "--version", SO_NONE },
@ -318,6 +327,7 @@ CSimpleOpt::SOption g_rgBackupExpireOptions[] = {
{ OPT_DESTCONTAINER, "--destcontainer", SO_REQ_SEP },
{ OPT_TRACE, "--log", SO_NONE },
{ OPT_TRACE_DIR, "--logdir", SO_REQ_SEP },
{ OPT_TRACE_FORMAT, "--trace_format", SO_REQ_SEP },
{ OPT_QUIET, "-q", SO_NONE },
{ OPT_QUIET, "--quiet", SO_NONE },
{ OPT_VERSION, "-v", SO_NONE },
@ -349,6 +359,7 @@ CSimpleOpt::SOption g_rgBackupDeleteOptions[] = {
{ OPT_DESTCONTAINER, "--destcontainer", SO_REQ_SEP },
{ OPT_TRACE, "--log", SO_NONE },
{ OPT_TRACE_DIR, "--logdir", SO_REQ_SEP },
{ OPT_TRACE_FORMAT, "--trace_format", SO_REQ_SEP },
{ OPT_QUIET, "-q", SO_NONE },
{ OPT_QUIET, "--quiet", SO_NONE },
{ OPT_VERSION, "-v", SO_NONE },
@ -376,6 +387,7 @@ CSimpleOpt::SOption g_rgBackupDescribeOptions[] = {
{ OPT_DESTCONTAINER, "--destcontainer", SO_REQ_SEP },
{ OPT_TRACE, "--log", SO_NONE },
{ OPT_TRACE_DIR, "--logdir", SO_REQ_SEP },
{ OPT_TRACE_FORMAT, "--trace_format", SO_REQ_SEP },
{ OPT_QUIET, "-q", SO_NONE },
{ OPT_QUIET, "--quiet", SO_NONE },
{ OPT_VERSION, "-v", SO_NONE },
@ -403,6 +415,7 @@ CSimpleOpt::SOption g_rgBackupListOptions[] = {
{ OPT_BASEURL, "--base_url", SO_REQ_SEP },
{ OPT_TRACE, "--log", SO_NONE },
{ OPT_TRACE_DIR, "--logdir", SO_REQ_SEP },
{ OPT_TRACE_FORMAT, "--trace_format", SO_REQ_SEP },
{ OPT_QUIET, "-q", SO_NONE },
{ OPT_QUIET, "--quiet", SO_NONE },
{ OPT_VERSION, "-v", SO_NONE },
@ -440,6 +453,7 @@ CSimpleOpt::SOption g_rgRestoreOptions[] = {
{ OPT_DBVERSION, "-v", SO_REQ_SEP },
{ OPT_TRACE, "--log", SO_NONE },
{ OPT_TRACE_DIR, "--logdir", SO_REQ_SEP },
{ OPT_TRACE_FORMAT, "--trace_format", SO_REQ_SEP },
{ OPT_QUIET, "-q", SO_NONE },
{ OPT_QUIET, "--quiet", SO_NONE },
{ OPT_DRYRUN, "-n", SO_NONE },
@ -473,6 +487,7 @@ CSimpleOpt::SOption g_rgDBAgentOptions[] = {
{ OPT_QUIET, "--quiet", SO_NONE },
{ OPT_TRACE, "--log", SO_NONE },
{ OPT_TRACE_DIR, "--logdir", SO_REQ_SEP },
{ OPT_TRACE_FORMAT, "--trace_format", SO_REQ_SEP },
{ OPT_CRASHONERROR, "--crash", SO_NONE },
{ OPT_LOCALITY, "--locality_", SO_REQ_SEP },
{ OPT_MEMLIMIT, "-m", SO_REQ_SEP },
@ -499,6 +514,7 @@ CSimpleOpt::SOption g_rgDBStartOptions[] = {
{ OPT_BACKUPKEYS, "--keys", SO_REQ_SEP },
{ OPT_TRACE, "--log", SO_NONE },
{ OPT_TRACE_DIR, "--logdir", SO_REQ_SEP },
{ OPT_TRACE_FORMAT, "--trace_format", SO_REQ_SEP },
{ OPT_QUIET, "-q", SO_NONE },
{ OPT_QUIET, "--quiet", SO_NONE },
{ OPT_VERSION, "--version", SO_NONE },
@ -528,6 +544,7 @@ CSimpleOpt::SOption g_rgDBStatusOptions[] = {
{ OPT_TAGNAME, "--tagname", SO_REQ_SEP },
{ OPT_TRACE, "--log", SO_NONE },
{ OPT_TRACE_DIR, "--logdir", SO_REQ_SEP },
{ OPT_TRACE_FORMAT, "--trace_format", SO_REQ_SEP },
{ OPT_VERSION, "--version", SO_NONE },
{ OPT_VERSION, "-v", SO_NONE },
{ OPT_QUIET, "-q", SO_NONE },
@ -555,6 +572,7 @@ CSimpleOpt::SOption g_rgDBSwitchOptions[] = {
{ OPT_TAGNAME, "--tagname", SO_REQ_SEP },
{ OPT_TRACE, "--log", SO_NONE },
{ OPT_TRACE_DIR, "--logdir", SO_REQ_SEP },
{ OPT_TRACE_FORMAT, "--trace_format", SO_REQ_SEP },
{ OPT_QUIET, "-q", SO_NONE },
{ OPT_QUIET, "--quiet", SO_NONE },
{ OPT_VERSION, "--version", SO_NONE },
@ -583,6 +601,7 @@ CSimpleOpt::SOption g_rgDBAbortOptions[] = {
{ OPT_TAGNAME, "--tagname", SO_REQ_SEP },
{ OPT_TRACE, "--log", SO_NONE },
{ OPT_TRACE_DIR, "--logdir", SO_REQ_SEP },
{ OPT_TRACE_FORMAT, "--trace_format", SO_REQ_SEP },
{ OPT_QUIET, "-q", SO_NONE },
{ OPT_QUIET, "--quiet", SO_NONE },
{ OPT_VERSION, "--version", SO_NONE },
@ -608,6 +627,7 @@ CSimpleOpt::SOption g_rgDBPauseOptions[] = {
{ OPT_DEST_CLUSTER, "--destination", SO_REQ_SEP },
{ OPT_TRACE, "--log", SO_NONE },
{ OPT_TRACE_DIR, "--logdir", SO_REQ_SEP },
{ OPT_TRACE_FORMAT, "--trace_format", SO_REQ_SEP },
{ OPT_QUIET, "-q", SO_NONE },
{ OPT_QUIET, "--quiet", SO_NONE },
{ OPT_VERSION, "--version", SO_NONE },
@ -677,6 +697,9 @@ static void printAgentUsage(bool devhelp) {
" --logdir PATH Specifes the output directory for trace files. If\n"
" unspecified, defaults to the current directory. Has\n"
" no effect unless --log is specified.\n");
printf(" --trace_format FORMAT\n"
" Select the format of the trace files. xml (the default) and json are supported.\n"
" Has no effect unless --log is specified.\n");
printf(" -m SIZE, --memory SIZE\n"
" Memory limit. The default value is 8GiB. When specified\n"
" without a unit, MiB is assumed.\n");
@ -812,6 +835,9 @@ static void printDBAgentUsage(bool devhelp) {
" --logdir PATH Specifes the output directory for trace files. If\n"
" unspecified, defaults to the current directory. Has\n"
" no effect unless --log is specified.\n");
printf(" --trace_format FORMAT\n"
" Select the format of the trace files. xml (the default) and json are supported.\n"
" Has no effect unless --log is specified.\n");
printf(" -m SIZE, --memory SIZE\n"
" Memory limit. The default value is 8GiB. When specified\n"
" without a unit, MiB is assumed.\n");
@ -2375,6 +2401,11 @@ int main(int argc, char* argv[]) {
trace = true;
traceDir = args->OptionArg();
break;
case OPT_TRACE_FORMAT:
if (!selectTraceFormatter(args->OptionArg())) {
fprintf(stderr, "WARNING: Unrecognized trace format `%s'\n", args->OptionArg());
}
break;
case OPT_TRACE_LOG_GROUP:
traceLogGroup = args->OptionArg();
break;

View File

@ -57,7 +57,7 @@ extern const char* getHGVersion();
std::vector<std::string> validOptions;
enum { OPT_CONNFILE, OPT_DATABASE, OPT_HELP, OPT_TRACE, OPT_TRACE_DIR, OPT_TIMEOUT, OPT_EXEC, OPT_NO_STATUS, OPT_STATUS_FROM_JSON, OPT_VERSION };
enum { OPT_CONNFILE, OPT_DATABASE, OPT_HELP, OPT_TRACE, OPT_TRACE_DIR, OPT_TIMEOUT, OPT_EXEC, OPT_NO_STATUS, OPT_STATUS_FROM_JSON, OPT_VERSION, OPT_TRACE_FORMAT };
CSimpleOpt::SOption g_rgOptions[] = {
{ OPT_CONNFILE, "-C", SO_REQ_SEP },
@ -74,6 +74,7 @@ CSimpleOpt::SOption g_rgOptions[] = {
{ OPT_STATUS_FROM_JSON, "--status-from-json", SO_REQ_SEP },
{ OPT_VERSION, "--version", SO_NONE },
{ OPT_VERSION, "-v", SO_NONE },
{ OPT_TRACE_FORMAT, "--trace_format", SO_REQ_SEP },
#ifndef TLS_DISABLED
TLS_OPTION_FLAGS
@ -401,6 +402,9 @@ static void printProgramUsage(const char* name) {
" --log-dir PATH Specifes the output directory for trace files. If\n"
" unspecified, defaults to the current directory. Has\n"
" no effect unless --log is specified.\n"
" --trace_format FORMAT\n"
" Select the format of the log files. xml (the default) and json\n"
" are supported. Has no effect unless --log is specified.\n"
" --exec CMDS Immediately executes the semicolon separated CLI commands\n"
" and then exits.\n"
" --no-status Disables the initial status check done when starting\n"
@ -2331,6 +2335,11 @@ struct CLIOptions {
return 0;
case OPT_STATUS_FROM_JSON:
return printStatusFromJSON(args.OptionArg());
case OPT_TRACE_FORMAT:
if (!selectTraceFormatter(args.OptionArg())) {
fprintf(stderr, "WARNING: Unrecognized trace format `%s'\n", args.OptionArg());
}
break;
case OPT_VERSION:
printVersion();
return FDB_EXIT_SUCCESS;

View File

@ -77,7 +77,7 @@
enum {
OPT_CONNFILE, OPT_SEEDCONNFILE, OPT_SEEDCONNSTRING, OPT_ROLE, OPT_LISTEN, OPT_PUBLICADDR, OPT_DATAFOLDER, OPT_LOGFOLDER, OPT_PARENTPID, OPT_NEWCONSOLE, OPT_NOBOX, OPT_TESTFILE, OPT_RESTARTING, OPT_RANDOMSEED, OPT_KEY, OPT_MEMLIMIT, OPT_STORAGEMEMLIMIT, OPT_MACHINEID, OPT_DCID, OPT_MACHINE_CLASS, OPT_BUGGIFY, OPT_VERSION, OPT_CRASHONERROR, OPT_HELP, OPT_NETWORKIMPL, OPT_NOBUFSTDOUT, OPT_BUFSTDOUTERR, OPT_TRACECLOCK, OPT_NUMTESTERS, OPT_DEVHELP, OPT_ROLLSIZE, OPT_MAXLOGS, OPT_MAXLOGSSIZE, OPT_KNOB, OPT_TESTSERVERS, OPT_TEST_ON_SERVERS, OPT_METRICSCONNFILE, OPT_METRICSPREFIX,
OPT_LOGGROUP, OPT_LOCALITY, OPT_IO_TRUST_SECONDS, OPT_IO_TRUST_WARN_ONLY, OPT_FILESYSTEM, OPT_KVFILE };
OPT_LOGGROUP, OPT_LOCALITY, OPT_IO_TRUST_SECONDS, OPT_IO_TRUST_WARN_ONLY, OPT_FILESYSTEM, OPT_KVFILE, OPT_TRACE_FORMAT };
CSimpleOpt::SOption g_rgOptions[] = {
{ OPT_CONNFILE, "-C", SO_REQ_SEP },
@ -151,6 +151,7 @@ CSimpleOpt::SOption g_rgOptions[] = {
{ OPT_METRICSPREFIX, "--metrics_prefix", SO_REQ_SEP },
{ OPT_IO_TRUST_SECONDS, "--io_trust_seconds", SO_REQ_SEP },
{ OPT_IO_TRUST_WARN_ONLY, "--io_trust_warn_only", SO_NONE },
{ OPT_TRACE_FORMAT , "--trace_format", SO_REQ_SEP },
#ifndef TLS_DISABLED
TLS_OPTION_FLAGS
@ -551,6 +552,8 @@ static void printUsage( const char *name, bool devhelp ) {
" Delete the oldest log file when the total size of all log\n"
" files exceeds SIZE bytes. If set to 0, old log files will not\n"
" be deleted. The default value is 100MiB.\n");
printf(" --trace_format FORMAT\n"
" Select the format of the log files. xml (the default) and json are supported.\n");
printf(" -i ID, --machine_id ID\n"
" Machine identifier key (up to 16 hex characters). Defaults\n"
" to a random value shared by all fdbserver processes on this\n"
@ -1129,6 +1132,11 @@ int main(int argc, char* argv[]) {
case OPT_IO_TRUST_WARN_ONLY:
fileIoWarnOnly = true;
break;
case OPT_TRACE_FORMAT:
if (!selectTraceFormatter(args.OptionArg())) {
fprintf(stderr, "WARNING: Unrecognized trace format `%s'\n", args.OptionArg());
}
break;
#ifndef TLS_DISABLED
case TLSOptions::OPT_TLS_PLUGIN:
args.OptionArg();

View File

@ -0,0 +1,85 @@
/*
* JsonTraceLogFormatter.cpp
*
* This source file is part of the FoundationDB open source project
*
* Copyright 2018 Apple Inc. and the FoundationDB project authors
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
#include "flow/flow.h"
#include "flow/JsonTraceLogFormatter.h"
#include <sstream>
void JsonTraceLogFormatter::addref() {
ReferenceCounted<JsonTraceLogFormatter>::addref();
}
void JsonTraceLogFormatter::delref() {
ReferenceCounted<JsonTraceLogFormatter>::delref();
}
const char* JsonTraceLogFormatter::getExtension() {
return "json";
}
const char* JsonTraceLogFormatter::getHeader() {
return "";
}
const char* JsonTraceLogFormatter::getFooter() {
return "";
}
namespace {
void escapeString(std::stringstream& ss, const std::string& source) {
for (auto c : source) {
if (c == '"') {
ss << "\\\"";
} else if (c == '\\') {
ss << "\\\\";
} else if (c == '\n') {
ss << "\\n";
} else if (c == '\r') {
ss << "\\r";
} else if (isprint(c)) {
ss << c;
} else {
constexpr char hex[] = "0123456789abcdef";
int x = int{ static_cast<uint8_t>(c) };
ss << "\\x" << hex[x / 16] << hex[x % 16];
}
}
}
} // namespace
std::string JsonTraceLogFormatter::formatEvent(const TraceEventFields& fields) {
std::stringstream ss;
ss << "{ ";
for (auto iter = fields.begin(); iter != fields.end(); ++iter) {
if (iter != fields.begin()) {
ss << ", ";
}
ss << "\"";
escapeString(ss, iter->first);
ss << "\": \"";
escapeString(ss, iter->second);
ss << "\"";
}
ss << " }\r\n";
return ss.str();
}

View File

@ -0,0 +1,32 @@
/*
* JsonTraceLogFormatter.h
*
* This source file is part of the FoundationDB open source project
*
* Copyright 2018 Apple Inc. and the FoundationDB project authors
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
#include "flow/FastRef.h"
#include "flow/Trace.h"
struct JsonTraceLogFormatter : public ITraceLogFormatter, ReferenceCounted<JsonTraceLogFormatter> {
const char* getExtension() override;
const char* getHeader() override; // Called when starting a new file
const char* getFooter() override; // Called when ending a file
std::string formatEvent(const TraceEventFields&) override; // Called for each event
void addref() override;
void delref() override;
};

View File

@ -22,10 +22,12 @@
#include "flow/Trace.h"
#include "flow/FileTraceLogWriter.h"
#include "flow/XmlTraceLogFormatter.h"
#include "flow/JsonTraceLogFormatter.h"
#include "flow/flow.h"
#include "flow/DeterministicRandom.h"
#include <stdlib.h>
#include <stdarg.h>
#include <cctype>
#include <time.h>
#include "flow/IThreadPool.h"
@ -41,6 +43,18 @@
#undef min
#endif
namespace {
Reference<ITraceLogFormatter> createLogFormatter(const std::string& f) {
if (f == "json") {
return Reference<ITraceLogFormatter>(new JsonTraceLogFormatter());
} else if (f == "xml") {
return Reference<ITraceLogFormatter>(new XmlTraceLogFormatter());
} else {
UNREACHABLE();
}
}
} // namespace
class DummyThreadPool : public IThreadPool, ReferenceCounted<DummyThreadPool> {
public:
~DummyThreadPool() {}
@ -122,10 +136,10 @@ static int TRACE_LOG_MAX_PREOPEN_BUFFER = 1000000;
static int TRACE_EVENT_MAX_SIZE = 4000;
struct TraceLog {
Reference<ITraceLogFormatter> formatter;
private:
Reference<ITraceLogWriter> logWriter;
Reference<ITraceLogFormatter> formatter;
std::vector<TraceEventFields> eventBuffer;
int loggedLength;
int bufferLength;
@ -562,6 +576,17 @@ TraceEventFields LatestEventCache::getLatestError() {
static TraceLog g_traceLog;
bool selectTraceFormatter(std::string format) {
ASSERT(!g_traceLog.isOpen());
std::transform(format.begin(), format.end(), format.begin(), ::tolower);
if (format == "xml" || format == "json") {
g_traceLog.formatter = createLogFormatter(format);
return true;
} else {
return false;
}
}
ThreadFuture<Void> flushTraceFile() {
if (!g_traceLog.isOpen())
return Void();

View File

@ -262,6 +262,10 @@ void initTraceEventMetrics();
void closeTraceFile();
bool traceFileIsOpen();
// Changes the format of trace files. Returns false if the format is unrecognized. No longer safe to call after a call
// to openTraceFile.
bool selectTraceFormatter(std::string format);
void addTraceRole(std::string role);
void removeTraceRole(std::string role);

View File

@ -20,8 +20,10 @@
<ClCompile Include="FaultInjection.cpp" />
<ClCompile Include="FileTraceLogWriter.cpp" />
<ClCompile Include="XmlTraceLogFormatter.cpp" />
<ClCompile Include="JsonTraceLogFormatter.cpp" />
<ClInclude Include="FileTraceLogWriter.h" />
<ClInclude Include="XmlTraceLogFormatter.h" />
<ClInclude Include="JsonTraceLogFormatter.h" />
<ClInclude Include="MetricSample.h" />
<ClInclude Include="Profiler.h" />
<ActorCompiler Include="Profiler.actor.cpp" />