[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:20:09.399111   873 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.0.218.126:43883
I20260812 06:20:09.400291   873 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:20:09.400941   873 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:09.408030   889 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:09.408275   873 server_base.cc:1061] running on GCE node
W20260812 06:20:09.408341   878 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:09.408420   884 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:09.409027   873 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:09.409157   873 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:09.409199   873 hybrid_clock.cc:648] HybridClock initialized: now 1786515609409197 us; error 0 us; skew 500 ppm
I20260812 06:20:09.414318   873 webserver.cc:533] Webserver started at http://127.0.218.126:36015/ using document root <none> and password file <none>
I20260812 06:20:09.414912   873 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:09.414995   873 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:09.415216   873 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:09.417090   873 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/master-0-root/instance:
uuid: "88a29b19de9c404fb6d6d239df57945a"
format_stamp: "Formatted at 2026-08-12 06:20:09 on dist-test-slave-1l3l"
I20260812 06:20:09.420892   873 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:20:09.423167   900 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:09.424314   873 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:09.424438   873 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/master-0-root
uuid: "88a29b19de9c404fb6d6d239df57945a"
format_stamp: "Formatted at 2026-08-12 06:20:09 on dist-test-slave-1l3l"
I20260812 06:20:09.424551   873 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:09.440827   873 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:09.441551   873 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:20:09.441728   873 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:09.449625   993 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.218.126:43883 every 8 connection(s)
I20260812 06:20:09.449640   873 rpc_server.cc:307] RPC server started. Bound to: 127.0.218.126:43883
I20260812 06:20:09.452167   994 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:09.458086   994 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a: Bootstrap starting.
I20260812 06:20:09.460736   994 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:09.461722   994 log.cc:826] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:09.463631   994 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a: No bootstrap required, opened a new log
I20260812 06:20:09.466779   994 raft_consensus.cc:359] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "88a29b19de9c404fb6d6d239df57945a" member_type: VOTER }
I20260812 06:20:09.466988   994 raft_consensus.cc:385] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:09.467041   994 raft_consensus.cc:740] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 88a29b19de9c404fb6d6d239df57945a, State: Initialized, Role: FOLLOWER
I20260812 06:20:09.467736   994 consensus_queue.cc:260] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 0, Majority size: -1, State: 0, Mode: NON_LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "88a29b19de9c404fb6d6d239df57945a" member_type: VOTER }
I20260812 06:20:09.467900   994 raft_consensus.cc:399] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:09.467952   994 raft_consensus.cc:493] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:09.468051   994 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:09.468912   994 raft_consensus.cc:515] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "88a29b19de9c404fb6d6d239df57945a" member_type: VOTER }
I20260812 06:20:09.469359   994 leader_election.cc:304] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a [CANDIDATE]: Term 1 election: Election decided. Result: candidate won. Election summary: received 1 responses out of 1 voters: 1 yes votes; 0 no votes. yes voters: 88a29b19de9c404fb6d6d239df57945a; no voters: 
I20260812 06:20:09.469681   994 leader_election.cc:290] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:09.469851   999 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:09.470086   999 raft_consensus.cc:697] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a [term 1 LEADER]: Becoming Leader. State: Replica: 88a29b19de9c404fb6d6d239df57945a, State: Running, Role: LEADER
I20260812 06:20:09.470541   999 consensus_queue.cc:237] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a [LEADER]: Queue going to LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 1, Majority size: 1, State: 0, Mode: LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "88a29b19de9c404fb6d6d239df57945a" member_type: VOTER }
I20260812 06:20:09.470827   994 sys_catalog.cc:565] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:09.472684  1003 sys_catalog.cc:455] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a [sys.catalog]: SysCatalogTable state changed. Reason: New leader 88a29b19de9c404fb6d6d239df57945a. Latest consensus state: current_term: 1 leader_uuid: "88a29b19de9c404fb6d6d239df57945a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "88a29b19de9c404fb6d6d239df57945a" member_type: VOTER } }
I20260812 06:20:09.472708  1001 sys_catalog.cc:455] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "88a29b19de9c404fb6d6d239df57945a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "88a29b19de9c404fb6d6d239df57945a" member_type: VOTER } }
I20260812 06:20:09.472854  1003 sys_catalog.cc:458] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:09.472901  1001 sys_catalog.cc:458] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:09.473147   873 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:20:09.475229  1029 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:20:09.475317  1029 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:20:09.475391  1026 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:09.476186  1026 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:09.481220  1026 catalog_manager.cc:1383] Generated new cluster ID: 501097d7623948e181ba86d624aa5ad7
I20260812 06:20:09.481308  1026 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:09.497557  1026 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:09.498839  1026 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:09.510859  1026 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a: Generated new TSK 0
I20260812 06:20:09.511782  1026 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:09.538322   873 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:09.541535  1039 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:09.541482  1035 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:09.541663   873 server_base.cc:1061] running on GCE node
W20260812 06:20:09.541566  1034 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:09.542163   873 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:09.542217   873 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:09.542238   873 hybrid_clock.cc:648] HybridClock initialized: now 1786515609542238 us; error 0 us; skew 500 ppm
I20260812 06:20:09.543228   873 webserver.cc:533] Webserver started at http://127.0.218.65:34773/ using document root <none> and password file <none>
I20260812 06:20:09.543422   873 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:09.543493   873 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:09.543583   873 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:09.544072   873 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/instance:
uuid: "4705a2686d044d9aa656f65df9ef2970"
format_stamp: "Formatted at 2026-08-12 06:20:09 on dist-test-slave-1l3l"
I20260812 06:20:09.548206   873 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:09.549554  1049 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:09.549856   873 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:09.550009   873 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root
uuid: "4705a2686d044d9aa656f65df9ef2970"
format_stamp: "Formatted at 2026-08-12 06:20:09 on dist-test-slave-1l3l"
I20260812 06:20:09.550098   873 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:09.570861   873 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:09.571846   873 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:09.572527   873 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:09.573681   873 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:09.573791   873 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:09.573885   873 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:09.573937   873 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:09.587436   873 rpc_server.cc:307] RPC server started. Bound to: 127.0.218.65:35539
I20260812 06:20:09.587483  1153 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.218.65:35539 every 8 connection(s)
I20260812 06:20:09.600083  1154 heartbeater.cc:344] Connected to a master server at 127.0.218.126:43883
I20260812 06:20:09.600410  1154 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:09.601071  1154 heartbeater.cc:507] Master 127.0.218.126:43883 requested a full tablet report, sending...
I20260812 06:20:09.602838   934 ts_manager.cc:194] Registered new tserver with Master: 4705a2686d044d9aa656f65df9ef2970 (127.0.218.65:35539)
I20260812 06:20:09.603976   873 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015757543s
I20260812 06:20:09.604379   934 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:48336
I20260812 06:20:09.616184   934 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:48352:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:09.631450  1099 tablet_service.cc:1511] Processing CreateTablet for tablet 6c8b4d3e77e645cd98006972b4e9ecba (DEFAULT_TABLE table=heavy-update-compaction-test [id=d0f657c674404138949945eb6e1ad96d]), partition=
I20260812 06:20:09.632143  1099 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 6c8b4d3e77e645cd98006972b4e9ecba. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:09.634661  1166 tablet_bootstrap.cc:492] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Bootstrap starting.
I20260812 06:20:09.636422  1166 tablet_bootstrap.cc:654] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:09.637872  1166 tablet_bootstrap.cc:492] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: No bootstrap required, opened a new log
I20260812 06:20:09.638019  1166 ts_tablet_manager.cc:1403] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Time spent bootstrapping tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:20:09.638633  1166 raft_consensus.cc:359] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4705a2686d044d9aa656f65df9ef2970" member_type: VOTER last_known_addr { host: "127.0.218.65" port: 35539 } }
I20260812 06:20:09.638774  1166 raft_consensus.cc:385] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:09.638866  1166 raft_consensus.cc:740] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4705a2686d044d9aa656f65df9ef2970, State: Initialized, Role: FOLLOWER
I20260812 06:20:09.639111  1166 consensus_queue.cc:260] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970 [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 0, Majority size: -1, State: 0, Mode: NON_LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4705a2686d044d9aa656f65df9ef2970" member_type: VOTER last_known_addr { host: "127.0.218.65" port: 35539 } }
I20260812 06:20:09.639230  1166 raft_consensus.cc:399] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:09.639281  1166 raft_consensus.cc:493] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:09.639329  1166 raft_consensus.cc:3060] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:09.640488  1166 raft_consensus.cc:515] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4705a2686d044d9aa656f65df9ef2970" member_type: VOTER last_known_addr { host: "127.0.218.65" port: 35539 } }
I20260812 06:20:09.640648  1166 leader_election.cc:304] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970 [CANDIDATE]: Term 1 election: Election decided. Result: candidate won. Election summary: received 1 responses out of 1 voters: 1 yes votes; 0 no votes. yes voters: 4705a2686d044d9aa656f65df9ef2970; no voters: 
I20260812 06:20:09.640899  1166 leader_election.cc:290] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:09.641036  1168 raft_consensus.cc:2804] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:09.641291  1168 raft_consensus.cc:697] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970 [term 1 LEADER]: Becoming Leader. State: Replica: 4705a2686d044d9aa656f65df9ef2970, State: Running, Role: LEADER
I20260812 06:20:09.641522  1168 consensus_queue.cc:237] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970 [LEADER]: Queue going to LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 1, Majority size: 1, State: 0, Mode: LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4705a2686d044d9aa656f65df9ef2970" member_type: VOTER last_known_addr { host: "127.0.218.65" port: 35539 } }
I20260812 06:20:09.641577  1154 heartbeater.cc:499] Master 127.0.218.126:43883 was elected leader, sending a full tablet report...
I20260812 06:20:09.641300  1166 ts_tablet_manager.cc:1434] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Time spent starting tablet: real 0.003s	user 0.002s	sys 0.002s
I20260812 06:20:09.644650   933 catalog_manager.cc:5719] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970 reported cstate change: term changed from 0 to 1, leader changed from <none> to 4705a2686d044d9aa656f65df9ef2970 (127.0.218.65). New cstate: current_term: 1 leader_uuid: "4705a2686d044d9aa656f65df9ef2970" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4705a2686d044d9aa656f65df9ef2970" member_type: VOTER last_known_addr { host: "127.0.218.65" port: 35539 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:09.711529   873 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.020s	sys 0.008s
I20260812 06:20:09.838739  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushMRSOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=15.086190
I20260812 06:20:10.002086  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushMRSOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.163s	user 0.115s	sys 0.043s Metrics: {"bytes_written":8615325,"cfile_init":1,"compiler_manager_pool.queue_time_us":846,"delete_count":0,"dirs.queue_time_us":44,"dirs.run_cpu_time_us":187,"dirs.run_wall_time_us":749,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39442,"lbm_writes_lt_1ms":667,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":132,"threads_started":1,"update_count":1050}
I20260812 06:20:10.004069  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling LogGCOp(6c8b4d3e77e645cd98006972b4e9ecba): free 20743880 bytes of WAL
I20260812 06:20:10.004475  1059 log_reader.cc:385] T 6c8b4d3e77e645cd98006972b4e9ecba: removed 2 log segments from log reader
I20260812 06:20:10.004601  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000001 (ops 1-6)
I20260812 06:20:10.004666  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000002 (ops 7-11)
I20260812 06:20:10.009927  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: LogGCOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:10.010522  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling UndoDeltaBlockGCOp(6c8b4d3e77e645cd98006972b4e9ecba): 16411392 bytes on disk
I20260812 06:20:10.011297  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: UndoDeltaBlockGCOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":83,"lbm_reads_lt_1ms":4}
I20260812 06:20:10.011839  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:10.035827  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.024s	user 0.003s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4406,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:10.036268  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:10.046795  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3754,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.047312  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:10.181012  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.134s	user 0.095s	sys 0.032s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20672389,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":661,"lbm_read_time_us":8498,"lbm_reads_lt_1ms":469,"lbm_write_time_us":23222,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"thread_start_us":300,"threads_started":5,"update_count":2000}
I20260812 06:20:10.181602  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=10.126437
I20260812 06:20:10.227165  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.045s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14969,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:10.227810  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:10.244933  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.017s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6126,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.245617  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:10.366604  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.121s	user 0.100s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":519,"lbm_read_time_us":9770,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21664,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":52992,"update_count":2000}
I20260812 06:20:10.367372  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=10.126437
I20260812 06:20:10.405169  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.038s	user 0.029s	sys 0.000s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12740,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:10.405768  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:10.421737  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6000,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.422281  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:10.537716  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.115s	user 0.079s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":168,"lbm_read_time_us":8180,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21565,"lbm_writes_lt_1ms":443,"mutex_wait_us":3,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:10.538509  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=10.126437
I20260812 06:20:10.582135  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.043s	user 0.008s	sys 0.026s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13236,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:10.582830  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:10.599208  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5845,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.599871  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:10.745880  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.146s	user 0.104s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":182,"lbm_read_time_us":10780,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23724,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13056,"update_count":2000}
I20260812 06:20:10.746584  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=10.126437
I20260812 06:20:10.791512  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.045s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18690,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:20:10.792057  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:10.803498  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4126,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.804141  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:10.926126  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.122s	user 0.100s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":333,"lbm_read_time_us":9131,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23467,"lbm_writes_lt_1ms":443,"mutex_wait_us":59,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2000}
I20260812 06:20:10.926622  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=10.126437
I20260812 06:20:10.966768  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.040s	user 0.033s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16772,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:10.967371  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:10.979055  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3993,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.979552  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:11.104249  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.125s	user 0.082s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":865,"lbm_read_time_us":8323,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25334,"lbm_writes_lt_1ms":443,"mutex_wait_us":294,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2000}
I20260812 06:20:11.104889  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=10.126437
I20260812 06:20:11.149698  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.045s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15055,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:11.150247  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:11.161047  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3962,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.161628  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushMRSOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:11.199194  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushMRSOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.037s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":116,"dirs.run_cpu_time_us":211,"dirs.run_wall_time_us":1563,"drs_written":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1888,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:11.200254  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling LogGCOp(6c8b4d3e77e645cd98006972b4e9ecba): free 112239304 bytes of WAL
I20260812 06:20:11.200543  1059 log_reader.cc:385] T 6c8b4d3e77e645cd98006972b4e9ecba: removed 11 log segments from log reader
I20260812 06:20:11.200596  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000003 (ops 12-16)
I20260812 06:20:11.200640  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000004 (ops 17-20)
I20260812 06:20:11.200675  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000005 (ops 21-25)
I20260812 06:20:11.200700  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000006 (ops 26-30)
I20260812 06:20:11.200731  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000007 (ops 31-35)
I20260812 06:20:11.200762  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000008 (ops 36-40)
I20260812 06:20:11.200794  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000009 (ops 41-45)
I20260812 06:20:11.200825  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000010 (ops 46-50)
I20260812 06:20:11.200865  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000011 (ops 51-55)
I20260812 06:20:11.200896  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000012 (ops 56-60)
I20260812 06:20:11.200927  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000013 (ops 61-65)
I20260812 06:20:11.220814  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: LogGCOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.020s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:20:11.221293  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:11.245168  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.024s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4718,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.245687  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling UndoDeltaBlockGCOp(6c8b4d3e77e645cd98006972b4e9ecba): 448 bytes on disk
I20260812 06:20:11.246141  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: UndoDeltaBlockGCOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:20:11.246640  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:11.257366  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3718,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.257959  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:11.449753  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.192s	user 0.136s	sys 0.051s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877339,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":705,"lbm_read_time_us":11968,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33339,"lbm_writes_lt_1ms":643,"mutex_wait_us":68,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":96,"threads_started":1,"update_count":3000}
I20260812 06:20:11.450397  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=14.095187
I20260812 06:20:11.490988  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.040s	user 0.037s	sys 0.000s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17950,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:11.491539  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:11.628373  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.137s	user 0.105s	sys 0.031s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":115,"lbm_read_time_us":10129,"lbm_reads_lt_1ms":467,"lbm_write_time_us":21243,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:20:11.629106  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=10.126437
I20260812 06:20:11.670990  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.042s	user 0.021s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18247,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:11.671861  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:11.688740  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.017s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5287,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.689281  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:11.816012  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.127s	user 0.096s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":520,"lbm_read_time_us":9518,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22764,"lbm_writes_lt_1ms":443,"mutex_wait_us":19,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2000}
I20260812 06:20:11.816817  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=10.126437
I20260812 06:20:11.849119  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.032s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13529,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:11.850082  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:11.862252  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4210,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.862970  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:11.988533  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.125s	user 0.093s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":403,"lbm_read_time_us":8374,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22467,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:11.989254  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=10.126437
I20260812 06:20:12.026981  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.037s	user 0.029s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14767,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:12.027607  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:12.042657  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5652,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.043248  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:12.161542  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.118s	user 0.088s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":320,"lbm_read_time_us":8424,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22670,"lbm_writes_lt_1ms":443,"mutex_wait_us":54,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:12.162075  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=10.126437
I20260812 06:20:12.214936  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.053s	user 0.026s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20733,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:12.215647  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:12.226238  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3954,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.226742  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:12.365260  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.138s	user 0.102s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":367,"lbm_read_time_us":10626,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21795,"lbm_writes_lt_1ms":443,"mutex_wait_us":19,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:20:12.368170  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=11.118625
I20260812 06:20:12.398689  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.030s	user 0.023s	sys 0.005s Metrics: {"bytes_written":12676712,"delete_count":0,"lbm_write_time_us":13086,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1545}
I20260812 06:20:12.399452  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:12.411163  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3733434,"delete_count":0,"lbm_write_time_us":4344,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:20:12.411628  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:12.532240  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.120s	user 0.096s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672274,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":137,"lbm_read_time_us":8578,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22924,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2000}
I20260812 06:20:12.533378  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=11.118625
I20260812 06:20:12.564332  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.031s	user 0.016s	sys 0.012s Metrics: {"bytes_written":12553634,"delete_count":0,"lbm_write_time_us":12045,"lbm_writes_lt_1ms":309,"reinsert_count":0,"update_count":1530}
I20260812 06:20:12.564909  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:12.577554  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3856508,"delete_count":0,"lbm_write_time_us":4774,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:20:12.578292  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushMRSOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:12.605626  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushMRSOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.027s	user 0.022s	sys 0.003s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":229,"dirs.run_wall_time_us":1444,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1561,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:12.606326  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling LogGCOp(6c8b4d3e77e645cd98006972b4e9ecba): free 121006439 bytes of WAL
I20260812 06:20:12.606530  1059 log_reader.cc:385] T 6c8b4d3e77e645cd98006972b4e9ecba: removed 12 log segments from log reader
I20260812 06:20:12.606570  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000014 (ops 66-70)
I20260812 06:20:12.606600  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000015 (ops 71-75)
I20260812 06:20:12.606619  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000016 (ops 76-80)
I20260812 06:20:12.606650  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000017 (ops 81-85)
I20260812 06:20:12.606675  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000018 (ops 86-90)
I20260812 06:20:12.606714  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000019 (ops 91-95)
I20260812 06:20:12.606732  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000020 (ops 96-100)
I20260812 06:20:12.606747  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000021 (ops 101-105)
I20260812 06:20:12.606768  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000022 (ops 106-110)
I20260812 06:20:12.606801  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000023 (ops 111-114)
I20260812 06:20:12.606823  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000024 (ops 115-119)
I20260812 06:20:12.606854  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000025 (ops 120-124)
I20260812 06:20:12.629895  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: LogGCOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.023s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:20:12.630406  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling UndoDeltaBlockGCOp(6c8b4d3e77e645cd98006972b4e9ecba): 482 bytes on disk
I20260812 06:20:12.630892  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: UndoDeltaBlockGCOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:20:12.631572  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=5.165500
I20260812 06:20:12.647336  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":6482066,"delete_count":0,"lbm_write_time_us":6262,"lbm_writes_lt_1ms":161,"reinsert_count":0,"update_count":790}
I20260812 06:20:12.648041  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling LogGCOp(6c8b4d3e77e645cd98006972b4e9ecba): free 12017886 bytes of WAL
I20260812 06:20:12.648313  1059 log_reader.cc:385] T 6c8b4d3e77e645cd98006972b4e9ecba: removed 1 log segments from log reader
I20260812 06:20:12.648365  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000026 (ops 125-129)
I20260812 06:20:12.651142  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: LogGCOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.003s	user 0.002s	sys 0.001s Metrics: {}
I20260812 06:20:12.651682  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:12.660423  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.008s	user 0.006s	sys 0.000s Metrics: {"bytes_written":1723202,"delete_count":0,"lbm_write_time_us":1886,"lbm_writes_lt_1ms":45,"reinsert_count":0,"update_count":210}
I20260812 06:20:12.660987  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:12.823872  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.163s	user 0.125s	sys 0.038s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":285,"lbm_read_time_us":11934,"lbm_reads_lt_1ms":670,"lbm_write_time_us":30684,"lbm_writes_lt_1ms":643,"mutex_wait_us":33,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:20:12.824926  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=14.095187
I20260812 06:20:12.874449  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.049s	user 0.037s	sys 0.010s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21784,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:12.875036  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:12.886288  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3811,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.886771  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:13.025465  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.139s	user 0.114s	sys 0.023s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":670,"lbm_read_time_us":9434,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28484,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2500}
I20260812 06:20:13.027266  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=11.118625
I20260812 06:20:13.056573  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.029s	user 0.021s	sys 0.007s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":12496,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:13.057226  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:13.069962  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4393,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:13.070559  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:13.195200  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.124s	user 0.097s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":249,"lbm_read_time_us":7795,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24659,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2000}
I20260812 06:20:13.195842  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=10.126437
I20260812 06:20:13.234422  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.038s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13618,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:13.234959  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:13.245322  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3755,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.246031  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:13.367760  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.122s	user 0.103s	sys 0.015s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":419,"lbm_read_time_us":8195,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22168,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":39936,"update_count":2000}
I20260812 06:20:13.368322  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=10.126437
I20260812 06:20:13.420518  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.052s	user 0.033s	sys 0.010s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15905,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:13.421164  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:13.432015  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4015,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.432498  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:13.568938  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.136s	user 0.096s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":339,"lbm_read_time_us":10638,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20859,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2000}
I20260812 06:20:13.572173  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=10.126437
I20260812 06:20:13.617003  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.044s	user 0.030s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15269,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:13.617538  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:13.628863  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3963,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.629384  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:13.750877  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.121s	user 0.092s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":469,"lbm_read_time_us":10312,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22723,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2000}
I20260812 06:20:13.751474  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=10.126437
I20260812 06:20:13.784680  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.033s	user 0.012s	sys 0.019s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":13677,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:13.785221  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:13.800729  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5575,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.801270  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:13.923893  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.122s	user 0.102s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":150,"lbm_read_time_us":8576,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24740,"lbm_writes_lt_1ms":443,"mutex_wait_us":18,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2000}
I20260812 06:20:13.924553  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=10.126437
I20260812 06:20:13.972630  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.048s	user 0.033s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14630,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:13.973199  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:13.988303  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5692,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.988806  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushMRSOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:14.025267  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushMRSOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.036s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":226,"dirs.run_wall_time_us":1482,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1371,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:14.026005  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling LogGCOp(6c8b4d3e77e645cd98006972b4e9ecba): free 121006757 bytes of WAL
I20260812 06:20:14.026221  1059 log_reader.cc:385] T 6c8b4d3e77e645cd98006972b4e9ecba: removed 12 log segments from log reader
I20260812 06:20:14.026265  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000027 (ops 130-134)
I20260812 06:20:14.026293  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000028 (ops 135-139)
I20260812 06:20:14.026321  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000029 (ops 140-144)
I20260812 06:20:14.026355  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000030 (ops 145-148)
I20260812 06:20:14.026378  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000031 (ops 149-153)
I20260812 06:20:14.026409  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000032 (ops 154-158)
I20260812 06:20:14.026441  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000033 (ops 159-163)
I20260812 06:20:14.026474  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000034 (ops 164-168)
I20260812 06:20:14.026504  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000035 (ops 169-173)
I20260812 06:20:14.026535  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000036 (ops 174-178)
I20260812 06:20:14.026567  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000037 (ops 179-183)
I20260812 06:20:14.026599  1059 log.cc:1079] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609385990-873-0/minicluster-data/ts-0-root/wals/6c8b4d3e77e645cd98006972b4e9ecba/wal-000000038 (ops 184-188)
I20260812 06:20:14.048615  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: LogGCOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.022s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:20:14.049048  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling UndoDeltaBlockGCOp(6c8b4d3e77e645cd98006972b4e9ecba): 472 bytes on disk
I20260812 06:20:14.049494  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: UndoDeltaBlockGCOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:20:14.050024  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:14.066959  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.017s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4195,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.067404  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=2.188937
I20260812 06:20:14.077479  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3772,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.077965  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:14.263988  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.186s	user 0.136s	sys 0.047s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":4492,"lbm_read_time_us":12634,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30700,"lbm_writes_lt_1ms":643,"mutex_wait_us":58,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8576,"thread_start_us":88,"threads_started":1,"update_count":3000}
I20260812 06:20:14.264580  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=14.095187
I20260812 06:20:14.314713  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: FlushDeltaMemStoresOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.050s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20941,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:14.315270  1155 maintenance_manager.cc:419] P 4705a2686d044d9aa656f65df9ef2970: Scheduling MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba): perf score=1.000000
I20260812 06:20:14.323570   873 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.612s	user 1.690s	sys 0.149s
I20260812 06:20:14.392835   873 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.069s	user 0.002s	sys 0.000s
I20260812 06:20:14.393457   873 tablet_server.cc:179] TabletServer@127.0.218.65:0 shutting down...
I20260812 06:20:14.437760  1059 maintenance_manager.cc:643] P 4705a2686d044d9aa656f65df9ef2970: MajorDeltaCompactionOp(6c8b4d3e77e645cd98006972b4e9ecba) complete. Timing: real 0.122s	user 0.082s	sys 0.039s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":260,"lbm_read_time_us":9826,"lbm_reads_lt_1ms":459,"lbm_write_time_us":19524,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":2000}
I20260812 06:20:14.438429   873 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:14.438859   873 tablet_replica.cc:333] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970: stopping tablet replica
I20260812 06:20:14.439090   873 raft_consensus.cc:2243] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:14.439325   873 raft_consensus.cc:2272] T 6c8b4d3e77e645cd98006972b4e9ecba P 4705a2686d044d9aa656f65df9ef2970 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:14.455515   873 tablet_server.cc:196] TabletServer@127.0.218.65:0 shutdown complete.
I20260812 06:20:14.480600   873 master.cc:562] Master@127.0.218.126:43883 shutting down...
I20260812 06:20:14.484148   873 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:14.484304   873 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:14.484357   873 tablet_replica.cc:333] T 00000000000000000000000000000000 P 88a29b19de9c404fb6d6d239df57945a: stopping tablet replica
I20260812 06:20:14.496425   873 master.cc:584] Master@127.0.218.126:43883 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5175 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:14.571939   873 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.0.218.126:35867
I20260812 06:20:14.572292   873 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:14.574151  1200 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:14.574221  1199 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:14.574298  1202 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:14.574312   873 server_base.cc:1061] running on GCE node
I20260812 06:20:14.574524   873 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:14.574563   873 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:14.574575   873 hybrid_clock.cc:648] HybridClock initialized: now 1786515614574576 us; error 0 us; skew 500 ppm
I20260812 06:20:14.575349   873 webserver.cc:533] Webserver started at http://127.0.218.126:34151/ using document root <none> and password file <none>
I20260812 06:20:14.575505   873 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:14.575552   873 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:14.575626   873 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:14.576150   873 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/master-0-root/instance:
uuid: "e7826aa0d3e946c5b07c879f7356ebea"
format_stamp: "Formatted at 2026-08-12 06:20:14 on dist-test-slave-1l3l"
I20260812 06:20:14.577657   873 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:14.578527  1209 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:14.578730   873 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:14.578806   873 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/master-0-root
uuid: "e7826aa0d3e946c5b07c879f7356ebea"
format_stamp: "Formatted at 2026-08-12 06:20:14 on dist-test-slave-1l3l"
I20260812 06:20:14.578876   873 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:14.592442   873 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:14.592921   873 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:14.596896   873 rpc_server.cc:307] RPC server started. Bound to: 127.0.218.126:35867
I20260812 06:20:14.612449  1295 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.218.126:35867 every 8 connection(s)
I20260812 06:20:14.612944  1297 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:14.614745  1297 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea: Bootstrap starting.
I20260812 06:20:14.615545  1297 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:14.616603  1297 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea: No bootstrap required, opened a new log
I20260812 06:20:14.616994  1297 raft_consensus.cc:359] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e7826aa0d3e946c5b07c879f7356ebea" member_type: VOTER }
I20260812 06:20:14.617084  1297 raft_consensus.cc:385] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:14.617115  1297 raft_consensus.cc:740] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e7826aa0d3e946c5b07c879f7356ebea, State: Initialized, Role: FOLLOWER
I20260812 06:20:14.617254  1297 consensus_queue.cc:260] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 0, Majority size: -1, State: 0, Mode: NON_LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e7826aa0d3e946c5b07c879f7356ebea" member_type: VOTER }
I20260812 06:20:14.617323  1297 raft_consensus.cc:399] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:14.617362  1297 raft_consensus.cc:493] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:14.617409  1297 raft_consensus.cc:3060] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:14.618098  1297 raft_consensus.cc:515] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e7826aa0d3e946c5b07c879f7356ebea" member_type: VOTER }
I20260812 06:20:14.618227  1297 leader_election.cc:304] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea [CANDIDATE]: Term 1 election: Election decided. Result: candidate won. Election summary: received 1 responses out of 1 voters: 1 yes votes; 0 no votes. yes voters: e7826aa0d3e946c5b07c879f7356ebea; no voters: 
I20260812 06:20:14.618405  1297 leader_election.cc:290] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:14.618535  1301 raft_consensus.cc:2804] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:14.618724  1301 raft_consensus.cc:697] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea [term 1 LEADER]: Becoming Leader. State: Replica: e7826aa0d3e946c5b07c879f7356ebea, State: Running, Role: LEADER
I20260812 06:20:14.618882  1297 sys_catalog.cc:565] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:14.618866  1301 consensus_queue.cc:237] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea [LEADER]: Queue going to LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 1, Majority size: 1, State: 0, Mode: LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e7826aa0d3e946c5b07c879f7356ebea" member_type: VOTER }
I20260812 06:20:14.619315  1304 sys_catalog.cc:455] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea [sys.catalog]: SysCatalogTable state changed. Reason: New leader e7826aa0d3e946c5b07c879f7356ebea. Latest consensus state: current_term: 1 leader_uuid: "e7826aa0d3e946c5b07c879f7356ebea" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e7826aa0d3e946c5b07c879f7356ebea" member_type: VOTER } }
I20260812 06:20:14.619302  1302 sys_catalog.cc:455] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "e7826aa0d3e946c5b07c879f7356ebea" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e7826aa0d3e946c5b07c879f7356ebea" member_type: VOTER } }
I20260812 06:20:14.619454  1304 sys_catalog.cc:458] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:14.619509  1302 sys_catalog.cc:458] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:14.620052  1311 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:14.620795  1311 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:14.620949   873 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:14.622581  1311 catalog_manager.cc:1383] Generated new cluster ID: 2d4ab7e92ac746a4ac891f0debb0c293
I20260812 06:20:14.622640  1311 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:14.640311  1311 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:14.640902  1311 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:14.646872  1311 catalog_manager.cc:6092] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea: Generated new TSK 0
I20260812 06:20:14.647047  1311 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:14.653118   873 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:14.654982  1335 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:14.655071  1336 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:14.655071  1338 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:14.655249   873 server_base.cc:1061] running on GCE node
I20260812 06:20:14.655422   873 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:14.655478   873 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:14.655512   873 hybrid_clock.cc:648] HybridClock initialized: now 1786515614655512 us; error 0 us; skew 500 ppm
I20260812 06:20:14.656360   873 webserver.cc:533] Webserver started at http://127.0.218.65:42935/ using document root <none> and password file <none>
I20260812 06:20:14.656534   873 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:14.656589   873 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:14.656663   873 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:14.657037   873 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/instance:
uuid: "7cd6ee146deb41f18f714c0fefd6ab1a"
format_stamp: "Formatted at 2026-08-12 06:20:14 on dist-test-slave-1l3l"
I20260812 06:20:14.658422   873 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:14.659263  1344 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:14.659461   873 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:14.659528   873 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root
uuid: "7cd6ee146deb41f18f714c0fefd6ab1a"
format_stamp: "Formatted at 2026-08-12 06:20:14 on dist-test-slave-1l3l"
I20260812 06:20:14.659593   873 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:14.666163   873 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:14.666476   873 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:14.666738   873 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:14.667176   873 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:14.667215   873 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:14.667254   873 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:14.667282   873 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:14.671223   873 rpc_server.cc:307] RPC server started. Bound to: 127.0.218.65:42355
I20260812 06:20:14.671247  1465 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.218.65:42355 every 8 connection(s)
I20260812 06:20:14.678982  1467 heartbeater.cc:344] Connected to a master server at 127.0.218.126:35867
I20260812 06:20:14.679085  1467 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:14.679314  1467 heartbeater.cc:507] Master 127.0.218.126:35867 requested a full tablet report, sending...
I20260812 06:20:14.679953  1237 ts_manager.cc:194] Registered new tserver with Master: 7cd6ee146deb41f18f714c0fefd6ab1a (127.0.218.65:42355)
I20260812 06:20:14.680331   873 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008715054s
I20260812 06:20:14.680711  1237 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:40962
I20260812 06:20:14.686683  1237 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:40976:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:14.694578  1392 tablet_service.cc:1511] Processing CreateTablet for tablet 82698a953b494c429834b8b2372bee6f (DEFAULT_TABLE table=heavy-update-compaction-test [id=c3524386ca764932a57cc244b92079b5]), partition=
I20260812 06:20:14.694825  1392 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 82698a953b494c429834b8b2372bee6f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:14.696741  1493 tablet_bootstrap.cc:492] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Bootstrap starting.
I20260812 06:20:14.697683  1493 tablet_bootstrap.cc:654] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:14.698606  1493 tablet_bootstrap.cc:492] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: No bootstrap required, opened a new log
I20260812 06:20:14.698678  1493 ts_tablet_manager.cc:1403] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:14.699040  1493 raft_consensus.cc:359] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7cd6ee146deb41f18f714c0fefd6ab1a" member_type: VOTER last_known_addr { host: "127.0.218.65" port: 42355 } }
I20260812 06:20:14.699121  1493 raft_consensus.cc:385] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:14.699147  1493 raft_consensus.cc:740] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7cd6ee146deb41f18f714c0fefd6ab1a, State: Initialized, Role: FOLLOWER
I20260812 06:20:14.699237  1493 consensus_queue.cc:260] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 0, Majority size: -1, State: 0, Mode: NON_LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7cd6ee146deb41f18f714c0fefd6ab1a" member_type: VOTER last_known_addr { host: "127.0.218.65" port: 42355 } }
I20260812 06:20:14.699294  1493 raft_consensus.cc:399] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:14.699321  1493 raft_consensus.cc:493] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:14.699354  1493 raft_consensus.cc:3060] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:14.700138  1493 raft_consensus.cc:515] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7cd6ee146deb41f18f714c0fefd6ab1a" member_type: VOTER last_known_addr { host: "127.0.218.65" port: 42355 } }
I20260812 06:20:14.700273  1493 leader_election.cc:304] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a [CANDIDATE]: Term 1 election: Election decided. Result: candidate won. Election summary: received 1 responses out of 1 voters: 1 yes votes; 0 no votes. yes voters: 7cd6ee146deb41f18f714c0fefd6ab1a; no voters: 
I20260812 06:20:14.700460  1493 leader_election.cc:290] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:14.700558  1496 raft_consensus.cc:2804] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:14.700748  1493 ts_tablet_manager.cc:1434] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:14.700790  1496 raft_consensus.cc:697] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a [term 1 LEADER]: Becoming Leader. State: Replica: 7cd6ee146deb41f18f714c0fefd6ab1a, State: Running, Role: LEADER
I20260812 06:20:14.700781  1467 heartbeater.cc:499] Master 127.0.218.126:35867 was elected leader, sending a full tablet report...
I20260812 06:20:14.700971  1496 consensus_queue.cc:237] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a [LEADER]: Queue going to LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 1, Majority size: 1, State: 0, Mode: LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7cd6ee146deb41f18f714c0fefd6ab1a" member_type: VOTER last_known_addr { host: "127.0.218.65" port: 42355 } }
I20260812 06:20:14.702158  1237 catalog_manager.cc:5719] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a reported cstate change: term changed from 0 to 1, leader changed from <none> to 7cd6ee146deb41f18f714c0fefd6ab1a (127.0.218.65). New cstate: current_term: 1 leader_uuid: "7cd6ee146deb41f18f714c0fefd6ab1a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7cd6ee146deb41f18f714c0fefd6ab1a" member_type: VOTER last_known_addr { host: "127.0.218.65" port: 42355 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:14.755287   873 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.014s	sys 0.008s
I20260812 06:20:14.922133  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushMRSOp(82698a953b494c429834b8b2372bee6f): perf score=23.023690
I20260812 06:20:15.068567  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushMRSOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.146s	user 0.110s	sys 0.035s Metrics: {"bytes_written":12348514,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":251,"dirs.run_wall_time_us":998,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36654,"lbm_writes_lt_1ms":858,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1505}
I20260812 06:20:15.069228  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling LogGCOp(82698a953b494c429834b8b2372bee6f): free 20743880 bytes of WAL
I20260812 06:20:15.069449  1354 log_reader.cc:385] T 82698a953b494c429834b8b2372bee6f: removed 2 log segments from log reader
I20260812 06:20:15.069496  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000001 (ops 1-6)
I20260812 06:20:15.069526  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000002 (ops 7-11)
I20260812 06:20:15.073638  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: LogGCOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:15.073988  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling UndoDeltaBlockGCOp(82698a953b494c429834b8b2372bee6f): 20513818 bytes on disk
I20260812 06:20:15.074491  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: UndoDeltaBlockGCOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:20:15.074899  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=2.188937
I20260812 06:20:15.087473  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4061634,"delete_count":0,"lbm_write_time_us":4572,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":495}
I20260812 06:20:15.087935  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f): perf score=1.000000
I20260812 06:20:15.247601  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.159s	user 0.099s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":497,"lbm_read_time_us":9487,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24338,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3200,"thread_start_us":301,"threads_started":5,"update_count":2000}
I20260812 06:20:15.248217  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=14.095187
I20260812 06:20:15.290081  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.042s	user 0.024s	sys 0.012s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17035,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:15.290509  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=2.188937
I20260812 06:20:15.301254  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3708,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.301780  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f): perf score=1.000000
I20260812 06:20:15.467278  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.165s	user 0.106s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":182,"lbm_read_time_us":9567,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30425,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2500}
I20260812 06:20:15.467908  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=14.095187
I20260812 06:20:15.509606  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.041s	user 0.014s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17407,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:15.510066  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=2.188937
I20260812 06:20:15.519984  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3670,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.520597  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f): perf score=1.000000
I20260812 06:20:15.660542  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.140s	user 0.119s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":626,"lbm_read_time_us":9917,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28588,"lbm_writes_lt_1ms":543,"mutex_wait_us":312,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2500}
I20260812 06:20:15.661044  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=11.118625
I20260812 06:20:15.690073  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.029s	user 0.019s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":12220,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:15.690568  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=2.188937
I20260812 06:20:15.704826  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5390,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:15.705345  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f): perf score=1.000000
I20260812 06:20:15.823875  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.118s	user 0.092s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713264,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1328,"lbm_read_time_us":7794,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20880,"lbm_writes_lt_1ms":443,"mutex_wait_us":858,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:15.824376  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=10.126437
I20260812 06:20:15.873790  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.049s	user 0.024s	sys 0.023s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15755,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.874425  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=2.188937
I20260812 06:20:15.888690  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.014s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5239,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.889115  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f): perf score=1.000000
I20260812 06:20:16.044795  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.156s	user 0.102s	sys 0.050s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":616,"lbm_read_time_us":9592,"lbm_reads_lt_1ms":468,"lbm_write_time_us":24627,"lbm_writes_lt_1ms":443,"mutex_wait_us":252,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:20:16.045403  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=11.118625
I20260812 06:20:16.076328  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.031s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12300,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:16.076838  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=2.188937
I20260812 06:20:16.101176  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.024s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5277,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:16.101666  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=2.188937
I20260812 06:20:16.111483  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3577,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.112170  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f): perf score=1.000000
I20260812 06:20:16.282531  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.170s	user 0.115s	sys 0.046s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815793,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":231,"lbm_read_time_us":10863,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28013,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:20:16.283026  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=14.095187
I20260812 06:20:16.327129  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.044s	user 0.031s	sys 0.007s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18596,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.327630  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=2.188937
I20260812 06:20:16.337677  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3619,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.338346  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushMRSOp(82698a953b494c429834b8b2372bee6f): perf score=1.000000
I20260812 06:20:16.370659  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushMRSOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.032s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1316413,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":253,"dirs.run_wall_time_us":1361,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1630,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32,"spinlock_wait_cycles":15744}
I20260812 06:20:16.371332  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling LogGCOp(82698a953b494c429834b8b2372bee6f): free 133024309 bytes of WAL
I20260812 06:20:16.371569  1354 log_reader.cc:385] T 82698a953b494c429834b8b2372bee6f: removed 13 log segments from log reader
I20260812 06:20:16.371618  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000003 (ops 12-16)
I20260812 06:20:16.371656  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000004 (ops 17-21)
I20260812 06:20:16.371688  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000005 (ops 22-26)
I20260812 06:20:16.371744  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000006 (ops 27-31)
I20260812 06:20:16.371778  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000007 (ops 32-36)
I20260812 06:20:16.371817  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000008 (ops 37-40)
I20260812 06:20:16.371847  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000009 (ops 41-45)
I20260812 06:20:16.371877  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000010 (ops 46-50)
I20260812 06:20:16.371907  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000011 (ops 51-55)
I20260812 06:20:16.371937  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000012 (ops 56-60)
I20260812 06:20:16.371968  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000013 (ops 61-65)
I20260812 06:20:16.371997  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000014 (ops 66-70)
I20260812 06:20:16.372027  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000015 (ops 71-75)
I20260812 06:20:16.398782  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: LogGCOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.027s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:20:16.399243  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling UndoDeltaBlockGCOp(82698a953b494c429834b8b2372bee6f): 493 bytes on disk
I20260812 06:20:16.399860  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: UndoDeltaBlockGCOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:20:16.400422  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=4.173312
I20260812 06:20:16.422073  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.021s	user 0.017s	sys 0.003s Metrics: {"bytes_written":6235917,"delete_count":0,"lbm_write_time_us":9245,"lbm_writes_lt_1ms":155,"reinsert_count":0,"update_count":760}
I20260812 06:20:16.422498  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=1.000000
I20260812 06:20:16.428224  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {"bytes_written":1969352,"delete_count":0,"lbm_write_time_us":1826,"lbm_writes_lt_1ms":51,"reinsert_count":0,"update_count":240}
I20260812 06:20:16.428606  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f): perf score=1.000000
I20260812 06:20:16.658619  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.230s	user 0.133s	sys 0.087s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":177,"lbm_read_time_us":14174,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36292,"lbm_writes_lt_1ms":743,"mutex_wait_us":79,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:20:16.659183  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=18.063937
I20260812 06:20:16.724960  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.065s	user 0.049s	sys 0.013s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":26289,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:16.725435  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=2.188937
I20260812 06:20:16.735091  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3573,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.735581  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f): perf score=1.000000
I20260812 06:20:16.944950  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.209s	user 0.125s	sys 0.080s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1287,"lbm_read_time_us":14113,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32305,"lbm_writes_lt_1ms":643,"mutex_wait_us":460,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":3000}
I20260812 06:20:16.945600  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=16.079562
I20260812 06:20:16.990633  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.045s	user 0.019s	sys 0.021s Metrics: {"bytes_written":18173938,"delete_count":0,"lbm_write_time_us":19049,"lbm_writes_lt_1ms":446,"reinsert_count":0,"update_count":2215}
I20260812 06:20:16.991161  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=1.196750
I20260812 06:20:17.000771  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":2789863,"delete_count":0,"lbm_write_time_us":3550,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:20:17.001209  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=2.188937
I20260812 06:20:17.010010  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.009s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3651380,"delete_count":0,"lbm_write_time_us":3338,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":445}
I20260812 06:20:17.010389  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f): perf score=1.000000
I20260812 06:20:17.211561  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.201s	user 0.140s	sys 0.060s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918176,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":245,"lbm_read_time_us":14784,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32425,"lbm_writes_lt_1ms":643,"mutex_wait_us":62,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":3000}
I20260812 06:20:17.216101  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=15.087375
I20260812 06:20:17.259516  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.043s	user 0.031s	sys 0.008s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":18714,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:17.260121  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=2.188937
I20260812 06:20:17.277968  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.018s	user 0.009s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4465,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:17.278414  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=2.188937
I20260812 06:20:17.288477  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3855,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.288883  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f): perf score=1.000000
I20260812 06:20:17.484784  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.196s	user 0.153s	sys 0.041s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918202,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":403,"lbm_read_time_us":14185,"lbm_reads_lt_1ms":673,"lbm_write_time_us":30351,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":3000}
I20260812 06:20:17.485462  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=15.087375
I20260812 06:20:17.532131  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.046s	user 0.026s	sys 0.020s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":20826,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:17.532684  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=2.188937
I20260812 06:20:17.557523  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.025s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4122,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:17.558041  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=2.188937
I20260812 06:20:17.573551  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5544,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.574177  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f): perf score=1.000000
I20260812 06:20:17.775802  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.201s	user 0.138s	sys 0.063s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918201,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":602,"lbm_read_time_us":14484,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33319,"lbm_writes_lt_1ms":643,"mutex_wait_us":1,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:20:17.776522  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=14.095187
I20260812 06:20:17.824141  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.047s	user 0.033s	sys 0.014s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20557,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.824705  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=2.188937
I20260812 06:20:17.838227  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5355,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.838696  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushMRSOp(82698a953b494c429834b8b2372bee6f): perf score=1.000000
I20260812 06:20:17.867935  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushMRSOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.029s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1275446,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":1378,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1574,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:17.869132  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling LogGCOp(82698a953b494c429834b8b2372bee6f): free 124710398 bytes of WAL
I20260812 06:20:17.869421  1354 log_reader.cc:385] T 82698a953b494c429834b8b2372bee6f: removed 12 log segments from log reader
I20260812 06:20:17.869474  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000016 (ops 76-80)
I20260812 06:20:17.869515  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000017 (ops 81-85)
I20260812 06:20:17.869539  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000018 (ops 86-90)
I20260812 06:20:17.869562  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000019 (ops 91-95)
I20260812 06:20:17.869591  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000020 (ops 96-100)
I20260812 06:20:17.869614  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000021 (ops 101-105)
I20260812 06:20:17.869635  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000022 (ops 106-110)
I20260812 06:20:17.869664  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000023 (ops 111-115)
I20260812 06:20:17.869690  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000024 (ops 116-120)
I20260812 06:20:17.869711  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000025 (ops 121-125)
I20260812 06:20:17.869732  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000026 (ops 126-130)
I20260812 06:20:17.869753  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000027 (ops 131-135)
I20260812 06:20:17.892041  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: LogGCOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.023s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:20:17.892572  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling UndoDeltaBlockGCOp(82698a953b494c429834b8b2372bee6f): 482 bytes on disk
I20260812 06:20:17.893162  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: UndoDeltaBlockGCOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:20:17.893751  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=4.173312
I20260812 06:20:17.911907  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.018s	user 0.010s	sys 0.008s Metrics: {"bytes_written":6153869,"delete_count":0,"lbm_write_time_us":7223,"lbm_writes_lt_1ms":153,"reinsert_count":0,"update_count":750}
I20260812 06:20:17.912389  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling LogGCOp(82698a953b494c429834b8b2372bee6f): free 12017954 bytes of WAL
I20260812 06:20:17.912606  1354 log_reader.cc:385] T 82698a953b494c429834b8b2372bee6f: removed 1 log segments from log reader
I20260812 06:20:17.912662  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000028 (ops 136-140)
I20260812 06:20:17.915607  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: LogGCOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:17.916252  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=1.000000
I20260812 06:20:17.925987  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.010s	user 0.007s	sys 0.000s Metrics: {"bytes_written":2051402,"delete_count":0,"lbm_write_time_us":2948,"lbm_writes_lt_1ms":53,"reinsert_count":0,"update_count":250}
I20260812 06:20:17.926534  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f): perf score=1.000000
I20260812 06:20:18.142989  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.216s	user 0.130s	sys 0.080s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020693,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":6063,"lbm_read_time_us":15253,"lbm_reads_lt_1ms":774,"lbm_write_time_us":34840,"lbm_writes_lt_1ms":743,"mutex_wait_us":2049,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6784,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:20:18.143525  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=18.063937
I20260812 06:20:18.197876  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.054s	user 0.025s	sys 0.027s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":23817,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:18.198408  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=2.188937
I20260812 06:20:18.213486  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6088,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.214073  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f): perf score=1.000000
I20260812 06:20:18.371378  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.157s	user 0.133s	sys 0.024s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":177,"lbm_read_time_us":11544,"lbm_reads_lt_1ms":664,"lbm_write_time_us":32392,"lbm_writes_lt_1ms":643,"mutex_wait_us":46,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":60416,"update_count":3000}
I20260812 06:20:18.371909  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=14.095187
I20260812 06:20:18.416240  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.044s	user 0.031s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19545,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:18.416800  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=2.188937
I20260812 06:20:18.429373  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4972,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.429796  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f): perf score=1.000000
I20260812 06:20:18.576213  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.146s	user 0.085s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":137,"lbm_read_time_us":9887,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26145,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":48256,"update_count":2500}
I20260812 06:20:18.577010  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=14.095187
I20260812 06:20:18.626276  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.049s	user 0.026s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22365,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:18.626740  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f): perf score=1.000000
I20260812 06:20:18.771679  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.145s	user 0.105s	sys 0.032s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":760,"lbm_read_time_us":8548,"lbm_reads_lt_1ms":467,"lbm_write_time_us":22151,"lbm_writes_lt_1ms":443,"mutex_wait_us":288,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:20:18.772356  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=14.095187
I20260812 06:20:18.816345  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.044s	user 0.021s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17842,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:18.816866  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=2.188937
I20260812 06:20:18.828123  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4034,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.828759  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f): perf score=1.000000
I20260812 06:20:18.996316  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.167s	user 0.091s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":248,"lbm_read_time_us":10471,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25099,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:18.996790  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=14.095187
I20260812 06:20:19.044771  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.048s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20252,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.045331  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=2.188937
I20260812 06:20:19.060947  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5922,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.061453  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f): perf score=1.000000
I20260812 06:20:19.213407  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: MajorDeltaCompactionOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.152s	user 0.111s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":654,"lbm_read_time_us":10010,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26653,"lbm_writes_lt_1ms":543,"mutex_wait_us":299,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2500}
I20260812 06:20:19.213966  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=14.095187
I20260812 06:20:19.262450   873 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.507s	user 1.650s	sys 0.175s
I20260812 06:20:19.265463  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.051s	user 0.025s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20466,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.265965  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f): perf score=2.188937
I20260812 06:20:19.275362  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushDeltaMemStoresOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3873,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":500}
I20260812 06:20:19.275784  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling FlushMRSOp(82698a953b494c429834b8b2372bee6f): perf score=1.000000
I20260812 06:20:19.301822  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: FlushMRSOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.026s	user 0.020s	sys 0.004s Metrics: {"bytes_written":1316415,"cfile_init":1,"dirs.queue_time_us":90,"dirs.run_cpu_time_us":227,"dirs.run_wall_time_us":1428,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1446,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:19.302588  1468 maintenance_manager.cc:419] P 7cd6ee146deb41f18f714c0fefd6ab1a: Scheduling LogGCOp(82698a953b494c429834b8b2372bee6f): free 120553644 bytes of WAL
I20260812 06:20:19.302825  1354 log_reader.cc:385] T 82698a953b494c429834b8b2372bee6f: removed 12 log segments from log reader
I20260812 06:20:19.302873  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000029 (ops 141-145)
I20260812 06:20:19.302913  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000030 (ops 146-150)
I20260812 06:20:19.302946  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000031 (ops 151-155)
I20260812 06:20:19.302978  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000032 (ops 156-160)
I20260812 06:20:19.303009  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000033 (ops 161-164)
I20260812 06:20:19.303040  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000034 (ops 165-169)
I20260812 06:20:19.303071  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000035 (ops 170-174)
I20260812 06:20:19.303102  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000036 (ops 175-179)
I20260812 06:20:19.303133  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000037 (ops 180-184)
I20260812 06:20:19.303164  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000038 (ops 185-189)
I20260812 06:20:19.303193  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000039 (ops 190-194)
I20260812 06:20:19.303223  1354 log.cc:1079] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: Deleting log segment in path: /tmp/dist-test-task9gPSvt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609385990-873-0/minicluster-data/ts-0-root/wals/82698a953b494c429834b8b2372bee6f/wal-000000040 (ops 195-198)
I20260812 06:20:19.303537   873 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.041s	user 0.001s	sys 0.000s
I20260812 06:20:19.303958   873 tablet_server.cc:179] TabletServer@127.0.218.65:0 shutting down...
I20260812 06:20:19.324427  1354 maintenance_manager.cc:643] P 7cd6ee146deb41f18f714c0fefd6ab1a: LogGCOp(82698a953b494c429834b8b2372bee6f) complete. Timing: real 0.022s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:20:19.324838   873 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:19.325054   873 tablet_replica.cc:333] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a: stopping tablet replica
I20260812 06:20:19.325184   873 raft_consensus.cc:2243] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:19.325310   873 raft_consensus.cc:2272] T 82698a953b494c429834b8b2372bee6f P 7cd6ee146deb41f18f714c0fefd6ab1a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:19.328042   873 tablet_server.cc:196] TabletServer@127.0.218.65:0 shutdown complete.
I20260812 06:20:19.330363   873 master.cc:562] Master@127.0.218.126:35867 shutting down...
I20260812 06:20:19.333123   873 raft_consensus.cc:2243] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:19.333250   873 raft_consensus.cc:2272] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:19.333315   873 tablet_replica.cc:333] T 00000000000000000000000000000000 P e7826aa0d3e946c5b07c879f7356ebea: stopping tablet replica
I20260812 06:20:19.345142   873 master.cc:584] Master@127.0.218.126:35867 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4846 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10022 ms total)

[----------] Global test environment tear-down
[==========] 2 tests from 1 test suite ran. (10022 ms total)
[  PASSED  ] 2 tests.
