From 1cdfbf9d2e497a47a7de2b1fcf9532c238e7320b Mon Sep 17 00:00:00 2001 From: Henrik Edin Date: Thu, 20 Feb 2020 13:43:32 -0500 Subject: SERVER-46235 Fix and re-enable jstests in replica_sets, sharding and core_txns suites. --- buildscripts/resmokeconfig/suites/core_txns.yml | 3 -- .../suites/core_txns_large_txns_format.yml | 3 -- .../resmokeconfig/suites/cwrwc_passthrough.yml | 2 -- buildscripts/resmokeconfig/suites/replica_sets.yml | 4 --- .../resmokeconfig/suites/replica_sets_auth.yml | 3 -- .../resmokeconfig/suites/replica_sets_ese.yml | 4 --- .../resmokeconfig/suites/replica_sets_ese_gcm.yml | 4 --- .../replica_sets_initsync_jscore_passthrough.yml | 2 -- ...ica_sets_initsync_static_jscore_passthrough.yml | 2 -- .../suites/replica_sets_jscore_passthrough.yml | 2 -- ...ca_sets_kill_secondaries_jscore_passthrough.yml | 2 -- .../suites/replica_sets_large_txns_format.yml | 4 --- ...a_sets_large_txns_format_jscore_passthrough.yml | 2 -- .../suites/replica_sets_multiversion.yml | 4 --- buildscripts/resmokeconfig/suites/sharding.yml | 3 +- .../resmokeconfig/suites/sharding_auth.yml | 3 +- .../resmokeconfig/suites/sharding_auth_audit.yml | 3 +- .../suites/sharding_continuous_config_stepdown.yml | 4 +-- buildscripts/resmokeconfig/suites/sharding_ese.yml | 3 +- .../resmokeconfig/suites/sharding_ese_gcm.yml | 3 +- ...harding_last_stable_mongos_and_mixed_shards.yml | 3 +- .../resmokeconfig/suites/sharding_misc.yml | 3 +- .../resmokeconfig/suites/sharding_multiversion.yml | 3 +- .../suites/sharding_rs_matching_disabled.yml | 3 +- .../sharding_rs_matching_match_busiest_node.yml | 3 +- ...mped_reads_wait_for_prepare_oplog_visibility.js | 6 +++- jstests/replsets/initial_sync_drop_collection.js | 18 +++++++---- jstests/replsets/initial_sync_rename_collection.js | 16 ++++++---- jstests/sharding/comment_field.js | 2 +- src/mongo/db/repl/base_cloner.cpp | 35 +++++++++++----------- 30 files changed, 58 insertions(+), 94 deletions(-) diff --git a/buildscripts/resmokeconfig/suites/core_txns.yml b/buildscripts/resmokeconfig/suites/core_txns.yml index 3fb96dd4d66..6a303f1c982 100644 --- a/buildscripts/resmokeconfig/suites/core_txns.yml +++ b/buildscripts/resmokeconfig/suites/core_txns.yml @@ -12,9 +12,6 @@ selector: exclude_with_any_tags: # Transactions are not allowed to operate on capped collections. - requires_capped - exclude_files: - # Disable incompatible with json logging per SERVER-46235 - - jstests/core/txns/timestamped_reads_wait_for_prepare_oplog_visibility.js executor: archive: diff --git a/buildscripts/resmokeconfig/suites/core_txns_large_txns_format.yml b/buildscripts/resmokeconfig/suites/core_txns_large_txns_format.yml index c5bfda9bf5e..1164ac5824f 100644 --- a/buildscripts/resmokeconfig/suites/core_txns_large_txns_format.yml +++ b/buildscripts/resmokeconfig/suites/core_txns_large_txns_format.yml @@ -13,9 +13,6 @@ selector: exclude_with_any_tags: # Transactions are not allowed to operate on capped collections. - requires_capped - exclude_files: - # Disable incompatible with json logging per SERVER-46235 - - jstests/core/txns/timestamped_reads_wait_for_prepare_oplog_visibility.js executor: archive: diff --git a/buildscripts/resmokeconfig/suites/cwrwc_passthrough.yml b/buildscripts/resmokeconfig/suites/cwrwc_passthrough.yml index 64c725181d9..ca09948bf2d 100644 --- a/buildscripts/resmokeconfig/suites/cwrwc_passthrough.yml +++ b/buildscripts/resmokeconfig/suites/cwrwc_passthrough.yml @@ -13,8 +13,6 @@ selector: - jstests/core/opcounters_write_cmd.js - jstests/core/read_after_optime.js - jstests/core/capped_update.js - # Disable incompatible with json logging per SERVER-46235 - - jstests/core/txns/timestamped_reads_wait_for_prepare_oplog_visibility.js executor: archive: diff --git a/buildscripts/resmokeconfig/suites/replica_sets.yml b/buildscripts/resmokeconfig/suites/replica_sets.yml index 544d7c5402d..f7515dab9ab 100644 --- a/buildscripts/resmokeconfig/suites/replica_sets.yml +++ b/buildscripts/resmokeconfig/suites/replica_sets.yml @@ -3,10 +3,6 @@ test_kind: js_test selector: roots: - jstests/replsets/*.js - exclude_files: - # Disable incompatible with json logging per SERVER-46235 - - jstests/replsets/initial_sync_drop_collection.js - - jstests/replsets/initial_sync_rename_collection.js executor: config: diff --git a/buildscripts/resmokeconfig/suites/replica_sets_auth.yml b/buildscripts/resmokeconfig/suites/replica_sets_auth.yml index 3de148b9b99..904256d3302 100644 --- a/buildscripts/resmokeconfig/suites/replica_sets_auth.yml +++ b/buildscripts/resmokeconfig/suites/replica_sets_auth.yml @@ -15,9 +15,6 @@ selector: - jstests/replsets/interrupted_batch_insert.js - jstests/replsets/transactions_reaped_with_tickets_exhausted.js - jstests/replsets/transactions_committed_with_tickets_exhausted.js - # Disable incompatible with json logging per SERVER-46235 - - jstests/replsets/initial_sync_drop_collection.js - - jstests/replsets/initial_sync_rename_collection.js executor: config: diff --git a/buildscripts/resmokeconfig/suites/replica_sets_ese.yml b/buildscripts/resmokeconfig/suites/replica_sets_ese.yml index 3bbc68754c6..3e202ae3c1b 100644 --- a/buildscripts/resmokeconfig/suites/replica_sets_ese.yml +++ b/buildscripts/resmokeconfig/suites/replica_sets_ese.yml @@ -7,10 +7,6 @@ test_kind: js_test selector: roots: - jstests/replsets/*.js - exclude_files: - # Disable incompatible with json logging per SERVER-46235 - - jstests/replsets/initial_sync_drop_collection.js - - jstests/replsets/initial_sync_rename_collection.js executor: config: diff --git a/buildscripts/resmokeconfig/suites/replica_sets_ese_gcm.yml b/buildscripts/resmokeconfig/suites/replica_sets_ese_gcm.yml index ef90f4fc451..b44d14eb841 100644 --- a/buildscripts/resmokeconfig/suites/replica_sets_ese_gcm.yml +++ b/buildscripts/resmokeconfig/suites/replica_sets_ese_gcm.yml @@ -7,10 +7,6 @@ test_kind: js_test selector: roots: - jstests/replsets/*.js - exclude_files: - # Disable incompatible with json logging per SERVER-46235 - - jstests/replsets/initial_sync_drop_collection.js - - jstests/replsets/initial_sync_rename_collection.js executor: config: diff --git a/buildscripts/resmokeconfig/suites/replica_sets_initsync_jscore_passthrough.yml b/buildscripts/resmokeconfig/suites/replica_sets_initsync_jscore_passthrough.yml index 96db4e92e61..c68ae4dcb48 100644 --- a/buildscripts/resmokeconfig/suites/replica_sets_initsync_jscore_passthrough.yml +++ b/buildscripts/resmokeconfig/suites/replica_sets_initsync_jscore_passthrough.yml @@ -36,8 +36,6 @@ selector: - jstests/core/txns/transactions_profiling.js # The downstream syncing node affects the top output. - jstests/core/top.js - # Disable incompatible with json logging per SERVER-46235 - - jstests/core/txns/timestamped_reads_wait_for_prepare_oplog_visibility.js run_hook_interval: &run_hook_interval 20 executor: diff --git a/buildscripts/resmokeconfig/suites/replica_sets_initsync_static_jscore_passthrough.yml b/buildscripts/resmokeconfig/suites/replica_sets_initsync_static_jscore_passthrough.yml index 9be58dd30fb..388ef3feb0b 100644 --- a/buildscripts/resmokeconfig/suites/replica_sets_initsync_static_jscore_passthrough.yml +++ b/buildscripts/resmokeconfig/suites/replica_sets_initsync_static_jscore_passthrough.yml @@ -11,8 +11,6 @@ selector: - jstests/core/capped_update.js # Having duplicate namespaces is not supported and will cause initial sync to fail. - jstests/core/views/duplicate_ns.js - # Disable incompatible with json logging per SERVER-46235 - - jstests/core/txns/timestamped_reads_wait_for_prepare_oplog_visibility.js run_hook_interval: &run_hook_interval 20 executor: diff --git a/buildscripts/resmokeconfig/suites/replica_sets_jscore_passthrough.yml b/buildscripts/resmokeconfig/suites/replica_sets_jscore_passthrough.yml index 6086bcb234c..4173cd32c32 100644 --- a/buildscripts/resmokeconfig/suites/replica_sets_jscore_passthrough.yml +++ b/buildscripts/resmokeconfig/suites/replica_sets_jscore_passthrough.yml @@ -19,8 +19,6 @@ selector: # command multiple times, which may observe the change to the "transactionLifetimeLimitSeconds" # server parameter. - jstests/core/set_param1.js - # Disable incompatible with json logging per SERVER-46235 - - jstests/core/txns/timestamped_reads_wait_for_prepare_oplog_visibility.js executor: archive: diff --git a/buildscripts/resmokeconfig/suites/replica_sets_kill_secondaries_jscore_passthrough.yml b/buildscripts/resmokeconfig/suites/replica_sets_kill_secondaries_jscore_passthrough.yml index 752ea2e2b55..feaa5168c88 100644 --- a/buildscripts/resmokeconfig/suites/replica_sets_kill_secondaries_jscore_passthrough.yml +++ b/buildscripts/resmokeconfig/suites/replica_sets_kill_secondaries_jscore_passthrough.yml @@ -24,8 +24,6 @@ selector: - jstests/core/sortb.js - jstests/core/sortg.js - jstests/core/sortj.js - # Disable incompatible with json logging per SERVER-46235 - - jstests/core/txns/timestamped_reads_wait_for_prepare_oplog_visibility.js exclude_with_any_tags: # emptycapped is not supported with rollback using recover-to-timestamp. - requires_emptycapped diff --git a/buildscripts/resmokeconfig/suites/replica_sets_large_txns_format.yml b/buildscripts/resmokeconfig/suites/replica_sets_large_txns_format.yml index e3e0a0e5959..e77680df28d 100644 --- a/buildscripts/resmokeconfig/suites/replica_sets_large_txns_format.yml +++ b/buildscripts/resmokeconfig/suites/replica_sets_large_txns_format.yml @@ -6,10 +6,6 @@ selector: exclude_with_any_tags: # Transactions are not allowed to operate on capped collections. - requires_capped - exclude_files: - # Disable incompatible with json logging per SERVER-46235 - - jstests/replsets/initial_sync_drop_collection.js - - jstests/replsets/initial_sync_rename_collection.js executor: config: diff --git a/buildscripts/resmokeconfig/suites/replica_sets_large_txns_format_jscore_passthrough.yml b/buildscripts/resmokeconfig/suites/replica_sets_large_txns_format_jscore_passthrough.yml index 80538c4cff2..00a177cc35e 100644 --- a/buildscripts/resmokeconfig/suites/replica_sets_large_txns_format_jscore_passthrough.yml +++ b/buildscripts/resmokeconfig/suites/replica_sets_large_txns_format_jscore_passthrough.yml @@ -12,8 +12,6 @@ selector: - jstests/core/txns/abort_expired_transaction.js - jstests/core/txns/abort_transaction_thread_does_not_block_on_locks.js - jstests/core/txns/kill_op_on_txn_expiry.js - # Disable incompatible with json logging per SERVER-46235 - - jstests/core/txns/timestamped_reads_wait_for_prepare_oplog_visibility.js executor: archive: diff --git a/buildscripts/resmokeconfig/suites/replica_sets_multiversion.yml b/buildscripts/resmokeconfig/suites/replica_sets_multiversion.yml index 2c032c0a604..d1858e975f9 100644 --- a/buildscripts/resmokeconfig/suites/replica_sets_multiversion.yml +++ b/buildscripts/resmokeconfig/suites/replica_sets_multiversion.yml @@ -6,10 +6,6 @@ selector: exclude_with_any_tags: - multiversion_incompatible - requires_fcv_44 - exclude_files: - # Disable incompatible with json logging per SERVER-46235 - - jstests/replsets/initial_sync_drop_collection.js - - jstests/replsets/initial_sync_rename_collection.js executor: config: shell_options: diff --git a/buildscripts/resmokeconfig/suites/sharding.yml b/buildscripts/resmokeconfig/suites/sharding.yml index 20faaa12466..a57d4069d61 100644 --- a/buildscripts/resmokeconfig/suites/sharding.yml +++ b/buildscripts/resmokeconfig/suites/sharding.yml @@ -5,9 +5,8 @@ selector: - jstests/sharding/*.js exclude_files: - jstests/sharding/mrShardedOutput.js - # Disable incompatible with json logging per SERVER-46235 + # SERVER-46018 Disable incompatible with ramlog truncation. - jstests/sharding/read_write_concern_defaults_application.js - - jstests/sharding/comment_field.js executor: config: diff --git a/buildscripts/resmokeconfig/suites/sharding_auth.yml b/buildscripts/resmokeconfig/suites/sharding_auth.yml index 7f7e2b94ab5..fdba9ae21b9 100644 --- a/buildscripts/resmokeconfig/suites/sharding_auth.yml +++ b/buildscripts/resmokeconfig/suites/sharding_auth.yml @@ -30,9 +30,8 @@ selector: - jstests/sharding/migration_critical_section_concurrency.js # SERVER-21713 # Runs with auth enabled. - jstests/sharding/mongod_returns_no_cluster_time_without_keys.js - # Disable incompatible with json logging per SERVER-46235 + # SERVER-46018 Disable incompatible with ramlog truncation. - jstests/sharding/read_write_concern_defaults_application.js - - jstests/sharding/comment_field.js executor: config: diff --git a/buildscripts/resmokeconfig/suites/sharding_auth_audit.yml b/buildscripts/resmokeconfig/suites/sharding_auth_audit.yml index cbceafa023a..9eb0665a1ef 100644 --- a/buildscripts/resmokeconfig/suites/sharding_auth_audit.yml +++ b/buildscripts/resmokeconfig/suites/sharding_auth_audit.yml @@ -30,9 +30,8 @@ selector: - jstests/sharding/migration_critical_section_concurrency.js # SERVER-21713 # Runs with auth enabled. - jstests/sharding/mongod_returns_no_cluster_time_without_keys.js - # Disable incompatible with json logging per SERVER-46235 + # SERVER-46018 Disable incompatible with ramlog truncation. - jstests/sharding/read_write_concern_defaults_application.js - - jstests/sharding/comment_field.js executor: config: diff --git a/buildscripts/resmokeconfig/suites/sharding_continuous_config_stepdown.yml b/buildscripts/resmokeconfig/suites/sharding_continuous_config_stepdown.yml index 6320ec951a8..3a5d2b86a8d 100644 --- a/buildscripts/resmokeconfig/suites/sharding_continuous_config_stepdown.yml +++ b/buildscripts/resmokeconfig/suites/sharding_continuous_config_stepdown.yml @@ -213,8 +213,8 @@ selector: # Runs commands on mongos which target the primary configsvr, and then checks the outcome using # profiling/logging (on the configsvr primary), so cannot tolerate the configsvr primary changing. - jstests/sharding/read_write_concern_defaults_application.js - # Disable incompatible with json logging per SERVER-46235 - - jstests/sharding/comment_field.js + # SERVER-46018 Disable incompatible with ramlog truncation. + - jstests/sharding/read_write_concern_defaults_application.js executor: config: diff --git a/buildscripts/resmokeconfig/suites/sharding_ese.yml b/buildscripts/resmokeconfig/suites/sharding_ese.yml index 5797bf8c9b8..567677c35ff 100644 --- a/buildscripts/resmokeconfig/suites/sharding_ese.yml +++ b/buildscripts/resmokeconfig/suites/sharding_ese.yml @@ -8,9 +8,8 @@ selector: roots: - jstests/sharding/*.js exclude_files: - # Disable incompatible with json logging per SERVER-46235 + # SERVER-46018 Disable incompatible with ramlog truncation. - jstests/sharding/read_write_concern_defaults_application.js - - jstests/sharding/comment_field.js executor: config: diff --git a/buildscripts/resmokeconfig/suites/sharding_ese_gcm.yml b/buildscripts/resmokeconfig/suites/sharding_ese_gcm.yml index 8dbaf5d8945..ad86b9d9e08 100644 --- a/buildscripts/resmokeconfig/suites/sharding_ese_gcm.yml +++ b/buildscripts/resmokeconfig/suites/sharding_ese_gcm.yml @@ -8,9 +8,8 @@ selector: roots: - jstests/sharding/*.js exclude_files: - # Disable incompatible with json logging per SERVER-46235 + # SERVER-46018 Disable incompatible with ramlog truncation. - jstests/sharding/read_write_concern_defaults_application.js - - jstests/sharding/comment_field.js executor: config: diff --git a/buildscripts/resmokeconfig/suites/sharding_last_stable_mongos_and_mixed_shards.yml b/buildscripts/resmokeconfig/suites/sharding_last_stable_mongos_and_mixed_shards.yml index bdad7c608b1..2f74166b9dc 100644 --- a/buildscripts/resmokeconfig/suites/sharding_last_stable_mongos_and_mixed_shards.yml +++ b/buildscripts/resmokeconfig/suites/sharding_last_stable_mongos_and_mixed_shards.yml @@ -30,9 +30,8 @@ selector: - jstests/sharding/change_streams_update_lookup_shard_metadata_missing.js # Enable when SERVER-43310 is backported - jstests/sharding/cluster_create_indexes_always_routes_through_primary.js - # Disable incompatible with json logging per SERVER-46235 + # SERVER-46018 Disable incompatible with ramlog truncation. - jstests/sharding/read_write_concern_defaults_application.js - - jstests/sharding/comment_field.js executor: config: diff --git a/buildscripts/resmokeconfig/suites/sharding_misc.yml b/buildscripts/resmokeconfig/suites/sharding_misc.yml index 5018db17f24..f63647bdc6b 100644 --- a/buildscripts/resmokeconfig/suites/sharding_misc.yml +++ b/buildscripts/resmokeconfig/suites/sharding_misc.yml @@ -340,9 +340,8 @@ selector: - jstests/sharding/current_op_no_shards.js - jstests/sharding/movechunk_include.js - jstests/sharding/move_chunk_with_session_helper.js - # Disable incompatible with json logging per SERVER-46235 + # SERVER-46018 Disable incompatible with ramlog truncation. - jstests/sharding/read_write_concern_defaults_application.js - - jstests/sharding/comment_field.js executor: config: diff --git a/buildscripts/resmokeconfig/suites/sharding_multiversion.yml b/buildscripts/resmokeconfig/suites/sharding_multiversion.yml index bebac995367..0825addf473 100644 --- a/buildscripts/resmokeconfig/suites/sharding_multiversion.yml +++ b/buildscripts/resmokeconfig/suites/sharding_multiversion.yml @@ -7,9 +7,8 @@ selector: - multiversion_incompatible - requires_fcv_44 exclude_files: - # Disable incompatible with json logging per SERVER-46235 + # SERVER-46018 Disable incompatible with ramlog truncation. - jstests/sharding/read_write_concern_defaults_application.js - - jstests/sharding/comment_field.js executor: config: shell_options: diff --git a/buildscripts/resmokeconfig/suites/sharding_rs_matching_disabled.yml b/buildscripts/resmokeconfig/suites/sharding_rs_matching_disabled.yml index ae6a4e0ac13..750c8abe530 100644 --- a/buildscripts/resmokeconfig/suites/sharding_rs_matching_disabled.yml +++ b/buildscripts/resmokeconfig/suites/sharding_rs_matching_disabled.yml @@ -4,9 +4,8 @@ selector: roots: - jstests/sharding/*.js exclude_files: - # Disable incompatible with json logging per SERVER-46235 + # SERVER-46018 Disable incompatible with ramlog truncation. - jstests/sharding/read_write_concern_defaults_application.js - - jstests/sharding/comment_field.js executor: config: diff --git a/buildscripts/resmokeconfig/suites/sharding_rs_matching_match_busiest_node.yml b/buildscripts/resmokeconfig/suites/sharding_rs_matching_match_busiest_node.yml index 64a584ccd9f..3dfe353fc81 100644 --- a/buildscripts/resmokeconfig/suites/sharding_rs_matching_match_busiest_node.yml +++ b/buildscripts/resmokeconfig/suites/sharding_rs_matching_match_busiest_node.yml @@ -4,9 +4,8 @@ selector: roots: - jstests/sharding/*.js exclude_files: - # Disable incompatible with json logging per SERVER-46235 + # SERVER-46018 Disable incompatible with ramlog truncation. - jstests/sharding/read_write_concern_defaults_application.js - - jstests/sharding/comment_field.js executor: config: diff --git a/jstests/core/txns/timestamped_reads_wait_for_prepare_oplog_visibility.js b/jstests/core/txns/timestamped_reads_wait_for_prepare_oplog_visibility.js index 317bbe7feba..0c304a866ae 100644 --- a/jstests/core/txns/timestamped_reads_wait_for_prepare_oplog_visibility.js +++ b/jstests/core/txns/timestamped_reads_wait_for_prepare_oplog_visibility.js @@ -57,7 +57,11 @@ const readThreadFunc = function(readFunc, _collName, timesEntered) { db.adminCommand({configureFailPoint: 'hangAfterReservingPrepareTimestamp', mode: 'off'})); if (isJsonLogNoConn()) { - checkLog.contains(db.getMongo(), "\"command\":{\"prepareTransaction\":"); + checkLog.containsJson(db.getMongo(), 51803, { + 'command': function(obj) { + return obj.hasOwnProperty('prepareTransaction'); + } + }); } else { checkLog.contains(db.getMongo(), "command: prepareTransaction"); } diff --git a/jstests/replsets/initial_sync_drop_collection.js b/jstests/replsets/initial_sync_drop_collection.js index 468b3a1cce9..c31bb363550 100644 --- a/jstests/replsets/initial_sync_drop_collection.js +++ b/jstests/replsets/initial_sync_drop_collection.js @@ -139,8 +139,9 @@ let expectedLogFor3and4 = "`CollectionCloner ns: '${nss}' uuid: UUID(\"${uuid}\") stopped because collection was dropped on source.`"; if (isJsonLogNoConn()) { + // Double escape the backslash as eval will do unescaping expectedLogFor3and4 = - '`CollectionCloner ns: \'{ns}\' uuid: UUID("{uuid}") stopped because collection was dropped on source.","attr":{"ns":"${nss}","uuid":{"uuid":{"$binary":{"base64":"${uuid_base64}","subType":"4"}}}}}`'; + '`CollectionCloner ns: \'{ns}\' uuid: UUID(\\\\"{uuid}\\\\") stopped because collection was dropped on source.","attr":{"ns":"${nss}","uuid":{"uuid":{"$binary":{"base64":"${uuid_base64}","subType":"4"}}}}}`'; } // We don't support 4.2 style two-phase drops with EMRC=false - in that configuration, the @@ -148,8 +149,13 @@ if (isJsonLogNoConn()) { // the cloner queries collection by UUID, it will observe the first drop phase as a rename. // We still want to check that initial sync succeeds in such a case. if (TwoPhaseDropCollectionTest.supportsDropPendingNamespaces(replTest)) { - expectedLogFor3and4 = - "`Initial Sync retrying CollectionCloner stage query due to QueryPlanKilled: collection renamed from '${nss}' to '${rnss}'. UUID ${uuid}`"; + if (isJsonLogNoConn()) { + expectedLogFor3and4 = + '`Initial Sync retrying {cloner} stage {stage} due to {lastError}","attr":{"cloner":"CollectionCloner","stage":"query","lastError":{"code":175,"codeName":"QueryPlanKilled","errmsg":"collection renamed from \'${nss}\' to \'${rnss}\'. UUID ${uuid}`'; + } else { + expectedLogFor3and4 = + "`Initial Sync retrying CollectionCloner stage query due to QueryPlanKilled: collection renamed from '${nss}' to '${rnss}'. UUID ${uuid}`"; + } } jsTestLog("[3] Testing drop-pending between getMore calls."); @@ -178,8 +184,9 @@ runDropTest({ failPoint: "initialSyncHangCollectionClonerAfterHandlingBatchResponse", secondaryStartupParams: {collectionClonerBatchSize: 1}, waitForDrop: true, + // Double escape the backslash as eval will do unescaping expectedLog: isJsonLogNoConn() - ? '`CollectionCloner ns: \'{ns}\' uuid: UUID("{uuid}") stopped because collection was dropped on source.","attr":{"ns":"${nss}","uuid":{"uuid":{"$binary":{"base64":"${uuid_base64}","subType":"4"}}}}}`' + ? '`CollectionCloner ns: \'{ns}\' uuid: UUID(\\\\"{uuid}\\\\") stopped because collection was dropped on source.","attr":{"ns":"${nss}","uuid":{"uuid":{"$binary":{"base64":"${uuid_base64}","subType":"4"}}}}}`' : "`CollectionCloner ns: '${nss}' uuid: UUID(\"${uuid}\") stopped because collection was dropped on source.`" }); @@ -189,8 +196,9 @@ runDropTest({ failPoint: "initialSyncHangCollectionClonerAfterHandlingBatchResponse", secondaryStartupParams: {collectionClonerBatchSize: 1}, waitForDrop: true, + // Double escape the backslash as eval will do unescaping expectedLog: isJsonLogNoConn() - ? '`CollectionCloner ns: \'{ns}\' uuid: UUID("{uuid}") stopped because collection was dropped on source.","attr":{"ns":"${nss}","uuid":{"uuid":{"$binary":{"base64":"${uuid_base64}","subType":"4"}}}}}`' + ? '`CollectionCloner ns: \'{ns}\' uuid: UUID(\\\\"{uuid}\\\\") stopped because collection was dropped on source.","attr":{"ns":"${nss}","uuid":{"uuid":{"$binary":{"base64":"${uuid_base64}","subType":"4"}}}}}`' : "`CollectionCloner ns: '${nss}' uuid: UUID(\"${uuid}\") stopped because collection was dropped on source.`", createNew: true }); diff --git a/jstests/replsets/initial_sync_rename_collection.js b/jstests/replsets/initial_sync_rename_collection.js index fb1df6a604f..2bbbb3d3c70 100644 --- a/jstests/replsets/initial_sync_rename_collection.js +++ b/jstests/replsets/initial_sync_rename_collection.js @@ -163,9 +163,7 @@ runRenameTest({ }); const expectedLogFor5and7 = isJsonLogNoConn() - ? - - '`Initial Sync retrying {getClonerName} stage {stage_getName} due to {lastError}","attr":{"getClonerName":"CollectionCloner","stage_getName":"query","lastError":{"code":175,"codeName":"QueryPlanKilled","errmsg":"collection renamed from \'${nss}\' to \'${rnss}\'. UUID ${uuid}"}}}`' + ? '`Initial Sync retrying {cloner} stage {stage} due to {lastError}","attr":{"cloner":"CollectionCloner","stage":"query","lastError":{"code":175,"codeName":"QueryPlanKilled","errmsg":"collection renamed from \'${nss}\' to \'${rnss}\'. UUID ${uuid}"}}}`' : "`Initial Sync retrying CollectionCloner stage query due to QueryPlanKilled: collection renamed from '${nss}' to '${rnss}'. UUID ${uuid}`"; jsTestLog("[5] Testing rename between getMores."); @@ -180,8 +178,9 @@ let expectedLogFor6and8 = "`CollectionCloner ns: '${nss}' uuid: UUID(\"${uuid}\") stopped because collection was dropped on source.`"; if (isJsonLogNoConn()) { + // Double escape the backslash as eval will do unescaping expectedLogFor6and8 = - '`CollectionCloner ns: \'{ns}\' uuid: UUID("{uuid}") stopped because collection was dropped on source.","attr":{"ns":"${nss}","uuid":{"uuid":{"$binary":{"base64":"${uuid_base64}","subType":"4"}}}}}`'; + '`CollectionCloner ns: \'{ns}\' uuid: UUID(\\\\"{uuid}\\\\") stopped because collection was dropped on source.","attr":{"ns":"${nss}","uuid":{"uuid":{"$binary":{"base64":"${uuid_base64}","subType":"4"}}}}}`'; } // We don't support 4.2 style two-phase drops with EMRC=false - in that configuration, the @@ -189,8 +188,13 @@ if (isJsonLogNoConn()) { // the cloner queries collection by UUID, it will observe the first drop phase as a rename. // We still want to check that initial sync succeeds in such a case. if (TwoPhaseDropCollectionTest.supportsDropPendingNamespaces(replTest)) { - expectedLogFor6and8 = - "`Initial Sync retrying CollectionCloner stage query due to QueryPlanKilled: collection renamed from '${nss}' to '${dropPendingNss}'. UUID ${uuid}`"; + if (isJsonLogNoConn()) { + expectedLogFor6and8 = + '`Initial Sync retrying {cloner} stage {stage} due to {lastError}","attr":{"cloner":"CollectionCloner","stage":"query","lastError":{"code":175,"codeName":"QueryPlanKilled","errmsg":"collection renamed from \'${nss}\' to \'${dropPendingNss}\'. UUID ${uuid}`'; + } else { + expectedLogFor6and8 = + "`Initial Sync retrying CollectionCloner stage query due to QueryPlanKilled: collection renamed from '${nss}' to '${dropPendingNss}'. UUID ${uuid}`"; + } } jsTestLog("[6] Testing cross-DB rename between getMores."); diff --git a/jstests/sharding/comment_field.js b/jstests/sharding/comment_field.js index a155c2ed0c0..2a8753bac80 100644 --- a/jstests/sharding/comment_field.js +++ b/jstests/sharding/comment_field.js @@ -169,7 +169,7 @@ function runCommentParamTest({ checkLog.formatAsLogLine(commentObj), 'appName: "MongoDB Shell" command: ' + ((cmdName === "getMore") ? cmdName : "") ]; - if (isJsonLog(testDB)) { + if (isJsonLog(testDB.getMongo())) { expectStrings = [ ',"comment":', checkLog.formatAsJsonLogLine(commentObj), diff --git a/src/mongo/db/repl/base_cloner.cpp b/src/mongo/db/repl/base_cloner.cpp index 99b38605c4f..0fd80028486 100644 --- a/src/mongo/db/repl/base_cloner.cpp +++ b/src/mongo/db/repl/base_cloner.cpp @@ -216,11 +216,10 @@ BaseCloner::AfterStageBehavior BaseCloner::runStageWithRetries(BaseClonerStage* // If lastError is set, this is a retry. hangBeforeRetryingClonerStage.executeIf( [&](const BSONObj& data) { - LOGV2( - 21074, - "Cloner {getClonerName} hanging before retrying stage {stage_getName}", - "getClonerName"_attr = getClonerName(), - "stage_getName"_attr = stage->getName()); + LOGV2(21074, + "Cloner {cloner} hanging before retrying stage {stage}", + "cloner"_attr = getClonerName(), + "stage"_attr = stage->getName()); while (!mustExit() && hangBeforeRetryingClonerStage.shouldFail(isThisStageFailPoint)) { sleepmillis(100); @@ -228,10 +227,10 @@ BaseCloner::AfterStageBehavior BaseCloner::runStageWithRetries(BaseClonerStage* }, isThisStageFailPoint); LOGV2(21075, - "Initial Sync retrying {getClonerName} stage {stage_getName} due to " + "Initial Sync retrying {cloner} stage {stage} due to " "{lastError}", - "getClonerName"_attr = getClonerName(), - "stage_getName"_attr = stage->getName(), + "cloner"_attr = getClonerName(), + "stage"_attr = stage->getName(), "lastError"_attr = lastError); bool shouldRetry = [&] { stdx::lock_guard lk(*_sharedData); @@ -249,10 +248,10 @@ BaseCloner::AfterStageBehavior BaseCloner::runStageWithRetries(BaseClonerStage* hangBeforeCheckingRollBackIdClonerStage.executeIf( [&](const BSONObj& data) { LOGV2(21076, - "Cloner {getClonerName} hanging before checking rollBackId for stage " - "{stage_getName}", - "getClonerName"_attr = getClonerName(), - "stage_getName"_attr = stage->getName()); + "Cloner {cloner} hanging before checking rollBackId for stage " + "{stage}", + "cloner"_attr = getClonerName(), + "stage"_attr = stage->getName()); while (!mustExit() && hangBeforeCheckingRollBackIdClonerStage.shouldFail( isThisStageFailPoint)) { @@ -275,18 +274,18 @@ BaseCloner::AfterStageBehavior BaseCloner::runStageWithRetries(BaseClonerStage* if (!stage->isTransientError(lastError)) { LOGV2(21077, "Non-retryable error occured during cloner " - "{getClonerName}{stage_stage_getName}: {lastError}", - "getClonerName"_attr = getClonerName(), - "stage_stage_getName"_attr = " stage " + stage->getName(), + "{cloner} stage {stage}: {lastError}", + "cloner"_attr = getClonerName(), + "stage"_attr = stage->getName(), "lastError"_attr = lastError); throw; } LOGV2_DEBUG(21078, 1, "Transient error occured during cloner " - "{getClonerName}{stage_stage_getName}: {lastError}", - "getClonerName"_attr = getClonerName(), - "stage_stage_getName"_attr = " stage " + stage->getName(), + "{cloner} stage {stage}: {lastError}", + "cloner"_attr = getClonerName(), + "stage"_attr = stage->getName(), "lastError"_attr = lastError); } } -- cgit v1.2.1