wbtiger
/
foundationdb
mirror of https://github.com/apple/foundationdb.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

Make trace event field lengths (and total event sizes) default knobified and configurable. Add a transaction option to control the field length of transaction debug logging. Make the program start command line field less likely to be truncated.

This commit is contained in:
A.J. Beamon 2019-07-12 16:12:35 -07:00
parent b452292a14
commit d5051b08dd
25 changed files with 268 additions and 65 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

7
bindings/flow/tester/Tester.actor.cpp
View File

@ -1551,19 +1551,21 @@ struct UnitTestsFunc : InstructionFunc {
const uint64_t noRetryLimit = -1;
const uint64_t maxRetryDelay = 100;
const uint64_t sizeLimit = 100000;
const uint64_t maxFieldLength = 1000;
data->db->setDatabaseOption(FDBDatabaseOption::FDB_DB_OPTION_LOCATION_CACHE_SIZE, Optional<StringRef>(StringRef((const uint8_t*)&locationCacheSize, 8)));
data->db->setDatabaseOption(FDBDatabaseOption::FDB_DB_OPTION_MAX_WATCHES, Optional<StringRef>(StringRef((const uint8_t*)&maxWatches, 8)));
data->db->setDatabaseOption(FDBDatabaseOption::FDB_DB_OPTION_DATACENTER_ID, Optional<StringRef>(LiteralStringRef("dc_id")));
data->db->setDatabaseOption(FDBDatabaseOption::FDB_DB_OPTION_MACHINE_ID, Optional<StringRef>(LiteralStringRef("machine_id")));
data->db->setDatabaseOption(FDBDatabaseOption::FDB_DB_OPTION_SNAPSHOT_RYW_ENABLE);
data->db->setDatabaseOption(FDBDatabaseOption::FDB_DB_OPTION_SNAPSHOT_RYW_DISABLE);
data->db->setDatabaseOption(FDBDatabaseOption::FDB_DB_OPTION_TRANSACTION_LOGGING_MAX_FIELD_LENGTH, Optional<StringRef>(StringRef((const uint8_t*)&maxFieldLength, 8)));
data->db->setDatabaseOption(FDBDatabaseOption::FDB_DB_OPTION_TRANSACTION_TIMEOUT, Optional<StringRef>(StringRef((const uint8_t*)&timeout, 8)));
data->db->setDatabaseOption(FDBDatabaseOption::FDB_DB_OPTION_TRANSACTION_TIMEOUT, Optional<StringRef>(StringRef((const uint8_t*)&noTimeout, 8)));
data->db->setDatabaseOption(FDBDatabaseOption::FDB_DB_OPTION_TRANSACTION_MAX_RETRY_DELAY, Optional<StringRef>(StringRef((const uint8_t*)&maxRetryDelay, 8)));
data->db->setDatabaseOption(FDBDatabaseOption::FDB_DB_OPTION_TRANSACTION_SIZE_LIMIT, Optional<StringRef>(StringRef((const uint8_t*)&sizeLimit, 8)));
data->db->setDatabaseOption(FDBDatabaseOption::FDB_DB_OPTION_TRANSACTION_RETRY_LIMIT, Optional<StringRef>(StringRef((const uint8_t*)&retryLimit, 8)));
data->db->setDatabaseOption(FDBDatabaseOption::FDB_DB_OPTION_TRANSACTION_RETRY_LIMIT, Optional<StringRef>(StringRef((const uint8_t*)&noRetryLimit, 8)));
data->db->setDatabaseOption(FDBDatabaseOption::FDB_DB_OPTION_SNAPSHOT_RYW_ENABLE);
data->db->setDatabaseOption(FDBDatabaseOption::FDB_DB_OPTION_SNAPSHOT_RYW_DISABLE);
state Reference<Transaction> tr = data->db->createTransaction();
tr->setOption(FDBTransactionOption::FDB_TR_OPTION_PRIORITY_SYSTEM_IMMEDIATE);
@ -1574,6 +1576,7 @@ struct UnitTestsFunc : InstructionFunc {
tr->setOption(FDBTransactionOption::FDB_TR_OPTION_READ_YOUR_WRITES_DISABLE);
tr->setOption(FDBTransactionOption::FDB_TR_OPTION_READ_SYSTEM_KEYS);
tr->setOption(FDBTransactionOption::FDB_TR_OPTION_ACCESS_SYSTEM_KEYS);
tr->setOption(FDBTransactionOption::FDB_TR_OPTION_TRANSACTION_LOGGING_MAX_FIELD_LENGTH, Optional<StringRef>(StringRef((const uint8_t*)&maxFieldLength, 8)));
tr->setOption(FDBTransactionOption::FDB_TR_OPTION_TIMEOUT, Optional<StringRef>(StringRef((const uint8_t*)&timeout, 8)));
tr->setOption(FDBTransactionOption::FDB_TR_OPTION_RETRY_LIMIT, Optional<StringRef>(StringRef((const uint8_t*)&retryLimit, 8)));
tr->setOption(FDBTransactionOption::FDB_TR_OPTION_MAX_RETRY_DELAY, Optional<StringRef>(StringRef((const uint8_t*)&maxRetryDelay, 8)));

6
bindings/go/src/_stacktester/stacktester.go
View File

@ -793,13 +793,14 @@ func (sm *StackMachine) processInst(idx int, inst tuple.Tuple) {
db.Options().SetMaxWatches(10001)
db.Options().SetDatacenterId("dc_id")
db.Options().SetMachineId("machine_id")
db.Options().SetSnapshotRywEnable()
db.Options().SetSnapshotRywDisable()
db.Options().SetTransactionLoggingMaxFieldLength(1000)
db.Options().SetTransactionTimeout(100000)
db.Options().SetTransactionTimeout(0)
db.Options().SetTransactionMaxRetryDelay(100)
db.Options().SetTransactionRetryLimit(10)
db.Options().SetTransactionRetryLimit(-1)
db.Options().SetSnapshotRywEnable()
db.Options().SetSnapshotRywDisable()
if !fdb.IsAPIVersionSelected() {
log.Fatal("API version should be selected")
@ -836,6 +837,7 @@ func (sm *StackMachine) processInst(idx int, inst tuple.Tuple) {
tr.Options().SetReadYourWritesDisable()
tr.Options().SetReadSystemKeys()
tr.Options().SetAccessSystemKeys()
tr.Options().SetTransactionLoggingMaxFieldLength(1000)
tr.Options().SetTimeout(60 * 1000)
tr.Options().SetRetryLimit(50)
tr.Options().SetMaxRetryDelay(100)

34
bindings/go/src/fdb/generated.go
View File

@ -280,6 +280,23 @@ func (o DatabaseOptions) SetDatacenterId(param string) error {
return o.setOpt(22, []byte(param))
}
// Snapshot read operations will see the results of writes done in the same transaction. This is the default behavior.
func (o DatabaseOptions) SetSnapshotRywEnable() error {
return o.setOpt(26, nil)
}
// Snapshot read operations will not see the results of writes done in the same transaction. This was the default behavior prior to API version 300.
func (o DatabaseOptions) SetSnapshotRywDisable() error {
return o.setOpt(27, nil)
}
// Sets the maximum escaped length of key and value fields to be logged to the trace file via the LOG_TRANSACTION option. This sets the ``transaction_logging_max_field_length`` option of each transaction created by this database. See the transaction option description for more information.
//
// Parameter: Maximum length of escaped key and value fields.
func (o DatabaseOptions) SetTransactionLoggingMaxFieldLength(param int64) error {
return o.setOpt(405, int64ToBytes(param))
}
// Set a timeout in milliseconds which, when elapsed, will cause each transaction automatically to be cancelled. This sets the ``timeout`` option of each transaction created by this database. See the transaction option description for more information. Using this option requires that the API version is 610 or higher.
//
// Parameter: value in milliseconds of timeout
@ -308,16 +325,6 @@ func (o DatabaseOptions) SetTransactionSizeLimit(param int64) error {
return o.setOpt(503, int64ToBytes(param))
}
// Snapshot read operations will see the results of writes done in the same transaction. This is the default behavior.
func (o DatabaseOptions) SetSnapshotRywEnable() error {
return o.setOpt(26, nil)
}
// Snapshot read operations will not see the results of writes done in the same transaction. This was the default behavior prior to API version 300.
func (o DatabaseOptions) SetSnapshotRywDisable() error {
return o.setOpt(27, nil)
}
// The transaction, if not self-conflicting, may be committed a second time after commit succeeds, in the event of a fault
func (o TransactionOptions) SetCausalWriteRisky() error {
return o.setOpt(10, nil)
@ -412,6 +419,13 @@ func (o TransactionOptions) SetLogTransaction() error {
return o.setOpt(404, nil)
}
// Sets the maximum escaped length of key and value fields to be logged to the trace file via the LOG_TRANSACTION option, after which the field will be truncated. A negative value disables truncation.
//
// Parameter: Maximum length of escaped key and value fields.
func (o TransactionOptions) SetTransactionLoggingMaxFieldLength(param int64) error {
return o.setOpt(405, int64ToBytes(param))
}
// Set a timeout in milliseconds which, when elapsed, will cause the transaction automatically to be cancelled. Valid parameter values are ``[0, INT_MAX]``. If set to 0, will disable all timeouts. All pending and any future uses of the transaction will throw an exception. The transaction can be used again after it is reset. Prior to API version 610, like all other transaction options, the timeout must be reset after a call to ``onError``. If the API version is 610 or greater, the timeout is not reset after an ``onError`` call. This allows the user to specify a longer timeout on specific transactions than the default timeout specified through the ``transaction_timeout`` database option without the shorter database timeout cancelling transactions that encounter a retryable error. Note that at all API versions, it is safe and legal to set the timeout each time the transaction begins, so most code written assuming the older behavior can be upgraded to the newer behavior without requiring any modification, and the caller is not required to implement special logic in retry loops to only conditionally set this option.
//
// Parameter: value in milliseconds of timeout

6
bindings/java/src/test/com/apple/foundationdb/test/AsyncStackTester.java
View File

@ -481,13 +481,14 @@ public class AsyncStackTester {
db.options().setMaxWatches(10001);
db.options().setDatacenterId("dc_id");
db.options().setMachineId("machine_id");
db.options().setSnapshotRywEnable();
db.options().setSnapshotRywDisable();
db.options().setTransactionLoggingMaxFieldLength(1000);
db.options().setTransactionTimeout(100000);
db.options().setTransactionTimeout(0);
db.options().setTransactionMaxRetryDelay(100);
db.options().setTransactionRetryLimit(10);
db.options().setTransactionRetryLimit(-1);
db.options().setSnapshotRywEnable();
db.options().setSnapshotRywDisable();
tr.options().setPrioritySystemImmediate();
tr.options().setPriorityBatch();
@ -496,6 +497,7 @@ public class AsyncStackTester {
tr.options().setReadYourWritesDisable();
tr.options().setReadSystemKeys();
tr.options().setAccessSystemKeys();
tr.options().setTransactionLoggingMaxFieldLength(1000);
tr.options().setTimeout(60*1000);
tr.options().setRetryLimit(50);
tr.options().setMaxRetryDelay(100);

6
bindings/java/src/test/com/apple/foundationdb/test/StackTester.java
View File

@ -434,13 +434,14 @@ public class StackTester {
db.options().setMaxWatches(10001);
db.options().setDatacenterId("dc_id");
db.options().setMachineId("machine_id");
db.options().setSnapshotRywEnable();
db.options().setSnapshotRywDisable();
db.options().setTransactionLoggingMaxFieldLength(1000);
db.options().setTransactionTimeout(100000);
db.options().setTransactionTimeout(0);
db.options().setTransactionMaxRetryDelay(100);
db.options().setTransactionRetryLimit(10);
db.options().setTransactionRetryLimit(-1);
db.options().setSnapshotRywEnable();
db.options().setSnapshotRywDisable();
tr.options().setPrioritySystemImmediate();
tr.options().setPriorityBatch();
@ -449,6 +450,7 @@ public class StackTester {
tr.options().setReadYourWritesDisable();
tr.options().setReadSystemKeys();
tr.options().setAccessSystemKeys();
tr.options().setTransactionLoggingMaxFieldLength(1000);
tr.options().setTimeout(60*1000);
tr.options().setRetryLimit(50);
tr.options().setMaxRetryDelay(100);

9
bindings/python/tests/tester.py
View File

@ -128,9 +128,13 @@ class Instruction:
def test_db_options(db):
db.options.set_location_cache_size(100001)
db.options.set_max_watches(100001)
db.options.set_datacenter_id("dc_id")
db.options.set_machine_id("machine_id")
db.options.set_snapshot_ryw_enable()
db.options.set_snapshot_ryw_disable()
db.options.set_transaction_logging_max_field_length(1000)
db.options.set_transaction_timeout(100000)
db.options.set_transaction_timeout(0)
db.options.set_transaction_timeout(0)
@ -138,8 +142,6 @@ def test_db_options(db):
db.options.set_transaction_size_limit(100000)
db.options.set_transaction_retry_limit(10)
db.options.set_transaction_retry_limit(-1)
db.options.set_snapshot_ryw_enable()
db.options.set_snapshot_ryw_disable()
@fdb.transactional
@ -151,6 +153,7 @@ def test_options(tr):
tr.options.set_read_your_writes_disable()
tr.options.set_read_system_keys()
tr.options.set_access_system_keys()
tr.options.set_transaction_logging_max_field_length(1000)
tr.options.set_timeout(60 * 1000)
tr.options.set_retry_limit(50)
tr.options.set_max_retry_delay(100)
@ -545,8 +548,6 @@ class Tester:
inst.push(b"WAITED_FOR_EMPTY")
elif inst.op == six.u("UNIT_TESTS"):
try:
db.options.set_location_cache_size(100001)
test_db_options(db)
test_options(db)
test_watches(db)

6
bindings/ruby/tests/tester.rb
View File

@ -456,14 +456,15 @@ class Tester
@db.options.set_max_watches(10001)
@db.options.set_datacenter_id("dc_id")
@db.options.set_machine_id("machine_id")
@db.options.set_snapshot_ryw_enable()
@db.options.set_snapshot_ryw_disable()
@db.options.set_transaction_logging_max_field_length(1000)
@db.options.set_transaction_timeout(100000)
@db.options.set_transaction_timeout(0)
@db.options.set_transaction_max_retry_delay(100)
@db.options.set_transaction_size_limit(100000)
@db.options.set_transaction_retry_limit(10)
@db.options.set_transaction_retry_limit(-1)
@db.options.set_snapshot_ryw_enable()
@db.options.set_snapshot_ryw_disable()
@db.transact do |tr|
tr.options.set_priority_system_immediate
@ -473,6 +474,7 @@ class Tester
tr.options.set_read_your_writes_disable
tr.options.set_read_system_keys
tr.options.set_access_system_keys
tr.options.set_transaction_logging_max_field_length(1000)
tr.options.set_timeout(60*1000)
tr.options.set_retry_limit(50)
tr.options.set_max_retry_delay(100)

2
documentation/sphinx/source/api-c.rst
View File

@ -49,6 +49,8 @@
.. |max-retry-delay-database-option| replace:: FIXME
.. |transaction-size-limit-database-option| replace:: FIXME
.. |timeout-database-option| replace:: FIXME
.. |transaction-logging-max-field-length-database-option| replace:: FIXME
.. |transaction-logging-max-field-length-transaction-option| replace:: FIXME
.. include:: api-common.rst.inc

10
documentation/sphinx/source/api-common.rst.inc
View File

@ -326,6 +326,10 @@
If this option has been set more times with this database than the disable option, snapshot reads will *not* see the effects of prior writes in the same transaction. Disabling this option is equivalent to calling |snapshot-ryw-disable-transaction-option| on each transaction created by this database.
.. |option-db-tr-transaction-logging-max-field-length-blurb| replace::
Sets the maximum escaped length of key and value fields to be logged to the trace file via the LOG_TRANSACTION option. This is equivalent to calling |transaction-logging-max-field-length-transaction-option| on each transaction created by this database.
.. |transaction-options-blurb| replace::
Transaction options alter the behavior of FoundationDB transactions. FoundationDB defaults to extremely safe transaction behavior, and we have worked hard to make the performance excellent with the default setting, so you should not often need to use transaction options.
@ -411,7 +415,7 @@
.. |option-set-timeout-blurb3| replace::
Prior to API version 610, like all other transaction options, a timeout must be reset after a call to |on-error-func|. Note that resetting this option resets only the timeout *duration*, not the starting point from which the time is measured. If the API version is 610 or newer, then the timeout is not reset. This allows the user to specify a timeout for specific transactions that is longer than the timeout specified by |timeout-database-option|. Note that at all API versions, it is safe and legal to call this option after each call to |on-error-func|, so most code written assuming the older behavior can be upgraded without requiring any modification. This also means that there is no need to introduce logic to conditionally set this option within retry loops. One can set the default timeout for all transactions by calling |timeout-database-option|.
Prior to API version 610, like all other transaction options, a timeout must be reset after a call to |on-error-func|. Note that resetting this option resets only the timeout *duration*, not the starting point from which the time is measured. If the API version is 610 or newer, then the timeout is not reset. This allows the user to specify a timeout for specific transactions that is longer than the timeout specified by |timeout-database-option|. Note that at all API versions, it is safe and legal to call this option after each call to |on-error-func|, so most code written assuming the older behavior can be upgraded without requiring any modification. This also means that there is no need to introduce logic to conditionally set this option within retry loops. One can set the default timeout for all transactions by calling |timeout-database-option|.
.. |option-next-write-no-write-conflict-range-blurb| replace::
@ -421,6 +425,10 @@
Care needs to be taken when using this option on a transaction that is shared between multiple threads. When setting this option, write conflict ranges will be disabled on the next write operation, regardless of what thread it is on.
.. |option-set-transaction-logging-max-field-length-blurb| replace::
Sets the maximum escaped length of key and value fields to be logged to the trace file via the LOG_TRANSACTION option, after which the field will be truncated. A negative value disables truncation. One can set the default max field length for all transactions by calling |transaction-logging-max-field-length-database-option|.
.. |future-blurb1| replace::
Many FoundationDB API functions return "future" objects. A brief overview of futures is included in the :doc:`class scheduling tutorial <class-scheduling>`. Most future objects behave just like a normal object, but block when you use them for the first time if the asynchronous function which returned the future has not yet completed its action. A future object is considered ready when either a value is available, or when an error has occurred.

10
documentation/sphinx/source/api-python.rst
View File

@ -25,6 +25,7 @@
.. |timeout-database-option| replace:: :func:`Database.options.set_transaction_timeout`
.. |max-retry-delay-database-option| replace:: :func:`Database.options.set_transaction_max_retry_delay`
.. |transaction-size-limit-database-option| replace:: :func:`Database.options.set_transaction_size_limit`
.. |transaction-logging-max-field-length-database-option| replace:: :func:`Database.options.set_transaction_logging_max_field_length`
.. |snapshot-ryw-enable-database-option| replace:: :func:`Database.options.set_snapshot_ryw_enable`
.. |snapshot-ryw-disable-database-option| replace:: :func:`Database.options.set_snapshot_ryw_disable`
.. |future-type-string| replace:: a :ref:`future <api-python-future>`
@ -35,6 +36,7 @@
.. |size-limit-transaction-option| replace:: :func:`Transaction.options.set_size_limit`
.. |snapshot-ryw-enable-transaction-option| replace:: :func:`Transaction.options.set_snapshot_ryw_enable`
.. |snapshot-ryw-disable-transaction-option| replace:: :func:`Transaction.options.set_snapshot_ryw_disable`
.. |transaction-logging-max-field-length-transaction-option| replace:: :func:`Transaction.options.set_transaction_logging_max_field_length`
.. |lazy-iterator-object| replace:: generator
.. |key-meth| replace:: :meth:`Subspace.key`
.. |directory-subspace| replace:: :ref:`DirectorySubspace <api-python-directory-subspace>`
@ -384,6 +386,10 @@ Database options
|option-db-tr-size-limit-blurb|
.. method:: Database.options.set_transaction_logging_max_field_length(size_limit)
|option-db-tr-transaction-logging-max-field-length-blurb|
.. method:: Database.options.set_snapshot_ryw_enable()
|option-db-snapshot-ryw-enable-blurb|
@ -855,6 +861,10 @@ Transaction options
|option-set-timeout-blurb3|
.. method:: Transaction.options.set_transaction_logging_max_field_length(size_limit)
|option-set-transaction-logging-max-field-length-blurb|
.. _api-python-future:
Future objects

10
documentation/sphinx/source/api-ruby.rst
View File

@ -25,6 +25,7 @@
.. |transaction-size-limit-database-option| replace:: :func:`Database.options.set_transaction_size_limit`
.. |snapshot-ryw-enable-database-option| replace:: :meth:`Database.options.set_snapshot_ryw_enable`
.. |snapshot-ryw-disable-database-option| replace:: :meth:`Database.options.set_snapshot_ryw_disable`
.. |transaction-logging-max-field-length-database-option| replace:: :meth:`Database.options.set_transaction_logging_max_field_length`
.. |future-type-string| replace:: a :class:`Future`
.. |read-your-writes-disable-option| replace:: :meth:`Transaction.options.set_read_your_writes_disable`
.. |retry-limit-transaction-option| replace:: :meth:`Transaction.options.set_retry_limit`
@ -33,6 +34,7 @@
.. |size-limit-transaction-option| replace:: :meth:`Transaction.options.set_size_limit`
.. |snapshot-ryw-enable-transaction-option| replace:: :meth:`Transaction.options.set_snapshot_ryw_enable`
.. |snapshot-ryw-disable-transaction-option| replace:: :meth:`Transaction.options.set_snapshot_ryw_disable`
.. |transaction-logging-max-field-length-transaction-option| replace:: :meth:`Transaction.options.set_transaction_logging_max_field_length`
.. |lazy-iterator-object| replace:: :class:`Enumerator`
.. |key-meth| replace:: :meth:`Subspace.key`
.. |directory-subspace| replace:: :class:`DirectorySubspace`
@ -380,6 +382,10 @@ Database options
|option-db-tr-size-limit-blurb|
.. method:: Database.options.set_transaction_logging_max_field_length(size_limit) -> nil
|option-db-tr-transaction-logging-max-field-length-blurb|
.. method:: Database.options.set_snapshot_ryw_enable() -> nil
|option-db-snapshot-ryw-enable-blurb|
@ -797,6 +803,10 @@ Transaction options
|option-set-timeout-blurb3|
.. method:: Transaction.options.set_size_limit(size_limit) -> nil
|option-set-transaction-logging-max-field-length-blurb|
.. _transact:
The transact method

2
documentation/sphinx/source/data-modeling.rst
View File

@ -51,6 +51,8 @@
.. |max-retry-delay-database-option| replace:: FIXME
.. |transaction-size-limit-database-option| replace:: FIXME
.. |timeout-database-option| replace:: FIXME
.. |transaction-logging-max-field-length-transaction-option| replace:: FIXME
.. |transaction-logging-max-field-length-database-option| replace:: FIXME
.. include:: api-common.rst.inc

2
documentation/sphinx/source/developer-guide.rst
View File

@ -51,6 +51,8 @@
.. |max-retry-delay-database-option| replace:: FIXME
.. |transaction-size-limit-database-option| replace:: FIXME
.. |timeout-database-option| replace:: FIXME
.. |transaction-logging-max-field-length-transaction-option| replace:: FIXME
.. |transaction-logging-max-field-length-database-option| replace:: FIXME
.. include:: api-common.rst.inc

1
documentation/sphinx/source/release-notes.rst
View File

@ -30,6 +30,7 @@ Bindings
* Go: The Go bindings now require Go version 1.11 or later.
* Go: Fix issue with finalizers running too early that could lead to undefined behavior. `(PR #1451) <https://github.com/apple/foundationdb/pull/1451>`_.
* Added transaction option to control the field length of keys and values in debug transaction logging in order to avoid truncation. `(PR #) <https://github.com/apple/foundationdb/pull/>`_.
Other Changes
-------------

3
fdbbackup/backup.actor.cpp
View File

@ -3194,11 +3194,14 @@ int main(int argc, char* argv[]) {
}
TraceEvent("ProgramStart")
.setMaxEventLength(12000)
.detail("SourceVersion", getHGVersion())
.detail("Version", FDB_VT_VERSION )
.detail("PackageName", FDB_VT_PACKAGE_NAME)
.detailf("ActualTime", "%lld", DEBUG_DETERMINISM ? 0 : time(NULL))
.setMaxFieldLength(10000)
.detail("CommandLine", commandLine)
.setMaxFieldLength(0)
.detail("MemoryLimit", memLimit)
.trackLatest("ProgramStart");

2
fdbcli/fdbcli.actor.cpp
View File

@ -2529,12 +2529,14 @@ ACTOR Future<int> cli(CLIOptions opt, LineNoise* plinenoise) {
if (opt.trace) {
TraceEvent("CLIProgramStart")
.setMaxEventLength(12000)
.detail("SourceVersion", getHGVersion())
.detail("Version", FDB_VT_VERSION)
.detail("PackageName", FDB_VT_PACKAGE_NAME)
.detailf("ActualTime", "%lld", DEBUG_DETERMINISM ? 0 : time(NULL))
.detail("ClusterFile", ccf->getFilename().c_str())
.detail("ConnectionString", ccf->getConnectionString().toString())
.setMaxFieldLength(10000)
.detail("CommandLine", opt.commandLine)
.trackLatest("ProgramStart");
}

102
fdbclient/ClientLogEvents.h
View File

@ -44,7 +44,7 @@ namespace FdbClientLogEvents {
EventType type{ EVENTTYPEEND };
double startTs{ 0 };
void logEvent(std::string id) const {}
void logEvent(std::string id, int maxFieldLength) const {}
};
struct EventGetVersion : public Event {
@ -60,8 +60,10 @@ namespace FdbClientLogEvents {
double latency;
void logEvent(std::string id) const {
TraceEvent("TransactionTrace_GetVersion").detail("TransactionID", id).detail("Latency", latency);
void logEvent(std::string id, int maxFieldLength) const override {
TraceEvent("TransactionTrace_GetVersion")
.detail("TransactionID", id)
.detail("Latency", latency);
}
};
@ -80,8 +82,14 @@ namespace FdbClientLogEvents {
int valueSize;
Key key;
void logEvent(std::string id) const {
TraceEvent("TransactionTrace_Get").detail("TransactionID", id).detail("Latency", latency).detail("ValueSizeBytes", valueSize).detail("Key", key);
void logEvent(std::string id, int maxFieldLength) const override {
TraceEvent("TransactionTrace_Get")
.setMaxEventLength(-1)
.detail("TransactionID", id)
.detail("Latency", latency)
.detail("ValueSizeBytes", valueSize)
.setMaxFieldLength(maxFieldLength)
.detail("Key", key);
}
};
@ -101,8 +109,15 @@ namespace FdbClientLogEvents {
Key startKey;
Key endKey;
void logEvent(std::string id) const {
TraceEvent("TransactionTrace_GetRange").detail("TransactionID", id).detail("Latency", latency).detail("RangeSizeBytes", rangeSize).detail("StartKey", startKey).detail("EndKey", endKey);
void logEvent(std::string id, int maxFieldLength) const override {
TraceEvent("TransactionTrace_GetRange")
.setMaxEventLength(-1)
.detail("TransactionID", id)
.detail("Latency", latency)
.detail("RangeSizeBytes", rangeSize)
.setMaxFieldLength(maxFieldLength)
.detail("StartKey", startKey)
.detail("EndKey", endKey);
}
};
@ -122,20 +137,38 @@ namespace FdbClientLogEvents {
int commitBytes;
CommitTransactionRequest req; // Only CommitTransactionRef and Arena object within CommitTransactionRequest is serialized
void logEvent(std::string id) const {
void logEvent(std::string id, int maxFieldLength) const override {
for (auto &read_range : req.transaction.read_conflict_ranges) {
TraceEvent("TransactionTrace_Commit_ReadConflictRange").detail("TransactionID", id).detail("Begin", read_range.begin).detail("End", read_range.end);
TraceEvent("TransactionTrace_Commit_ReadConflictRange")
.setMaxEventLength(-1)
.detail("TransactionID", id)
.setMaxFieldLength(maxFieldLength)
.detail("Begin", read_range.begin)
.detail("End", read_range.end);
}
for (auto &write_range : req.transaction.write_conflict_ranges) {
TraceEvent("TransactionTrace_Commit_WriteConflictRange").detail("TransactionID", id).detail("Begin", write_range.begin).detail("End", write_range.end);
TraceEvent("TransactionTrace_Commit_WriteConflictRange")
.setMaxEventLength(-1)
.detail("TransactionID", id)
.setMaxFieldLength(maxFieldLength)
.detail("Begin", write_range.begin)
.detail("End", write_range.end);
}
for (auto &mutation : req.transaction.mutations) {
TraceEvent("TransactionTrace_Commit_Mutation").detail("TransactionID", id).detail("Mutation", mutation.toString());
TraceEvent("TransactionTrace_Commit_Mutation")
.setMaxEventLength(-1)
.detail("TransactionID", id)
.setMaxFieldLength(maxFieldLength)
.detail("Mutation", mutation.toString());
}
TraceEvent("TransactionTrace_Commit").detail("TransactionID", id).detail("Latency", latency).detail("NumMutations", numMutations).detail("CommitSizeBytes", commitBytes);
TraceEvent("TransactionTrace_Commit")
.detail("TransactionID", id)
.detail("Latency", latency)
.detail("NumMutations", numMutations)
.detail("CommitSizeBytes", commitBytes);
}
};
@ -153,8 +186,13 @@ namespace FdbClientLogEvents {
int errCode;
Key key;
void logEvent(std::string id) const {
TraceEvent("TransactionTrace_GetError").detail("TransactionID", id).detail("ErrCode", errCode).detail("Key", key);
void logEvent(std::string id, int maxFieldLength) const override {
TraceEvent("TransactionTrace_GetError")
.setMaxEventLength(-1)
.detail("TransactionID", id)
.detail("ErrCode", errCode)
.setMaxFieldLength(maxFieldLength)
.detail("Key", key);
}
};
@ -173,8 +211,14 @@ namespace FdbClientLogEvents {
Key startKey;
Key endKey;
void logEvent(std::string id) const {
TraceEvent("TransactionTrace_GetRangeError").detail("TransactionID", id).detail("ErrCode", errCode).detail("StartKey", startKey).detail("EndKey", endKey);
void logEvent(std::string id, int maxFieldLength) const override {
TraceEvent("TransactionTrace_GetRangeError")
.setMaxEventLength(-1)
.detail("TransactionID", id)
.detail("ErrCode", errCode)
.setMaxFieldLength(maxFieldLength)
.detail("StartKey", startKey)
.detail("EndKey", endKey);
}
};
@ -192,20 +236,36 @@ namespace FdbClientLogEvents {
int errCode;
CommitTransactionRequest req; // Only CommitTransactionRef and Arena object within CommitTransactionRequest is serialized
void logEvent(std::string id) const {
void logEvent(std::string id, int maxFieldLength) const override {
for (auto &read_range : req.transaction.read_conflict_ranges) {
TraceEvent("TransactionTrace_CommitError_ReadConflictRange").detail("TransactionID", id).detail("Begin", read_range.begin).detail("End", read_range.end);
TraceEvent("TransactionTrace_CommitError_ReadConflictRange")
.setMaxEventLength(-1)
.detail("TransactionID", id)
.setMaxFieldLength(maxFieldLength)
.detail("Begin", read_range.begin)
.detail("End", read_range.end);
}
for (auto &write_range : req.transaction.write_conflict_ranges) {
TraceEvent("TransactionTrace_CommitError_WriteConflictRange").detail("TransactionID", id).detail("Begin", write_range.begin).detail("End", write_range.end);
TraceEvent("TransactionTrace_CommitError_WriteConflictRange")
.setMaxEventLength(-1)
.detail("TransactionID", id)
.setMaxFieldLength(maxFieldLength)
.detail("Begin", write_range.begin)
.detail("End", write_range.end);
}
for (auto &mutation : req.transaction.mutations) {
TraceEvent("TransactionTrace_CommitError_Mutation").detail("TransactionID", id).detail("Mutation", mutation.toString());
TraceEvent("TransactionTrace_CommitError_Mutation")
.setMaxEventLength(-1)
.detail("TransactionID", id)
.setMaxFieldLength(maxFieldLength)
.detail("Mutation", mutation.toString());
}
TraceEvent("TransactionTrace_CommitError").detail("TransactionID", id).detail("ErrCode", errCode);
TraceEvent("TransactionTrace_CommitError")
.detail("TransactionID", id)
.detail("ErrCode", errCode);
}
};
}

15
fdbclient/NativeAPI.actor.cpp
View File

@ -2994,6 +2994,7 @@ void Transaction::setOption( FDBTransactionOptions::Option option, Optional<Stri
}
else {
trLogInfo = Reference<TransactionLogInfo>(new TransactionLogInfo(value.get().printable(), TransactionLogInfo::DONT_LOG));
trLogInfo->maxFieldLength = options.maxTransactionLoggingFieldLength;
}
break;
@ -3008,6 +3009,20 @@ void Transaction::setOption( FDBTransactionOptions::Option option, Optional<Stri
}
break;
case FDBTransactionOptions::TRANSACTION_LOGGING_MAX_FIELD_LENGTH:
validateOptionValue(value, true);
{
int maxFieldLength = extractIntOption(value, -1, std::numeric_limits<int32_t>::max());
if(maxFieldLength == 0) {
throw invalid_option_value();
}
options.maxTransactionLoggingFieldLength = maxFieldLength;
}
if(trLogInfo) {
trLogInfo->maxFieldLength = options.maxTransactionLoggingFieldLength;
}
break;
case FDBTransactionOptions::MAX_RETRY_DELAY:
validateOptionValue(value, true);
options.maxBackoff = extractIntOption(value, 0, std::numeric_limits<int32_t>::max()) / 1000.0;

11
fdbclient/NativeAPI.actor.h
View File

@ -149,6 +149,7 @@ struct TransactionOptions {
double maxBackoff;
uint32_t getReadVersionFlags;
uint32_t sizeLimit;
int maxTransactionLoggingFieldLength;
bool checkWritesEnabled : 1;
bool causalWriteRisky : 1;
bool commitOnFirstProxy : 1;
@ -174,17 +175,18 @@ struct TransactionInfo {
struct TransactionLogInfo : public ReferenceCounted<TransactionLogInfo>, NonCopyable {
enum LoggingLocation { DONT_LOG = 0, TRACE_LOG = 1, DATABASE = 2 };
TransactionLogInfo() : logLocation(DONT_LOG) {}
TransactionLogInfo(LoggingLocation location) : logLocation(location) {}
TransactionLogInfo(std::string id, LoggingLocation location) : logLocation(location), identifier(id) {}
TransactionLogInfo() : logLocation(DONT_LOG), maxFieldLength(0) {}
TransactionLogInfo(LoggingLocation location) : logLocation(location), maxFieldLength(0) {}
TransactionLogInfo(std::string id, LoggingLocation location) : logLocation(location), identifier(id), maxFieldLength(0) {}
void setIdentifier(std::string id) { identifier = id; }
void logTo(LoggingLocation loc) { logLocation = logLocation | loc; }
template <typename T>
void addLog(const T& event) {
if(logLocation & TRACE_LOG) {
ASSERT(!identifier.empty())
event.logEvent(identifier);
event.logEvent(identifier, maxFieldLength);
}
if (flushed) {
@ -202,6 +204,7 @@ struct TransactionLogInfo : public ReferenceCounted<TransactionLogInfo>, NonCopy
bool logsAdded{ false };
bool flushed{ false };
int logLocation;
int maxFieldLength;
std::string identifier;
};

17
fdbclient/vexillographer/fdb.options
View File

@ -146,6 +146,15 @@ description is not currently required but encouraged.
<Option name="datacenter_id" code="22"
paramType="String" paramDescription="Hexadecimal ID"
description="Specify the datacenter ID that was passed to fdbserver processes running in the same datacenter as this client, for better location-aware load balancing." />
<!-- The snapshot RYW options act like defaults for the equivalent transaction options, but database defaults cannot have cumulative effects from multiple calls.
Thus, we don't use the defaultFor annotation on these options. -->
<Option name="snapshot_ryw_enable" code="26"
description="Snapshot read operations will see the results of writes done in the same transaction. This is the default behavior." />
<Option name="snapshot_ryw_disable" code="27"
description="Snapshot read operations will not see the results of writes done in the same transaction. This was the default behavior prior to API version 300." />
<Option name="transaction_logging_max_field_length" code="405" paramType="Int" paramDescription="Maximum length of escaped key and value fields."
description="Sets the maximum escaped length of key and value fields to be logged to the trace file via the LOG_TRANSACTION option. This sets the ``transaction_logging_max_field_length`` option of each transaction created by this database. See the transaction option description for more information."
defaultFor="405"/>
<Option name="transaction_timeout" code="500"
paramType="Int" paramDescription="value in milliseconds of timeout"
description="Set a timeout in milliseconds which, when elapsed, will cause each transaction automatically to be cancelled. This sets the ``timeout`` option of each transaction created by this database. See the transaction option description for more information. Using this option requires that the API version is 610 or higher."
@ -162,12 +171,6 @@ description is not currently required but encouraged.
paramType="Int" paramDescription="value in bytes"
description="Set the maximum transaction size in bytes. This sets the ``size_limit`` option on each transaction created by this database. See the transaction option description for more information."
defaultFor="503"/>
<!-- The snapshot RYW options act like defaults for the equivalent transaction options, but database defaults cannot have cumulative effects from multiple calls.
Thus, we don't use the defaultFor annotation on these options. -->
<Option name="snapshot_ryw_enable" code="26"
description="Snapshot read operations will see the results of writes done in the same transaction. This is the default behavior." />
<Option name="snapshot_ryw_disable" code="27"
description="Snapshot read operations will not see the results of writes done in the same transaction. This was the default behavior prior to API version 300." />
</Scope>
<Scope name="TransactionOption">
@ -210,6 +213,8 @@ description is not currently required but encouraged.
description="Sets a client provided identifier for the transaction that will be used in scenarios like tracing or profiling. Client trace logging or transaction profiling must be separately enabled." />
<Option name="log_transaction" code="404"
description="Enables tracing for this transaction and logs results to the client trace logs. The DEBUG_TRANSACTION_IDENTIFIER option must be set before using this option, and client trace logging must be enabled and to get log output." />
<Option name="transaction_logging_max_field_length" code="405" paramType="Int" paramDescription="Maximum length of escaped key and value fields."
description="Sets the maximum escaped length of key and value fields to be logged to the trace file via the LOG_TRANSACTION option, after which the field will be truncated. A negative value disables truncation." />
<Option name="timeout" code="500"
paramType="Int" paramDescription="value in milliseconds of timeout"
description="Set a timeout in milliseconds which, when elapsed, will cause the transaction automatically to be cancelled. Valid parameter values are ``[0, INT_MAX]``. If set to 0, will disable all timeouts. All pending and any future uses of the transaction will throw an exception. The transaction can be used again after it is reset. Prior to API version 610, like all other transaction options, the timeout must be reset after a call to ``onError``. If the API version is 610 or greater, the timeout is not reset after an ``onError`` call. This allows the user to specify a longer timeout on specific transactions than the default timeout specified through the ``transaction_timeout`` database option without the shorter database timeout cancelling transactions that encounter a retryable error. Note that at all API versions, it is safe and legal to set the timeout each time the transaction begins, so most code written assuming the older behavior can be upgraded to the newer behavior without requiring any modification, and the caller is not required to implement special logic in retry loops to only conditionally set this option."

3
fdbserver/fdbserver.actor.cpp
View File

@ -1596,6 +1596,7 @@ int main(int argc, char* argv[]) {
}
TraceEvent("ProgramStart")
.setMaxEventLength(12000)
.detail("RandomSeed", randomSeed)
.detail("SourceVersion", getHGVersion())
.detail("Version", FDB_VT_VERSION )
@ -1606,7 +1607,9 @@ int main(int argc, char* argv[]) {
.detail("ClusterFile", connectionFile ? connectionFile->getFilename().c_str() : "")
.detail("ConnectionString", connectionFile ? connectionFile->getConnectionString().toString() : "")
.detailf("ActualTime", "%lld", DEBUG_DETERMINISM ? 0 : time(NULL))
.setMaxFieldLength(10000)
.detail("CommandLine", commandLine)
.setMaxFieldLength(0)
.detail("BuggifyEnabled", buggifyEnabled)
.detail("MemoryLimit", memLimit)
.trackLatest("ProgramStart");

2
flow/Knobs.cpp
View File

@ -137,6 +137,8 @@ FlowKnobs::FlowKnobs(bool randomize, bool isSimulated) {
init( TRACE_EVENT_METRIC_UNITS_PER_SAMPLE, 500 );
init( TRACE_EVENT_THROTTLER_SAMPLE_EXPIRY, 1800.0 ); // 30 mins
init( TRACE_EVENT_THROTTLER_MSG_LIMIT, 20000 );
init( MAX_TRACE_FIELD_LENGTH, 495 ); // If the value of this is changed, the corresponding default in Trace.cpp should be changed as well
init( MAX_TRACE_EVENT_LENGTH, 4000 ); // If the value of this is changed, the corresponding default in Trace.cpp should be changed as well
//TDMetrics
init( MAX_METRICS, 600 );

2
flow/Knobs.h
View File

@ -157,6 +157,8 @@ public:
int TRACE_EVENT_METRIC_UNITS_PER_SAMPLE;
int TRACE_EVENT_THROTTLER_SAMPLE_EXPIRY;
int TRACE_EVENT_THROTTLER_MSG_LIMIT;
int MAX_TRACE_FIELD_LENGTH;
int MAX_TRACE_EVENT_LENGTH;
//TDMetrics
int64_t MAX_METRIC_SIZE;

51
flow/Trace.cpp
View File

@ -122,7 +122,6 @@ static TransientThresholdMetricSample<Standalone<StringRef>> *traceEventThrottle
static const char *TRACE_EVENT_THROTTLE_STARTING_TYPE = "TraceEventThrottle_";
static const char *TRACE_EVENT_INVALID_SUPPRESSION = "InvalidSuppression_";
static int TRACE_LOG_MAX_PREOPEN_BUFFER = 1000000;
static int TRACE_EVENT_MAX_SIZE = 4000;
struct TraceLog {
Reference<ITraceLogFormatter> formatter;
@ -656,18 +655,26 @@ void removeTraceRole(std::string role) {
TraceEvent::TraceEvent( const char* type, UID id ) : id(id), type(type), severity(SevInfo), initialized(false), enabled(true) {
g_trace_depth++;
setMaxFieldLength(0);
setMaxEventLength(0);
}
TraceEvent::TraceEvent( Severity severity, const char* type, UID id )
: id(id), type(type), severity(severity), initialized(false),
enabled(g_network == nullptr || FLOW_KNOBS->MIN_TRACE_SEVERITY <= severity) {
g_trace_depth++;
setMaxFieldLength(0);
setMaxEventLength(0);
}
TraceEvent::TraceEvent( TraceInterval& interval, UID id )
: id(id), type(interval.type)
, severity(interval.severity)
, initialized(false)
, enabled(g_network == nullptr || FLOW_KNOBS->MIN_TRACE_SEVERITY <= interval.severity) {
: id(id), type(interval.type),
severity(interval.severity),
initialized(false),
enabled(g_network == nullptr || FLOW_KNOBS->MIN_TRACE_SEVERITY <= interval.severity) {
g_trace_depth++;
setMaxFieldLength(0);
setMaxEventLength(0);
init(interval);
}
TraceEvent::TraceEvent( Severity severity, TraceInterval& interval, UID id )
@ -675,7 +682,11 @@ TraceEvent::TraceEvent( Severity severity, TraceInterval& interval, UID id )
severity(severity),
initialized(false),
enabled(g_network == nullptr || FLOW_KNOBS->MIN_TRACE_SEVERITY <= severity) {
g_trace_depth++;
setMaxFieldLength(0);
setMaxEventLength(0);
init(interval);
}
@ -778,8 +789,8 @@ TraceEvent& TraceEvent::errorImpl(class Error const& error, bool includeCancelle
TraceEvent& TraceEvent::detailImpl( std::string&& key, std::string&& value, bool writeEventMetricField) {
init();
if (enabled) {
if( value.size() > 495 ) {
value = value.substr(0, 495) + "...";
if( maxFieldLength >= 0 && value.size() > maxFieldLength ) {
value = value.substr(0, maxFieldLength) + "...";
}
if(writeEventMetricField) {
@ -788,8 +799,8 @@ TraceEvent& TraceEvent::detailImpl( std::string&& key, std::string&& value, bool
fields.addField(std::move(key), std::move(value));
if(fields.sizeBytes() > TRACE_EVENT_MAX_SIZE) {
TraceEvent(g_network && g_network->isSimulated() ? SevError : SevWarnAlways, "TraceEventOverflow").detail("TraceFirstBytes", fields.toString().substr(300));
if(maxEventLength >= 0 && fields.sizeBytes() > maxEventLength) {
TraceEvent(g_network && g_network->isSimulated() ? SevError : SevWarnAlways, "TraceEventOverflow").setMaxEventLength(1000).detail("TraceFirstBytes", fields.toString().substr(300));
enabled = false;
}
}
@ -884,6 +895,28 @@ TraceEvent& TraceEvent::suppressFor( double duration, bool logSuppressedEventCou
return *this;
}
TraceEvent& TraceEvent::setMaxFieldLength(int maxFieldLength) {
if(maxFieldLength == 0) {
this->maxFieldLength = FLOW_KNOBS ? FLOW_KNOBS->MAX_TRACE_FIELD_LENGTH : 495;
}
else {
this->maxFieldLength = maxFieldLength;
}
return *this;
}
TraceEvent& TraceEvent::setMaxEventLength(int maxEventLength) {
if(maxEventLength == 0) {
this->maxEventLength = FLOW_KNOBS ? FLOW_KNOBS->MAX_TRACE_EVENT_LENGTH : 4000;
}
else {
this->maxEventLength = maxEventLength;
}
return *this;
}
TraceEvent& TraceEvent::GetLastError() {
#ifdef _WIN32
return detailf("WinErrorCode", "%x", ::GetLastError());

14
flow/Trace.h
View File

@ -446,6 +446,15 @@ public:
TraceEvent& trackLatest( const char* trackingKey );
TraceEvent& sample( double sampleRate, bool logSampleRate=true );
// Sets the maximum length a field can be before it gets truncated. A value of 0 uses the default, a negative value
// disables truncation. This should be called before the field whose length you want to change, and it can be
// changed multiple times in a single event.
TraceEvent& setMaxFieldLength(int maxFieldLength);
// Sets the maximum event length before the event gets suppressed and a warning is logged. A value of 0 uses the default,
// A negative value disables length suppression. This should be called before adding details.
TraceEvent& setMaxEventLength(int maxEventLength);
//Cannot call other functions which could disable the trace event afterwords
TraceEvent& suppressFor( double duration, bool logSuppressedEventCount=true );
@ -468,6 +477,11 @@ private:
UID id;
Error err;
int maxFieldLength;
int maxEventLength;
void setSizeLimits();
static unsigned long eventCounts[5];
static thread_local bool networkThread;