[==========] 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:16:56.294395 28896 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.28.56.62:43019
I20260812 06:16:56.295632 28896 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:16:56.296291 28896 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:56.303406 28901 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:16:56.303493 28896 server_base.cc:1061] running on GCE node
W20260812 06:16:56.303422 28906 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:16:56.303587 28903 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:16:56.304056 28896 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:56.304181 28896 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:16:56.304239 28896 hybrid_clock.cc:648] HybridClock initialized: now 1786515416304236 us; error 0 us; skew 500 ppm
I20260812 06:16:56.306561 28896 webserver.cc:533] Webserver started at http://127.28.56.62:45501/ using document root <none> and password file <none>
I20260812 06:16:56.307565 28896 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:56.307680 28896 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:56.307943 28896 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:56.309931 28896 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/master-0-root/instance:
uuid: "f275f27b53b6470996eadd214af5169d"
format_stamp: "Formatted at 2026-08-12 06:16:56 on dist-test-slave-drl0"
I20260812 06:16:56.314172 28896 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.006s	sys 0.000s
I20260812 06:16:56.316720 28913 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:16:56.318013 28896 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.001s	sys 0.000s
I20260812 06:16:56.318161 28896 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/master-0-root
uuid: "f275f27b53b6470996eadd214af5169d"
format_stamp: "Formatted at 2026-08-12 06:16:56 on dist-test-slave-drl0"
I20260812 06:16:56.318279 28896 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-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:16:56.335201 28896 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:56.336025 28896 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:16:56.336393 28896 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:56.345196 28896 rpc_server.cc:307] RPC server started. Bound to: 127.28.56.62:43019
I20260812 06:16:56.345270 28983 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.56.62:43019 every 8 connection(s)
I20260812 06:16:56.348265 28985 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:16:56.355114 28985 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d: Bootstrap starting.
I20260812 06:16:56.358371 28985 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:56.359750 28985 log.cc:826] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:56.361768 28985 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d: No bootstrap required, opened a new log
I20260812 06:16:56.365011 28985 raft_consensus.cc:359] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f275f27b53b6470996eadd214af5169d" member_type: VOTER }
I20260812 06:16:56.365202 28985 raft_consensus.cc:385] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:56.365283 28985 raft_consensus.cc:740] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f275f27b53b6470996eadd214af5169d, State: Initialized, Role: FOLLOWER
I20260812 06:16:56.365990 28985 consensus_queue.cc:260] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d [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: "f275f27b53b6470996eadd214af5169d" member_type: VOTER }
I20260812 06:16:56.366144 28985 raft_consensus.cc:399] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:56.366255 28985 raft_consensus.cc:493] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:56.366426 28985 raft_consensus.cc:3060] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:56.367372 28985 raft_consensus.cc:515] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f275f27b53b6470996eadd214af5169d" member_type: VOTER }
I20260812 06:16:56.367852 28985 leader_election.cc:304] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d [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: f275f27b53b6470996eadd214af5169d; no voters: 
I20260812 06:16:56.368191 28985 leader_election.cc:290] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:56.368515 28996 raft_consensus.cc:2804] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:56.368896 28996 raft_consensus.cc:697] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d [term 1 LEADER]: Becoming Leader. State: Replica: f275f27b53b6470996eadd214af5169d, State: Running, Role: LEADER
I20260812 06:16:56.369491 28985 sys_catalog.cc:565] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:56.369445 28996 consensus_queue.cc:237] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d [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: "f275f27b53b6470996eadd214af5169d" member_type: VOTER }
I20260812 06:16:56.371721 28998 sys_catalog.cc:455] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d [sys.catalog]: SysCatalogTable state changed. Reason: New leader f275f27b53b6470996eadd214af5169d. Latest consensus state: current_term: 1 leader_uuid: "f275f27b53b6470996eadd214af5169d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f275f27b53b6470996eadd214af5169d" member_type: VOTER } }
I20260812 06:16:56.371750 28997 sys_catalog.cc:455] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "f275f27b53b6470996eadd214af5169d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f275f27b53b6470996eadd214af5169d" member_type: VOTER } }
I20260812 06:16:56.371860 28998 sys_catalog.cc:458] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:56.371860 28997 sys_catalog.cc:458] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:56.372112 28896 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:56.372273 29018 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:56.374562 29018 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:56.379814 29018 catalog_manager.cc:1383] Generated new cluster ID: 03ae8ea075b9464893918af88f960d9d
I20260812 06:16:56.379887 29018 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:56.392095 29018 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:56.393182 29018 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:56.399807 29018 catalog_manager.cc:6092] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d: Generated new TSK 0
I20260812 06:16:56.400542 29018 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:56.404774 28896 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:56.407833 29033 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:16:56.407859 29030 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:16:56.407897 29029 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:16:56.408274 28896 server_base.cc:1061] running on GCE node
I20260812 06:16:56.408453 28896 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:56.408514 28896 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:16:56.408550 28896 hybrid_clock.cc:648] HybridClock initialized: now 1786515416408550 us; error 0 us; skew 500 ppm
I20260812 06:16:56.409503 28896 webserver.cc:533] Webserver started at http://127.28.56.1:42043/ using document root <none> and password file <none>
I20260812 06:16:56.409705 28896 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:56.409780 28896 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:56.409863 28896 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:56.410244 28896 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/instance:
uuid: "262bef4fc5ed459ebd866eb75b65adee"
format_stamp: "Formatted at 2026-08-12 06:16:56 on dist-test-slave-drl0"
I20260812 06:16:56.411861 28896 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:56.412961 29038 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:16:56.413357 28896 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:56.413427 28896 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root
uuid: "262bef4fc5ed459ebd866eb75b65adee"
format_stamp: "Formatted at 2026-08-12 06:16:56 on dist-test-slave-drl0"
I20260812 06:16:56.413520 28896 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-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:16:56.437366 28896 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:56.437886 28896 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:56.438428 28896 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:56.439406 28896 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:56.439457 28896 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:56.439524 28896 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:56.439564 28896 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:56.447355 28896 rpc_server.cc:307] RPC server started. Bound to: 127.28.56.1:36399
I20260812 06:16:56.447391 29133 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.56.1:36399 every 8 connection(s)
I20260812 06:16:56.463137 29135 heartbeater.cc:344] Connected to a master server at 127.28.56.62:43019
I20260812 06:16:56.463610 29135 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:56.464869 29135 heartbeater.cc:507] Master 127.28.56.62:43019 requested a full tablet report, sending...
I20260812 06:16:56.467309 28936 ts_manager.cc:194] Registered new tserver with Master: 262bef4fc5ed459ebd866eb75b65adee (127.28.56.1:36399)
I20260812 06:16:56.467370 28896 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.019326737s
I20260812 06:16:56.469115 28936 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:48586
I20260812 06:16:56.478618 28936 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:48590:
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:16:56.493319 29083 tablet_service.cc:1511] Processing CreateTablet for tablet 2397b268f65e4d32ac95bdeb7c389026 (DEFAULT_TABLE table=heavy-update-compaction-test [id=5191cf65391b4a789f75bcd4c6b8f16b]), partition=
I20260812 06:16:56.493772 29083 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 2397b268f65e4d32ac95bdeb7c389026. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:56.496147 29149 tablet_bootstrap.cc:492] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Bootstrap starting.
I20260812 06:16:56.497108 29149 tablet_bootstrap.cc:654] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:56.498106 29149 tablet_bootstrap.cc:492] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: No bootstrap required, opened a new log
I20260812 06:16:56.498229 29149 ts_tablet_manager.cc:1403] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:56.498806 29149 raft_consensus.cc:359] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "262bef4fc5ed459ebd866eb75b65adee" member_type: VOTER last_known_addr { host: "127.28.56.1" port: 36399 } }
I20260812 06:16:56.499142 29149 raft_consensus.cc:385] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:56.499225 29149 raft_consensus.cc:740] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 262bef4fc5ed459ebd866eb75b65adee, State: Initialized, Role: FOLLOWER
I20260812 06:16:56.499385 29149 consensus_queue.cc:260] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee [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: "262bef4fc5ed459ebd866eb75b65adee" member_type: VOTER last_known_addr { host: "127.28.56.1" port: 36399 } }
I20260812 06:16:56.499497 29149 raft_consensus.cc:399] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:56.499547 29149 raft_consensus.cc:493] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:56.499603 29149 raft_consensus.cc:3060] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:56.500315 29149 raft_consensus.cc:515] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "262bef4fc5ed459ebd866eb75b65adee" member_type: VOTER last_known_addr { host: "127.28.56.1" port: 36399 } }
I20260812 06:16:56.500469 29149 leader_election.cc:304] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee [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: 262bef4fc5ed459ebd866eb75b65adee; no voters: 
I20260812 06:16:56.500698 29149 leader_election.cc:290] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:56.500803 29154 raft_consensus.cc:2804] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:56.501084 29149 ts_tablet_manager.cc:1434] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:56.501084 29154 raft_consensus.cc:697] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee [term 1 LEADER]: Becoming Leader. State: Replica: 262bef4fc5ed459ebd866eb75b65adee, State: Running, Role: LEADER
I20260812 06:16:56.501246 29135 heartbeater.cc:499] Master 127.28.56.62:43019 was elected leader, sending a full tablet report...
I20260812 06:16:56.501458 29154 consensus_queue.cc:237] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee [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: "262bef4fc5ed459ebd866eb75b65adee" member_type: VOTER last_known_addr { host: "127.28.56.1" port: 36399 } }
I20260812 06:16:56.504030 28936 catalog_manager.cc:5719] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee reported cstate change: term changed from 0 to 1, leader changed from <none> to 262bef4fc5ed459ebd866eb75b65adee (127.28.56.1). New cstate: current_term: 1 leader_uuid: "262bef4fc5ed459ebd866eb75b65adee" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "262bef4fc5ed459ebd866eb75b65adee" member_type: VOTER last_known_addr { host: "127.28.56.1" port: 36399 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:56.573390 28896 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.063s	user 0.018s	sys 0.012s
I20260812 06:16:56.699185 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushMRSOp(2397b268f65e4d32ac95bdeb7c389026): perf score=15.086190
I20260812 06:16:56.874244 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushMRSOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.175s	user 0.134s	sys 0.033s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":199,"delete_count":0,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":189,"dirs.run_wall_time_us":767,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41909,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":110,"threads_started":1,"update_count":1500}
I20260812 06:16:56.875366 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=3.181125
I20260812 06:16:56.893828 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.018s	user 0.003s	sys 0.013s Metrics: {"bytes_written":5087239,"delete_count":0,"lbm_write_time_us":8265,"lbm_writes_lt_1ms":127,"reinsert_count":0,"update_count":620}
I20260812 06:16:56.894471 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling LogGCOp(2397b268f65e4d32ac95bdeb7c389026): free 11976772 bytes of WAL
I20260812 06:16:56.894872 29047 log_reader.cc:385] T 2397b268f65e4d32ac95bdeb7c389026: removed 1 log segments from log reader
I20260812 06:16:56.894980 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000001 (ops 1-6)
I20260812 06:16:56.898586 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: LogGCOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.004s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:16:56.898910 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=1.196750
I20260812 06:16:56.919798 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.021s	user 0.008s	sys 0.011s Metrics: {"bytes_written":3118055,"delete_count":0,"lbm_write_time_us":5510,"lbm_writes_lt_1ms":79,"reinsert_count":0,"update_count":380}
I20260812 06:16:56.920578 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026): perf score=1.000000
I20260812 06:16:57.124909 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.204s	user 0.139s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733819,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":853,"lbm_read_time_us":16370,"lbm_reads_lt_1ms":565,"lbm_write_time_us":32929,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8960,"thread_start_us":346,"threads_started":5,"update_count":2500}
I20260812 06:16:57.125523 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=14.095187
I20260812 06:16:57.175570 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.050s	user 0.035s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20839,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:57.176046 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling UndoDeltaBlockGCOp(2397b268f65e4d32ac95bdeb7c389026): 12308960 bytes on disk
I20260812 06:16:57.176508 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: UndoDeltaBlockGCOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:16:57.176909 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=2.188937
I20260812 06:16:57.188746 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4212,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.189564 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026): perf score=1.000000
I20260812 06:16:57.368321 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.178s	user 0.126s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":632,"lbm_read_time_us":11622,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33499,"lbm_writes_lt_1ms":543,"mutex_wait_us":249,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2500}
I20260812 06:16:57.368999 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=14.095187
I20260812 06:16:57.419046 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.050s	user 0.026s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19447,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:57.419598 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=2.188937
I20260812 06:16:57.436313 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.016s	user 0.005s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6448,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.436813 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026): perf score=1.000000
I20260812 06:16:57.601406 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.164s	user 0.142s	sys 0.016s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1763,"lbm_read_time_us":10617,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32104,"lbm_writes_lt_1ms":543,"mutex_wait_us":395,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:16:57.601886 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=11.118625
I20260812 06:16:57.645936 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.044s	user 0.025s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16250,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:57.646375 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=2.188937
I20260812 06:16:57.664351 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.018s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4238,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.664781 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=2.188937
I20260812 06:16:57.674845 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3905,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:57.675283 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026): perf score=1.000000
I20260812 06:16:57.842060 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.167s	user 0.107s	sys 0.047s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733834,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":377,"lbm_read_time_us":9964,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30753,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19456,"update_count":2500}
I20260812 06:16:57.845835 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=14.095187
I20260812 06:16:57.894613 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.049s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21299,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:57.895262 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=2.188937
I20260812 06:16:57.907965 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4782,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.908396 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026): perf score=1.000000
I20260812 06:16:58.085477 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.177s	user 0.127s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":359,"lbm_read_time_us":10116,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33881,"lbm_writes_lt_1ms":543,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2500}
I20260812 06:16:58.086033 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=14.095187
I20260812 06:16:58.134192 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.048s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21738,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:58.134775 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushMRSOp(2397b268f65e4d32ac95bdeb7c389026): perf score=1.000000
I20260812 06:16:58.178823 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushMRSOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.044s	user 0.023s	sys 0.003s Metrics: {"bytes_written":1234474,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":269,"dirs.run_wall_time_us":1345,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1657,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:16:58.180066 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=3.181125
I20260812 06:16:58.193084 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4878,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:58.193512 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling LogGCOp(2397b268f65e4d32ac95bdeb7c389026): free 121006387 bytes of WAL
I20260812 06:16:58.193717 29047 log_reader.cc:385] T 2397b268f65e4d32ac95bdeb7c389026: removed 12 log segments from log reader
I20260812 06:16:58.193758 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000002 (ops 7-11)
I20260812 06:16:58.193810 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000003 (ops 12-16)
I20260812 06:16:58.193854 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000004 (ops 17-21)
I20260812 06:16:58.193912 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000005 (ops 22-26)
I20260812 06:16:58.193951 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000006 (ops 27-31)
I20260812 06:16:58.193989 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000007 (ops 32-36)
I20260812 06:16:58.194028 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000008 (ops 37-41)
I20260812 06:16:58.194057 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000009 (ops 42-46)
I20260812 06:16:58.194092 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000010 (ops 47-51)
I20260812 06:16:58.194128 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000011 (ops 52-56)
I20260812 06:16:58.194168 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000012 (ops 57-60)
I20260812 06:16:58.194206 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000013 (ops 61-65)
I20260812 06:16:58.220028 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: LogGCOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:16:58.220522 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling UndoDeltaBlockGCOp(2397b268f65e4d32ac95bdeb7c389026): 473 bytes on disk
I20260812 06:16:58.221060 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: UndoDeltaBlockGCOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:16:58.221700 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=2.188937
I20260812 06:16:58.239225 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.017s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4463,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:58.239704 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling LogGCOp(2397b268f65e4d32ac95bdeb7c389026): free 12017983 bytes of WAL
I20260812 06:16:58.239904 29047 log_reader.cc:385] T 2397b268f65e4d32ac95bdeb7c389026: removed 1 log segments from log reader
I20260812 06:16:58.239945 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000014 (ops 66-70)
I20260812 06:16:58.242380 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: LogGCOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:16:58.242697 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=2.188937
I20260812 06:16:58.254465 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3999,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.255055 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026): perf score=1.000000
I20260812 06:16:58.489287 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.234s	user 0.143s	sys 0.081s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938775,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3446,"dirs.run_cpu_time_us":655,"dirs.run_wall_time_us":2701,"lbm_read_time_us":18821,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41463,"lbm_writes_lt_1ms":743,"mutex_wait_us":192,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":3500}
I20260812 06:16:58.489946 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=18.063937
I20260812 06:16:58.547808 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.058s	user 0.029s	sys 0.028s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":26024,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:58.548384 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=2.188937
I20260812 06:16:58.563262 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5751,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.563808 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026): perf score=1.000000
I20260812 06:16:58.741218 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.177s	user 0.149s	sys 0.028s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836136,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":185,"lbm_read_time_us":13995,"lbm_reads_lt_1ms":664,"lbm_write_time_us":37563,"lbm_writes_lt_1ms":643,"mutex_wait_us":42,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":3000}
I20260812 06:16:58.741917 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=14.095187
I20260812 06:16:58.798506 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.056s	user 0.031s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24523,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:58.799119 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=2.188937
I20260812 06:16:58.811335 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4603,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.811939 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026): perf score=1.000000
I20260812 06:16:58.989671 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.178s	user 0.120s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":703,"lbm_read_time_us":11436,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30477,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:16:58.990226 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=14.095187
I20260812 06:16:59.062172 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.072s	user 0.023s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":29910,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.062647 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=2.188937
I20260812 06:16:59.074275 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4094,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.074795 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026): perf score=1.000000
I20260812 06:16:59.278280 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.203s	user 0.140s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":195,"lbm_read_time_us":12141,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36013,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2500}
I20260812 06:16:59.279317 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=14.095187
I20260812 06:16:59.342804 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.063s	user 0.039s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27633,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.343307 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=2.188937
I20260812 06:16:59.355039 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.012s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4528,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.355639 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026): perf score=1.000000
I20260812 06:16:59.544924 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.189s	user 0.116s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1017,"lbm_read_time_us":14122,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32532,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:16:59.545650 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=14.095187
I20260812 06:16:59.607599 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.062s	user 0.030s	sys 0.030s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":22047,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.608115 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=2.188937
I20260812 06:16:59.621156 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5228,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.621670 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushMRSOp(2397b268f65e4d32ac95bdeb7c389026): perf score=1.000000
I20260812 06:16:59.665925 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushMRSOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.044s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":302,"dirs.run_wall_time_us":1234,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1892,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:59.666647 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling LogGCOp(2397b268f65e4d32ac95bdeb7c389026): free 108535450 bytes of WAL
I20260812 06:16:59.666877 29047 log_reader.cc:385] T 2397b268f65e4d32ac95bdeb7c389026: removed 11 log segments from log reader
I20260812 06:16:59.666966 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000015 (ops 71-75)
I20260812 06:16:59.667032 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000016 (ops 76-80)
I20260812 06:16:59.667066 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000017 (ops 81-84)
I20260812 06:16:59.667104 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000018 (ops 85-89)
I20260812 06:16:59.667140 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000019 (ops 90-94)
I20260812 06:16:59.667176 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000020 (ops 95-99)
I20260812 06:16:59.667217 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000021 (ops 100-104)
I20260812 06:16:59.667253 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000022 (ops 105-109)
I20260812 06:16:59.667302 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000023 (ops 110-114)
I20260812 06:16:59.667340 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000024 (ops 115-118)
I20260812 06:16:59.667382 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000025 (ops 119-123)
I20260812 06:16:59.689672 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: LogGCOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.023s	user 0.001s	sys 0.019s Metrics: {}
I20260812 06:16:59.690241 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=2.188937
I20260812 06:16:59.716521 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.026s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5141,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.717391 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=2.188937
I20260812 06:16:59.728507 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4229,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.729027 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026): perf score=1.000000
I20260812 06:16:59.970675 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.241s	user 0.158s	sys 0.081s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938782,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":471,"lbm_read_time_us":16997,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40600,"lbm_writes_lt_1ms":743,"mutex_wait_us":19,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":16512,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:16:59.971475 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=14.095187
I20260812 06:17:00.040614 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.069s	user 0.027s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":31717,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:00.041107 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling UndoDeltaBlockGCOp(2397b268f65e4d32ac95bdeb7c389026): 447 bytes on disk
I20260812 06:17:00.041572 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: UndoDeltaBlockGCOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:17:00.042114 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=3.181125
I20260812 06:17:00.055346 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.013s	user 0.002s	sys 0.011s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5197,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:00.055969 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=2.188937
I20260812 06:17:00.068874 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4253,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:00.069619 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026): perf score=1.000000
I20260812 06:17:00.331525 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.262s	user 0.159s	sys 0.053s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836245,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":303,"lbm_read_time_us":16130,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36296,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":3000}
I20260812 06:17:00.332846 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=19.056125
I20260812 06:17:00.412094 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.079s	user 0.040s	sys 0.020s Metrics: {"bytes_written":20922557,"delete_count":0,"lbm_write_time_us":26193,"lbm_writes_lt_1ms":513,"reinsert_count":0,"update_count":2550}
I20260812 06:17:00.412586 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=6.157687
I20260812 06:17:00.525039 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.112s	user 0.010s	sys 0.012s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8852,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:17:00.525583 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=6.157687
I20260812 06:17:00.623870 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.098s	user 0.013s	sys 0.011s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10581,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:00.624877 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=6.157687
I20260812 06:17:00.733352 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.108s	user 0.023s	sys 0.014s Metrics: {"bytes_written":8410198,"delete_count":0,"lbm_write_time_us":12851,"lbm_writes_lt_1ms":208,"reinsert_count":0,"update_count":1025}
I20260812 06:17:00.734160 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=6.157687
I20260812 06:17:00.830828 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.096s	user 0.007s	sys 0.016s Metrics: {"bytes_written":7999962,"delete_count":0,"lbm_write_time_us":10335,"lbm_writes_lt_1ms":198,"reinsert_count":0,"update_count":975}
I20260812 06:17:00.832516 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=7.149875
I20260812 06:17:00.934463 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.102s	user 0.006s	sys 0.017s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":9487,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:17:00.936581 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=8.142062
I20260812 06:17:01.039858 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.103s	user 0.015s	sys 0.016s Metrics: {"bytes_written":10502427,"delete_count":0,"lbm_write_time_us":12598,"lbm_writes_lt_1ms":259,"reinsert_count":0,"update_count":1280}
I20260812 06:17:01.040697 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=8.142062
I20260812 06:17:01.141980 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.101s	user 0.018s	sys 0.011s Metrics: {"bytes_written":9599902,"delete_count":0,"lbm_write_time_us":13846,"lbm_writes_lt_1ms":237,"reinsert_count":0,"update_count":1170}
I20260812 06:17:01.142855 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=6.157687
I20260812 06:17:01.196049 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.053s	user 0.011s	sys 0.016s Metrics: {"bytes_written":8287128,"delete_count":0,"lbm_write_time_us":9394,"lbm_writes_lt_1ms":205,"reinsert_count":0,"update_count":1010}
I20260812 06:17:01.197082 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=3.181125
I20260812 06:17:01.244047 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.047s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4430858,"delete_count":0,"lbm_write_time_us":4520,"lbm_writes_lt_1ms":111,"reinsert_count":0,"update_count":540}
I20260812 06:17:01.244580 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=2.188937
I20260812 06:17:01.293648 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.049s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4455,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.294271 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=2.188937
I20260812 06:17:01.397178 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.103s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4061,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.398017 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=9.134250
I20260812 06:17:01.503161 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.105s	user 0.011s	sys 0.024s Metrics: {"bytes_written":10584476,"delete_count":0,"lbm_write_time_us":14770,"lbm_writes_lt_1ms":261,"reinsert_count":0,"update_count":1290}
I20260812 06:17:01.503676 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=8.142062
I20260812 06:17:01.550871 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.047s	user 0.018s	sys 0.005s Metrics: {"bytes_written":9517849,"delete_count":0,"lbm_write_time_us":10757,"lbm_writes_lt_1ms":235,"reinsert_count":0,"update_count":1160}
I20260812 06:17:01.551417 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=1.000000
I20260812 06:17:01.560556 28896 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.987s	user 1.902s	sys 0.088s
I20260812 06:17:01.615767 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.064s	user 0.004s	sys 0.005s Metrics: {"bytes_written":1846280,"delete_count":0,"lbm_write_time_us":3031,"lbm_writes_lt_1ms":48,"reinsert_count":0,"update_count":225}
I20260812 06:17:01.616518 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026): perf score=1.196750
I20260812 06:17:01.713258 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushDeltaMemStoresOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.097s	user 0.009s	sys 0.001s Metrics: {"bytes_written":2256529,"delete_count":0,"lbm_write_time_us":3508,"lbm_writes_lt_1ms":58,"reinsert_count":0,"update_count":275}
I20260812 06:17:01.714011 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling FlushMRSOp(2397b268f65e4d32ac95bdeb7c389026): perf score=1.000000
I20260812 06:17:01.813138 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: FlushMRSOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.099s	user 0.037s	sys 0.008s Metrics: {"bytes_written":1603405,"cfile_init":1,"dirs.queue_time_us":257,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2688,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":39,"thread_start_us":131,"threads_started":1}
I20260812 06:17:01.814056 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling LogGCOp(2397b268f65e4d32ac95bdeb7c389026): free 154262806 bytes of WAL
I20260812 06:17:01.814438 29047 log_reader.cc:385] T 2397b268f65e4d32ac95bdeb7c389026: removed 15 log segments from log reader
I20260812 06:17:01.814504 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000026 (ops 124-128)
I20260812 06:17:01.814555 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000027 (ops 129-133)
I20260812 06:17:01.814635 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000028 (ops 134-138)
I20260812 06:17:01.814682 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000029 (ops 139-143)
I20260812 06:17:01.814718 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000030 (ops 144-148)
I20260812 06:17:01.814798 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000031 (ops 149-153)
I20260812 06:17:01.814844 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000032 (ops 154-158)
I20260812 06:17:01.814909 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000033 (ops 159-163)
I20260812 06:17:01.815024 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000034 (ops 164-168)
I20260812 06:17:01.815097 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000035 (ops 169-173)
I20260812 06:17:01.815145 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000036 (ops 174-178)
I20260812 06:17:01.815187 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000037 (ops 179-183)
I20260812 06:17:01.815229 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000038 (ops 184-188)
I20260812 06:17:01.815292 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000039 (ops 189-193)
I20260812 06:17:01.815338 29047 log.cc:1079] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/2397b268f65e4d32ac95bdeb7c389026/wal-000000040 (ops 194-198)
I20260812 06:17:01.848898 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: LogGCOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.035s	user 0.002s	sys 0.031s Metrics: {}
I20260812 06:17:01.849287 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling UndoDeltaBlockGCOp(2397b268f65e4d32ac95bdeb7c389026): 573 bytes on disk
I20260812 06:17:01.849802 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: UndoDeltaBlockGCOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:17:01.850354 29136 maintenance_manager.cc:419] P 262bef4fc5ed459ebd866eb75b65adee: Scheduling MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026): perf score=1.000000
I20260812 06:17:01.898047 28896 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.337s	user 0.001s	sys 0.000s
I20260812 06:17:01.898782 28896 tablet_server.cc:179] TabletServer@127.28.56.1:0 shutting down...
I20260812 06:17:03.322469 29047 maintenance_manager.cc:643] P 262bef4fc5ed459ebd866eb75b65adee: MajorDeltaCompactionOp(2397b268f65e4d32ac95bdeb7c389026) complete. Timing: real 1.472s	user 0.540s	sys 0.932s Metrics: {"cfile_cache_hit":3044,"cfile_cache_hit_bytes":127295479,"cfile_cache_miss":102,"cfile_cache_miss_bytes":4102554,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":16,"delta_iterators_relevant":16,"dirs.queue_time_us":1051,"lbm_read_time_us":2188,"lbm_reads_lt_1ms":118,"lbm_write_time_us":553064,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":3143,"peak_mem_usage":386206772,"reinsert_count":0,"thread_start_us":587,"threads_started":7,"update_count":15500,"wal-append.queue_time_us":238}
I20260812 06:17:03.323123 28896 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:03.323568 28896 tablet_replica.cc:333] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee: stopping tablet replica
I20260812 06:17:03.323839 28896 raft_consensus.cc:2243] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:03.324082 28896 raft_consensus.cc:2272] T 2397b268f65e4d32ac95bdeb7c389026 P 262bef4fc5ed459ebd866eb75b65adee [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:03.339967 28896 tablet_server.cc:196] TabletServer@127.28.56.1:0 shutdown complete.
I20260812 06:17:03.786813 28896 master.cc:562] Master@127.28.56.62:43019 shutting down...
I20260812 06:17:03.791414 28896 raft_consensus.cc:2243] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:03.791585 28896 raft_consensus.cc:2272] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:03.791646 28896 tablet_replica.cc:333] T 00000000000000000000000000000000 P f275f27b53b6470996eadd214af5169d: stopping tablet replica
I20260812 06:17:03.804821 28896 master.cc:584] Master@127.28.56.62:43019 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (7605 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:03.932897 28896 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.28.56.62:46661
I20260812 06:17:03.933293 28896 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:03.935849 29189 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:17:03.936035 29188 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:17:03.936019 29192 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:17:03.935979 28896 server_base.cc:1061] running on GCE node
I20260812 06:17:03.936324 28896 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:03.936389 28896 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:17:03.936419 28896 hybrid_clock.cc:648] HybridClock initialized: now 1786515423936419 us; error 0 us; skew 500 ppm
I20260812 06:17:03.937521 28896 webserver.cc:533] Webserver started at http://127.28.56.62:32935/ using document root <none> and password file <none>
I20260812 06:17:03.937816 28896 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:03.937942 28896 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:03.938045 28896 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:03.938493 28896 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/master-0-root/instance:
uuid: "9654e2eafc3e458b9e3bdccae324d9f4"
format_stamp: "Formatted at 2026-08-12 06:17:03 on dist-test-slave-drl0"
I20260812 06:17:03.940580 28896 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:17:03.941875 29200 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:17:03.942235 28896 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:03.942348 28896 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/master-0-root
uuid: "9654e2eafc3e458b9e3bdccae324d9f4"
format_stamp: "Formatted at 2026-08-12 06:17:03 on dist-test-slave-drl0"
I20260812 06:17:03.942453 28896 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-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:17:03.955328 28896 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:03.955711 28896 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:03.961948 28896 rpc_server.cc:307] RPC server started. Bound to: 127.28.56.62:46661
I20260812 06:17:03.963650 29282 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.56.62:46661 every 8 connection(s)
I20260812 06:17:03.964188 29283 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:17:03.970358 29283 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4: Bootstrap starting.
I20260812 06:17:03.971275 29283 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:03.972364 29283 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4: No bootstrap required, opened a new log
I20260812 06:17:03.972766 29283 raft_consensus.cc:359] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9654e2eafc3e458b9e3bdccae324d9f4" member_type: VOTER }
I20260812 06:17:03.972879 29283 raft_consensus.cc:385] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:03.972942 29283 raft_consensus.cc:740] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9654e2eafc3e458b9e3bdccae324d9f4, State: Initialized, Role: FOLLOWER
I20260812 06:17:03.973208 29283 consensus_queue.cc:260] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [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: "9654e2eafc3e458b9e3bdccae324d9f4" member_type: VOTER }
I20260812 06:17:03.973349 29286 raft_consensus.cc:493] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [term 0 FOLLOWER]: Starting pre-election (no leader contacted us within the election timeout)
I20260812 06:17:03.973452 29286 raft_consensus.cc:515] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [term 0 FOLLOWER]: Starting pre-election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9654e2eafc3e458b9e3bdccae324d9f4" member_type: VOTER }
I20260812 06:17:03.973623 29286 leader_election.cc:304] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [CANDIDATE]: Term 1 pre-election: Election decided. Result: candidate won. Election summary: received 1 responses out of 1 voters: 1 yes votes; 0 no votes. yes voters: 9654e2eafc3e458b9e3bdccae324d9f4; no voters: 
I20260812 06:17:03.973673 29283 raft_consensus.cc:399] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:03.973834 29283 raft_consensus.cc:493] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:03.973865 29286 leader_election.cc:290] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [CANDIDATE]: Term 1 pre-election: Requested pre-vote from peers 
I20260812 06:17:03.973970 29283 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:03.974651 29283 raft_consensus.cc:515] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9654e2eafc3e458b9e3bdccae324d9f4" member_type: VOTER }
I20260812 06:17:03.974789 29283 leader_election.cc:304] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [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: 9654e2eafc3e458b9e3bdccae324d9f4; no voters: 
I20260812 06:17:03.974828 29287 raft_consensus.cc:2764] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [term 1 FOLLOWER]: Leader pre-election decision vote started in defunct term 0: won
I20260812 06:17:03.974944 29283 leader_election.cc:290] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:03.975001 29287 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:03.975163 29287 raft_consensus.cc:697] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [term 1 LEADER]: Becoming Leader. State: Replica: 9654e2eafc3e458b9e3bdccae324d9f4, State: Running, Role: LEADER
I20260812 06:17:03.975344 29283 sys_catalog.cc:565] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:03.975322 29287 consensus_queue.cc:237] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [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: "9654e2eafc3e458b9e3bdccae324d9f4" member_type: VOTER }
I20260812 06:17:03.975873 29286 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "9654e2eafc3e458b9e3bdccae324d9f4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9654e2eafc3e458b9e3bdccae324d9f4" member_type: VOTER } }
I20260812 06:17:03.975911 29289 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 9654e2eafc3e458b9e3bdccae324d9f4. Latest consensus state: current_term: 1 leader_uuid: "9654e2eafc3e458b9e3bdccae324d9f4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9654e2eafc3e458b9e3bdccae324d9f4" member_type: VOTER } }
I20260812 06:17:03.976035 29286 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:03.976127 29289 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:03.976678 29297 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:03.977530 29297 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:03.977793 28896 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:03.979660 29297 catalog_manager.cc:1383] Generated new cluster ID: 0a9bc4d143f341c1b7f312e206b4a469
I20260812 06:17:03.979732 29297 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:04.001056 29297 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:04.001864 29297 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:04.014580 29297 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4: Generated new TSK 0
I20260812 06:17:04.014788 29297 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:04.043251 28896 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:04.046136 29315 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:17:04.046137 29311 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:17:04.046231 29313 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:17:04.046639 28896 server_base.cc:1061] running on GCE node
I20260812 06:17:04.047039 28896 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:04.047106 28896 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:17:04.047133 28896 hybrid_clock.cc:648] HybridClock initialized: now 1786515424047132 us; error 0 us; skew 500 ppm
I20260812 06:17:04.048105 28896 webserver.cc:533] Webserver started at http://127.28.56.1:43755/ using document root <none> and password file <none>
I20260812 06:17:04.048321 28896 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:04.048396 28896 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:04.048482 28896 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:04.049016 28896 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/instance:
uuid: "6b94fe527414482494b8b3f22f36c0e6"
format_stamp: "Formatted at 2026-08-12 06:17:04 on dist-test-slave-drl0"
I20260812 06:17:04.050745 28896 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:04.051970 29323 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:17:04.052434 28896 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:04.052546 28896 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root
uuid: "6b94fe527414482494b8b3f22f36c0e6"
format_stamp: "Formatted at 2026-08-12 06:17:04 on dist-test-slave-drl0"
I20260812 06:17:04.052639 28896 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-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:17:04.072513 28896 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:04.073079 28896 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:04.073544 28896 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:04.074262 28896 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:04.074347 28896 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:04.074416 28896 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:04.074476 28896 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:04.081238 28896 rpc_server.cc:307] RPC server started. Bound to: 127.28.56.1:39557
I20260812 06:17:04.081248 29410 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.56.1:39557 every 8 connection(s)
I20260812 06:17:04.090561 29411 heartbeater.cc:344] Connected to a master server at 127.28.56.62:46661
I20260812 06:17:04.090687 29411 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:04.090901 29411 heartbeater.cc:507] Master 127.28.56.62:46661 requested a full tablet report, sending...
I20260812 06:17:04.091701 29226 ts_manager.cc:194] Registered new tserver with Master: 6b94fe527414482494b8b3f22f36c0e6 (127.28.56.1:39557)
I20260812 06:17:04.092154 28896 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010446816s
I20260812 06:17:04.092530 29226 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:56306
I20260812 06:17:04.100800 29226 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:56314:
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:17:04.111274 29356 tablet_service.cc:1511] Processing CreateTablet for tablet 68f86a967e46429eaab3c6bdb3fbbd0d (DEFAULT_TABLE table=heavy-update-compaction-test [id=937db95121e748b7a77532d046fb065f]), partition=
I20260812 06:17:04.111526 29356 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 68f86a967e46429eaab3c6bdb3fbbd0d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:04.113880 29427 tablet_bootstrap.cc:492] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Bootstrap starting.
I20260812 06:17:04.114884 29427 tablet_bootstrap.cc:654] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:04.116114 29427 tablet_bootstrap.cc:492] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: No bootstrap required, opened a new log
I20260812 06:17:04.116225 29427 ts_tablet_manager.cc:1403] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:04.116616 29427 raft_consensus.cc:359] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6b94fe527414482494b8b3f22f36c0e6" member_type: VOTER last_known_addr { host: "127.28.56.1" port: 39557 } }
I20260812 06:17:04.116744 29427 raft_consensus.cc:385] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:04.116784 29427 raft_consensus.cc:740] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6b94fe527414482494b8b3f22f36c0e6, State: Initialized, Role: FOLLOWER
I20260812 06:17:04.116954 29427 consensus_queue.cc:260] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6 [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: "6b94fe527414482494b8b3f22f36c0e6" member_type: VOTER last_known_addr { host: "127.28.56.1" port: 39557 } }
I20260812 06:17:04.117062 29427 raft_consensus.cc:399] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:04.117108 29427 raft_consensus.cc:493] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:04.117169 29427 raft_consensus.cc:3060] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:04.117893 29427 raft_consensus.cc:515] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6b94fe527414482494b8b3f22f36c0e6" member_type: VOTER last_known_addr { host: "127.28.56.1" port: 39557 } }
I20260812 06:17:04.118014 29427 leader_election.cc:304] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6 [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: 6b94fe527414482494b8b3f22f36c0e6; no voters: 
I20260812 06:17:04.118237 29427 leader_election.cc:290] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:04.118462 29432 raft_consensus.cc:2804] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:04.118705 29427 ts_tablet_manager.cc:1434] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:17:04.118752 29432 raft_consensus.cc:697] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6 [term 1 LEADER]: Becoming Leader. State: Replica: 6b94fe527414482494b8b3f22f36c0e6, State: Running, Role: LEADER
I20260812 06:17:04.118733 29411 heartbeater.cc:499] Master 127.28.56.62:46661 was elected leader, sending a full tablet report...
I20260812 06:17:04.118980 29432 consensus_queue.cc:237] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6 [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: "6b94fe527414482494b8b3f22f36c0e6" member_type: VOTER last_known_addr { host: "127.28.56.1" port: 39557 } }
I20260812 06:17:04.120441 29226 catalog_manager.cc:5719] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6 reported cstate change: term changed from 0 to 1, leader changed from <none> to 6b94fe527414482494b8b3f22f36c0e6 (127.28.56.1). New cstate: current_term: 1 leader_uuid: "6b94fe527414482494b8b3f22f36c0e6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6b94fe527414482494b8b3f22f36c0e6" member_type: VOTER last_known_addr { host: "127.28.56.1" port: 39557 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:04.187906 28896 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.015s	sys 0.010s
I20260812 06:17:04.332180 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushMRSOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=15.086190
I20260812 06:17:04.498484 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushMRSOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.166s	user 0.127s	sys 0.036s Metrics: {"bytes_written":11897249,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":230,"dirs.run_wall_time_us":873,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42188,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":12544,"update_count":1450}
I20260812 06:17:04.499269 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling LogGCOp(68f86a967e46429eaab3c6bdb3fbbd0d): free 20743880 bytes of WAL
I20260812 06:17:04.499491 29329 log_reader.cc:385] T 68f86a967e46429eaab3c6bdb3fbbd0d: removed 2 log segments from log reader
I20260812 06:17:04.499536 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000001 (ops 1-6)
I20260812 06:17:04.499567 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000002 (ops 7-11)
I20260812 06:17:04.504324 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: LogGCOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:17:04.504658 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=2.188937
I20260812 06:17:04.518131 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4852,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:04.518790 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=1.000000
I20260812 06:17:04.695609 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.177s	user 0.090s	sys 0.087s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262036,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":787,"lbm_read_time_us":13545,"lbm_reads_lt_1ms":458,"lbm_write_time_us":28475,"lbm_writes_lt_1ms":433,"mutex_wait_us":93,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":4224,"thread_start_us":410,"threads_started":5,"update_count":1950}
I20260812 06:17:04.696331 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=10.126437
I20260812 06:17:04.742483 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.046s	user 0.029s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18478,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:04.743096 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=2.188937
I20260812 06:17:04.759179 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6040,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:04.761370 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=1.000000
I20260812 06:17:04.894165 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.133s	user 0.112s	sys 0.020s 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":447,"lbm_read_time_us":9951,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25753,"lbm_writes_lt_1ms":443,"mutex_wait_us":4,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18560,"update_count":2000}
I20260812 06:17:04.895231 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=10.126437
I20260812 06:17:04.949040 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.054s	user 0.021s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17786,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:04.949592 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling UndoDeltaBlockGCOp(68f86a967e46429eaab3c6bdb3fbbd0d): 12719219 bytes on disk
I20260812 06:17:04.949997 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: UndoDeltaBlockGCOp(68f86a967e46429eaab3c6bdb3fbbd0d) 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:17:04.950362 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=2.188937
I20260812 06:17:04.964021 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5318,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:04.964449 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=1.000000
I20260812 06:17:05.097929 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.133s	user 0.111s	sys 0.022s 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":72,"lbm_read_time_us":10463,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25576,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":23040,"update_count":2000}
I20260812 06:17:05.098845 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=10.126437
I20260812 06:17:05.151770 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.053s	user 0.028s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18821,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:05.152297 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=2.188937
I20260812 06:17:05.163853 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4741,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:05.164310 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=1.000000
I20260812 06:17:05.348862 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.184s	user 0.099s	sys 0.081s 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":440,"lbm_read_time_us":12402,"lbm_reads_lt_1ms":472,"lbm_write_time_us":39175,"lbm_writes_lt_1ms":443,"mutex_wait_us":191,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2000}
I20260812 06:17:05.349613 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=11.118625
I20260812 06:17:05.415645 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.066s	user 0.036s	sys 0.017s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":28694,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:05.416225 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=6.157687
I20260812 06:17:05.446259 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.030s	user 0.009s	sys 0.017s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":12526,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:17:05.446769 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=1.000000
I20260812 06:17:05.653473 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.207s	user 0.112s	sys 0.084s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774694,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1062,"lbm_read_time_us":12269,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31380,"lbm_writes_lt_1ms":543,"mutex_wait_us":320,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:17:05.654306 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=15.087375
I20260812 06:17:05.725878 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.071s	user 0.036s	sys 0.023s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":29021,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:05.726310 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=6.157687
I20260812 06:17:05.764986 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.038s	user 0.010s	sys 0.023s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":9930,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:17:05.765817 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=1.000000
I20260812 06:17:05.998740 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.233s	user 0.136s	sys 0.096s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877100,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":779,"lbm_read_time_us":17443,"lbm_reads_lt_1ms":664,"lbm_write_time_us":38246,"lbm_writes_lt_1ms":643,"mutex_wait_us":220,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:17:05.999490 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=18.063937
I20260812 06:17:06.074636 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.075s	user 0.041s	sys 0.030s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":28490,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:06.075284 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=2.188937
I20260812 06:17:06.087117 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4674,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:06.087553 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushMRSOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=1.000000
I20260812 06:17:06.135349 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushMRSOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.048s	user 0.032s	sys 0.009s Metrics: {"bytes_written":1316413,"cfile_init":1,"dirs.queue_time_us":98,"dirs.run_cpu_time_us":207,"dirs.run_wall_time_us":1195,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2711,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:06.135969 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling LogGCOp(68f86a967e46429eaab3c6bdb3fbbd0d): free 128867395 bytes of WAL
I20260812 06:17:06.136186 29329 log_reader.cc:385] T 68f86a967e46429eaab3c6bdb3fbbd0d: removed 13 log segments from log reader
I20260812 06:17:06.136229 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000003 (ops 12-16)
I20260812 06:17:06.136260 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000004 (ops 17-20)
I20260812 06:17:06.136327 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000005 (ops 21-25)
I20260812 06:17:06.136370 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000006 (ops 26-30)
I20260812 06:17:06.136415 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000007 (ops 31-34)
I20260812 06:17:06.136473 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000008 (ops 35-39)
I20260812 06:17:06.136508 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000009 (ops 40-44)
I20260812 06:17:06.136549 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000010 (ops 45-48)
I20260812 06:17:06.136585 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000011 (ops 49-53)
I20260812 06:17:06.136623 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000012 (ops 54-58)
I20260812 06:17:06.136662 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000013 (ops 59-63)
I20260812 06:17:06.136706 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000014 (ops 64-68)
I20260812 06:17:06.136745 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000015 (ops 69-73)
I20260812 06:17:06.170043 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: LogGCOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.034s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:17:06.170404 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=3.181125
I20260812 06:17:06.184803 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4841098,"delete_count":0,"lbm_write_time_us":5296,"lbm_writes_lt_1ms":121,"reinsert_count":0,"update_count":590}
I20260812 06:17:06.185210 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=2.188937
I20260812 06:17:06.195467 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3364205,"delete_count":0,"lbm_write_time_us":3890,"lbm_writes_lt_1ms":85,"reinsert_count":0,"update_count":410}
I20260812 06:17:06.195925 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling UndoDeltaBlockGCOp(68f86a967e46429eaab3c6bdb3fbbd0d): 492 bytes on disk
I20260812 06:17:06.196307 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: UndoDeltaBlockGCOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:17:06.196725 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=1.000000
I20260812 06:17:06.488826 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.292s	user 0.193s	sys 0.098s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37082148,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":971,"lbm_read_time_us":22064,"lbm_reads_lt_1ms":874,"lbm_write_time_us":50315,"lbm_writes_lt_1ms":843,"mutex_wait_us":260,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":10624,"thread_start_us":91,"threads_started":1,"update_count":4000}
I20260812 06:17:06.491219 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=18.063937
I20260812 06:17:06.578821 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.087s	user 0.035s	sys 0.037s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":36860,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:17:06.579442 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=6.157687
I20260812 06:17:06.607633 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.028s	user 0.022s	sys 0.000s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9473,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:06.608325 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=1.000000
I20260812 06:17:06.817237 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.209s	user 0.136s	sys 0.069s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":32979514,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1036,"lbm_read_time_us":15919,"lbm_reads_lt_1ms":764,"lbm_write_time_us":42377,"lbm_writes_lt_1ms":743,"mutex_wait_us":324,"peak_mem_usage":87969044,"reinsert_count":0,"update_count":3500}
I20260812 06:17:06.818136 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=15.087375
I20260812 06:17:06.875058 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.057s	user 0.039s	sys 0.012s Metrics: {"bytes_written":16820145,"delete_count":0,"lbm_write_time_us":22655,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:06.875739 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=3.181125
I20260812 06:17:06.889916 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4553929,"delete_count":0,"lbm_write_time_us":5559,"lbm_writes_lt_1ms":114,"reinsert_count":0,"update_count":555}
I20260812 06:17:06.890406 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=2.188937
I20260812 06:17:06.903782 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.013s	user 0.009s	sys 0.003s Metrics: {"bytes_written":3241130,"delete_count":0,"lbm_write_time_us":4838,"lbm_writes_lt_1ms":82,"reinsert_count":0,"update_count":395}
I20260812 06:17:06.904579 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=1.000000
I20260812 06:17:07.099042 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.194s	user 0.149s	sys 0.044s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877204,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":595,"lbm_read_time_us":15926,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38835,"lbm_writes_lt_1ms":643,"mutex_wait_us":84,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":3000}
I20260812 06:17:07.099552 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=14.095187
I20260812 06:17:07.154852 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.055s	user 0.034s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22492,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:07.155412 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=2.188937
I20260812 06:17:07.170260 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4754,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.170835 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=1.000000
I20260812 06:17:07.366115 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.195s	user 0.122s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1062,"lbm_read_time_us":13444,"lbm_reads_lt_1ms":564,"lbm_write_time_us":36809,"lbm_writes_lt_1ms":543,"mutex_wait_us":277,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":48640,"update_count":2500}
I20260812 06:17:07.367031 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=14.095187
I20260812 06:17:07.415485 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.048s	user 0.032s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22387,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:07.415947 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=1.000000
I20260812 06:17:07.581111 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.165s	user 0.114s	sys 0.043s 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":1002,"lbm_read_time_us":9859,"lbm_reads_lt_1ms":467,"lbm_write_time_us":27377,"lbm_writes_lt_1ms":443,"mutex_wait_us":319,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2000}
I20260812 06:17:07.581893 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=11.118625
I20260812 06:17:07.617120 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.035s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":14701,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:07.618024 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=2.188937
I20260812 06:17:07.648926 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.031s	user 0.003s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6169,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:07.649922 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=2.188937
I20260812 06:17:07.662110 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4836,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.662824 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushMRSOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=1.000000
I20260812 06:17:07.708470 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushMRSOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.045s	user 0.030s	sys 0.002s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":230,"dirs.run_wall_time_us":1257,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2072,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:07.709218 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling LogGCOp(68f86a967e46429eaab3c6bdb3fbbd0d): free 124710335 bytes of WAL
I20260812 06:17:07.709450 29329 log_reader.cc:385] T 68f86a967e46429eaab3c6bdb3fbbd0d: removed 12 log segments from log reader
I20260812 06:17:07.709509 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000016 (ops 74-78)
I20260812 06:17:07.709560 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000017 (ops 79-83)
I20260812 06:17:07.709614 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000018 (ops 84-88)
I20260812 06:17:07.709658 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000019 (ops 89-93)
I20260812 06:17:07.709699 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000020 (ops 94-98)
I20260812 06:17:07.709738 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000021 (ops 99-103)
I20260812 06:17:07.709779 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000022 (ops 104-108)
I20260812 06:17:07.709816 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000023 (ops 109-113)
I20260812 06:17:07.709862 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000024 (ops 114-118)
I20260812 06:17:07.709903 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000025 (ops 119-123)
I20260812 06:17:07.709940 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000026 (ops 124-128)
I20260812 06:17:07.709978 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000027 (ops 129-133)
I20260812 06:17:07.739832 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: LogGCOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.030s	user 0.001s	sys 0.028s Metrics: {}
I20260812 06:17:07.740350 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling UndoDeltaBlockGCOp(68f86a967e46429eaab3c6bdb3fbbd0d): 463 bytes on disk
I20260812 06:17:07.740775 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: UndoDeltaBlockGCOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:17:07.741647 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=2.188937
I20260812 06:17:07.764801 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.023s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4266759,"delete_count":0,"lbm_write_time_us":7149,"lbm_writes_lt_1ms":107,"reinsert_count":0,"update_count":520}
I20260812 06:17:07.765260 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=2.188937
I20260812 06:17:07.776019 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3938559,"delete_count":0,"lbm_write_time_us":4310,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:17:07.776443 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=1.000000
I20260812 06:17:08.053210 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.277s	user 0.161s	sys 0.111s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979863,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":2774,"lbm_read_time_us":18925,"lbm_reads_lt_1ms":775,"lbm_write_time_us":47105,"lbm_writes_lt_1ms":743,"mutex_wait_us":1860,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":24192,"thread_start_us":74,"threads_started":1,"update_count":3500}
I20260812 06:17:08.053905 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=18.063937
I20260812 06:17:08.125761 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.072s	user 0.038s	sys 0.020s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":28007,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:08.126281 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=2.188937
I20260812 06:17:08.206394 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.080s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4670,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:08.207026 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=5.165500
I20260812 06:17:08.231967 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.025s	user 0.019s	sys 0.005s Metrics: {"bytes_written":6687182,"delete_count":0,"lbm_write_time_us":10581,"lbm_writes_lt_1ms":166,"reinsert_count":0,"update_count":815}
I20260812 06:17:08.232537 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=1.000000
I20260812 06:17:08.238890 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.006s	user 0.005s	sys 0.000s Metrics: {"bytes_written":1518077,"delete_count":0,"lbm_write_time_us":1843,"lbm_writes_lt_1ms":40,"reinsert_count":0,"update_count":185}
I20260812 06:17:08.239500 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=1.000000
I20260812 06:17:08.508144 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.268s	user 0.176s	sys 0.087s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37082102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":191,"lbm_read_time_us":20522,"lbm_reads_lt_1ms":874,"lbm_write_time_us":48727,"lbm_writes_lt_1ms":843,"mutex_wait_us":71,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":4000}
I20260812 06:17:08.508876 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=19.056125
I20260812 06:17:08.579186 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.070s	user 0.038s	sys 0.022s Metrics: {"bytes_written":20922555,"delete_count":0,"lbm_write_time_us":27148,"lbm_writes_lt_1ms":513,"reinsert_count":0,"update_count":2550}
I20260812 06:17:08.579962 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=6.157687
I20260812 06:17:08.609112 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.029s	user 0.014s	sys 0.013s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":12535,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:17:08.609565 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=1.000000
I20260812 06:17:08.806109 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.196s	user 0.157s	sys 0.036s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":32979513,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":396,"lbm_read_time_us":12822,"lbm_reads_lt_1ms":768,"lbm_write_time_us":41974,"lbm_writes_lt_1ms":743,"mutex_wait_us":74,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":16768,"update_count":3500}
I20260812 06:17:08.806991 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=15.087375
I20260812 06:17:08.874945 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.068s	user 0.032s	sys 0.016s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":22613,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:08.875415 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=6.157687
I20260812 06:17:08.902273 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.027s	user 0.010s	sys 0.013s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":10874,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:17:08.903064 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=1.000000
I20260812 06:17:09.074904 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.172s	user 0.137s	sys 0.032s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877100,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":278,"lbm_read_time_us":12831,"lbm_reads_lt_1ms":664,"lbm_write_time_us":35746,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:17:09.075726 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=14.095187
I20260812 06:17:09.126636 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.051s	user 0.026s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22194,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:09.127285 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=2.188937
I20260812 06:17:09.146245 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.019s	user 0.004s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7602,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:09.146826 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushMRSOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=1.000000
I20260812 06:17:09.179273 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushMRSOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.032s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":109,"dirs.run_cpu_time_us":226,"dirs.run_wall_time_us":1214,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1739,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:09.180264 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling LogGCOp(68f86a967e46429eaab3c6bdb3fbbd0d): free 111786566 bytes of WAL
I20260812 06:17:09.180519 29329 log_reader.cc:385] T 68f86a967e46429eaab3c6bdb3fbbd0d: removed 11 log segments from log reader
I20260812 06:17:09.180569 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000028 (ops 134-138)
I20260812 06:17:09.180604 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000029 (ops 139-143)
I20260812 06:17:09.180667 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000030 (ops 144-148)
I20260812 06:17:09.180717 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000031 (ops 149-152)
I20260812 06:17:09.180739 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000032 (ops 153-157)
I20260812 06:17:09.180809 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000033 (ops 158-162)
I20260812 06:17:09.180876 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000034 (ops 163-166)
I20260812 06:17:09.180920 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000035 (ops 167-171)
I20260812 06:17:09.180989 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000036 (ops 172-176)
I20260812 06:17:09.181020 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000037 (ops 177-181)
I20260812 06:17:09.181197 29329 log.cc:1079] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: Deleting log segment in path: /tmp/dist-test-taskpaPoB4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416283451-28896-0/minicluster-data/ts-0-root/wals/68f86a967e46429eaab3c6bdb3fbbd0d/wal-000000038 (ops 182-186)
I20260812 06:17:09.208109 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: LogGCOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:09.208817 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=3.181125
I20260812 06:17:09.223278 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.014s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":5646,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:09.223794 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=2.188937
I20260812 06:17:09.241446 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6629,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:09.242184 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=1.000000
I20260812 06:17:09.459098 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.217s	user 0.149s	sys 0.067s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979739,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":838,"lbm_read_time_us":17749,"lbm_reads_lt_1ms":774,"lbm_write_time_us":47666,"lbm_writes_lt_1ms":743,"mutex_wait_us":46,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14208,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:17:09.459931 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling UndoDeltaBlockGCOp(68f86a967e46429eaab3c6bdb3fbbd0d): 447 bytes on disk
I20260812 06:17:09.460700 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: UndoDeltaBlockGCOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":92,"lbm_reads_lt_1ms":4}
I20260812 06:17:09.461575 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=14.095187
I20260812 06:17:09.519932 28896 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.332s	user 2.012s	sys 0.151s
I20260812 06:17:09.523995 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.062s	user 0.036s	sys 0.024s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":27395,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:09.524509 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=2.188937
I20260812 06:17:09.534570 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: FlushDeltaMemStoresOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4373,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":500}
I20260812 06:17:09.535077 29412 maintenance_manager.cc:419] P 6b94fe527414482494b8b3f22f36c0e6: Scheduling MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d): perf score=1.000000
I20260812 06:17:09.569327 28896 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.049s	user 0.001s	sys 0.000s
I20260812 06:17:09.569916 28896 tablet_server.cc:179] TabletServer@127.28.56.1:0 shutting down...
I20260812 06:17:09.655794 29329 maintenance_manager.cc:643] P 6b94fe527414482494b8b3f22f36c0e6: MajorDeltaCompactionOp(68f86a967e46429eaab3c6bdb3fbbd0d) complete. Timing: real 0.121s	user 0.092s	sys 0.028s Metrics: {"cfile_cache_hit":341,"cfile_cache_hit_bytes":13949110,"cfile_cache_miss":191,"cfile_cache_miss_bytes":10825581,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":852,"lbm_read_time_us":5114,"lbm_reads_lt_1ms":223,"lbm_write_time_us":26536,"lbm_writes_lt_1ms":543,"mutex_wait_us":73,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":85888,"update_count":2500}
I20260812 06:17:09.656476 28896 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:09.656715 28896 tablet_replica.cc:333] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6: stopping tablet replica
I20260812 06:17:09.656847 28896 raft_consensus.cc:2243] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:09.657034 28896 raft_consensus.cc:2272] T 68f86a967e46429eaab3c6bdb3fbbd0d P 6b94fe527414482494b8b3f22f36c0e6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:09.662335 28896 tablet_server.cc:196] TabletServer@127.28.56.1:0 shutdown complete.
I20260812 06:17:09.703627 28896 master.cc:562] Master@127.28.56.62:46661 shutting down...
I20260812 06:17:09.708030 28896 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:09.708252 28896 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:09.708333 28896 tablet_replica.cc:333] T 00000000000000000000000000000000 P 9654e2eafc3e458b9e3bdccae324d9f4: stopping tablet replica
I20260812 06:17:09.720978 28896 master.cc:584] Master@127.28.56.62:46661 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5919 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (13526 ms total)

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