[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:20:18.556098 31835 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.31.22.254:37049
I20260812 06:20:18.557092 31835 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:20:18.557689 31835 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:18.563832 31843 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:18.563841 31841 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:18.564136 31840 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:18.564190 31835 server_base.cc:1061] running on GCE node
I20260812 06:20:18.564610 31835 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:18.564728 31835 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:18.564774 31835 hybrid_clock.cc:648] HybridClock initialized: now 1786515618564770 us; error 0 us; skew 500 ppm
I20260812 06:20:18.566485 31835 webserver.cc:533] Webserver started at http://127.31.22.254:39831/ using document root <none> and password file <none>
I20260812 06:20:18.567013 31835 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:18.567101 31835 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:18.567359 31835 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:18.569070 31835 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/master-0-root/instance:
uuid: "05c4d402ae1b4a6f91c483c1dcea0cc0"
format_stamp: "Formatted at 2026-08-12 06:20:18 on dist-test-slave-6k22"
I20260812 06:20:18.572557 31835 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.000s	sys 0.004s
I20260812 06:20:18.574620 31852 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:18.575678 31835 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.002s
I20260812 06:20:18.575800 31835 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/master-0-root
uuid: "05c4d402ae1b4a6f91c483c1dcea0cc0"
format_stamp: "Formatted at 2026-08-12 06:20:18 on dist-test-slave-6k22"
I20260812 06:20:18.575898 31835 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:18.611712 31835 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:18.612411 31835 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:20:18.612612 31835 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:18.620272 31915 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.22.254:37049 every 8 connection(s)
I20260812 06:20:18.620287 31835 rpc_server.cc:307] RPC server started. Bound to: 127.31.22.254:37049
I20260812 06:20:18.622462 31916 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:18.627728 31916 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0: Bootstrap starting.
I20260812 06:20:18.630025 31916 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:18.630888 31916 log.cc:826] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:18.632505 31916 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0: No bootstrap required, opened a new log
I20260812 06:20:18.635089 31916 raft_consensus.cc:359] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "05c4d402ae1b4a6f91c483c1dcea0cc0" member_type: VOTER }
I20260812 06:20:18.635241 31916 raft_consensus.cc:385] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:18.635352 31916 raft_consensus.cc:740] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 05c4d402ae1b4a6f91c483c1dcea0cc0, State: Initialized, Role: FOLLOWER
I20260812 06:20:18.635952 31916 consensus_queue.cc:260] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0 [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: "05c4d402ae1b4a6f91c483c1dcea0cc0" member_type: VOTER }
I20260812 06:20:18.636113 31916 raft_consensus.cc:399] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:18.636186 31916 raft_consensus.cc:493] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:18.636345 31916 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:18.637084 31916 raft_consensus.cc:515] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "05c4d402ae1b4a6f91c483c1dcea0cc0" member_type: VOTER }
I20260812 06:20:18.637498 31916 leader_election.cc:304] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0 [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: 05c4d402ae1b4a6f91c483c1dcea0cc0; no voters: 
I20260812 06:20:18.637801 31916 leader_election.cc:290] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:18.637921 31919 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:18.638203 31919 raft_consensus.cc:697] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0 [term 1 LEADER]: Becoming Leader. State: Replica: 05c4d402ae1b4a6f91c483c1dcea0cc0, State: Running, Role: LEADER
I20260812 06:20:18.638667 31919 consensus_queue.cc:237] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0 [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: "05c4d402ae1b4a6f91c483c1dcea0cc0" member_type: VOTER }
I20260812 06:20:18.638772 31916 sys_catalog.cc:565] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:18.640568 31921 sys_catalog.cc:455] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 05c4d402ae1b4a6f91c483c1dcea0cc0. Latest consensus state: current_term: 1 leader_uuid: "05c4d402ae1b4a6f91c483c1dcea0cc0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "05c4d402ae1b4a6f91c483c1dcea0cc0" member_type: VOTER } }
I20260812 06:20:18.640587 31920 sys_catalog.cc:455] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "05c4d402ae1b4a6f91c483c1dcea0cc0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "05c4d402ae1b4a6f91c483c1dcea0cc0" member_type: VOTER } }
I20260812 06:20:18.640698 31921 sys_catalog.cc:458] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:18.640756 31920 sys_catalog.cc:458] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:18.641105 31835 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:20:18.643010 31934 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:20:18.643072 31934 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:20:18.643148 31933 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:18.643972 31933 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:18.648794 31933 catalog_manager.cc:1383] Generated new cluster ID: 2fa61464c189486e9d4ad7d3f628d69e
I20260812 06:20:18.648860 31933 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:18.693851 31933 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:18.695096 31933 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:18.718130 31933 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0: Generated new TSK 0
I20260812 06:20:18.718842 31933 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:18.770287 31835 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:18.773510 31940 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:18.773540 31944 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:18.773608 31939 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:18.774111 31835 server_base.cc:1061] running on GCE node
I20260812 06:20:18.774315 31835 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:18.774359 31835 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:18.774375 31835 hybrid_clock.cc:648] HybridClock initialized: now 1786515618774375 us; error 0 us; skew 500 ppm
I20260812 06:20:18.775343 31835 webserver.cc:533] Webserver started at http://127.31.22.193:43643/ using document root <none> and password file <none>
I20260812 06:20:18.775514 31835 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:18.775620 31835 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:18.775709 31835 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:18.776139 31835 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/instance:
uuid: "fb2cc0d7c3b44b59b48c54310e91a4ec"
format_stamp: "Formatted at 2026-08-12 06:20:18 on dist-test-slave-6k22"
I20260812 06:20:18.777709 31835 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:18.778731 31950 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:18.778983 31835 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:18.779049 31835 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root
uuid: "fb2cc0d7c3b44b59b48c54310e91a4ec"
format_stamp: "Formatted at 2026-08-12 06:20:18 on dist-test-slave-6k22"
I20260812 06:20:18.779134 31835 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:18.806519 31835 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:18.806965 31835 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:18.807461 31835 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:18.808352 31835 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:18.808405 31835 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:18.808473 31835 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:18.808514 31835 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:18.814539 31835 rpc_server.cc:307] RPC server started. Bound to: 127.31.22.193:39779
I20260812 06:20:18.814973 32026 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.22.193:39779 every 8 connection(s)
I20260812 06:20:18.823864 32027 heartbeater.cc:344] Connected to a master server at 127.31.22.254:37049
I20260812 06:20:18.824077 32027 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:18.824470 32027 heartbeater.cc:507] Master 127.31.22.254:37049 requested a full tablet report, sending...
I20260812 06:20:18.825862 31872 ts_manager.cc:194] Registered new tserver with Master: fb2cc0d7c3b44b59b48c54310e91a4ec (127.31.22.193:39779)
I20260812 06:20:18.826642 31835 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011271124s
I20260812 06:20:18.827010 31872 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:55712
I20260812 06:20:18.835641 31872 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:55716:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:18.848344 31984 tablet_service.cc:1511] Processing CreateTablet for tablet bda42f69d57544be90b7e5b5f9b5f7b4 (DEFAULT_TABLE table=heavy-update-compaction-test [id=d3ff2b989cde4639a14e6d9bcddf2ecb]), partition=
I20260812 06:20:18.848788 31984 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet bda42f69d57544be90b7e5b5f9b5f7b4. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:18.851209 32039 tablet_bootstrap.cc:492] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Bootstrap starting.
I20260812 06:20:18.852206 32039 tablet_bootstrap.cc:654] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:18.853519 32039 tablet_bootstrap.cc:492] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: No bootstrap required, opened a new log
I20260812 06:20:18.853605 32039 ts_tablet_manager.cc:1403] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:18.853998 32039 raft_consensus.cc:359] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fb2cc0d7c3b44b59b48c54310e91a4ec" member_type: VOTER last_known_addr { host: "127.31.22.193" port: 39779 } }
I20260812 06:20:18.854097 32039 raft_consensus.cc:385] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:18.854120 32039 raft_consensus.cc:740] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: fb2cc0d7c3b44b59b48c54310e91a4ec, State: Initialized, Role: FOLLOWER
I20260812 06:20:18.854269 32039 consensus_queue.cc:260] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec [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: "fb2cc0d7c3b44b59b48c54310e91a4ec" member_type: VOTER last_known_addr { host: "127.31.22.193" port: 39779 } }
I20260812 06:20:18.854369 32039 raft_consensus.cc:399] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:18.854398 32039 raft_consensus.cc:493] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:18.854432 32039 raft_consensus.cc:3060] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:18.855140 32039 raft_consensus.cc:515] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fb2cc0d7c3b44b59b48c54310e91a4ec" member_type: VOTER last_known_addr { host: "127.31.22.193" port: 39779 } }
I20260812 06:20:18.855274 32039 leader_election.cc:304] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec [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: fb2cc0d7c3b44b59b48c54310e91a4ec; no voters: 
I20260812 06:20:18.855453 32039 leader_election.cc:290] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:18.855623 32041 raft_consensus.cc:2804] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:18.855825 32039 ts_tablet_manager.cc:1434] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:18.855857 32041 raft_consensus.cc:697] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec [term 1 LEADER]: Becoming Leader. State: Replica: fb2cc0d7c3b44b59b48c54310e91a4ec, State: Running, Role: LEADER
I20260812 06:20:18.856034 32027 heartbeater.cc:499] Master 127.31.22.254:37049 was elected leader, sending a full tablet report...
I20260812 06:20:18.856280 32041 consensus_queue.cc:237] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec [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: "fb2cc0d7c3b44b59b48c54310e91a4ec" member_type: VOTER last_known_addr { host: "127.31.22.193" port: 39779 } }
I20260812 06:20:18.858927 31872 catalog_manager.cc:5719] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec reported cstate change: term changed from 0 to 1, leader changed from <none> to fb2cc0d7c3b44b59b48c54310e91a4ec (127.31.22.193). New cstate: current_term: 1 leader_uuid: "fb2cc0d7c3b44b59b48c54310e91a4ec" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fb2cc0d7c3b44b59b48c54310e91a4ec" member_type: VOTER last_known_addr { host: "127.31.22.193" port: 39779 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:18.917143 31835 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.013s	sys 0.012s
I20260812 06:20:19.065871 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushMRSOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=19.054940
I20260812 06:20:19.238168 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushMRSOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.172s	user 0.125s	sys 0.040s Metrics: {"bytes_written":12717736,"cfile_init":1,"compiler_manager_pool.queue_time_us":279,"delete_count":0,"dirs.queue_time_us":40,"dirs.run_cpu_time_us":204,"dirs.run_wall_time_us":912,"drs_written":1,"lbm_read_time_us":83,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44397,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":765,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":183,"threads_started":1,"update_count":1550}
I20260812 06:20:19.239229 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling LogGCOp(bda42f69d57544be90b7e5b5f9b5f7b4): free 20743880 bytes of WAL
I20260812 06:20:19.239527 31955 log_reader.cc:385] T bda42f69d57544be90b7e5b5f9b5f7b4: removed 2 log segments from log reader
I20260812 06:20:19.239622 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000001 (ops 1-6)
I20260812 06:20:19.239687 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000002 (ops 7-11)
I20260812 06:20:19.244813 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: LogGCOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.005s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:20:19.245280 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=2.188937
I20260812 06:20:19.259114 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4579,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:19.259778 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=1.000000
I20260812 06:20:19.406996 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.147s	user 0.084s	sys 0.058s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":471,"lbm_read_time_us":8358,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23530,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":329,"threads_started":5,"update_count":2000}
I20260812 06:20:19.407609 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=10.126437
I20260812 06:20:19.442761 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.035s	user 0.018s	sys 0.013s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14610,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.443287 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling UndoDeltaBlockGCOp(bda42f69d57544be90b7e5b5f9b5f7b4): 16411391 bytes on disk
I20260812 06:20:19.443830 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: UndoDeltaBlockGCOp(bda42f69d57544be90b7e5b5f9b5f7b4) 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:20:19.444290 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=2.188937
I20260812 06:20:19.459733 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.015s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5785,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.460160 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=1.000000
I20260812 06:20:19.583590 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.123s	user 0.091s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1056,"lbm_read_time_us":9436,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24469,"lbm_writes_lt_1ms":443,"mutex_wait_us":341,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":43008,"update_count":2000}
I20260812 06:20:19.584064 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=10.126437
I20260812 06:20:19.630748 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.047s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":17304,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.631266 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=2.188937
I20260812 06:20:19.646134 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5596,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.646656 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=1.000000
I20260812 06:20:19.774215 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.127s	user 0.091s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":245,"lbm_read_time_us":7545,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26910,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2000}
I20260812 06:20:19.774835 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=10.126437
I20260812 06:20:19.822904 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.048s	user 0.026s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15090,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.823542 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=2.188937
I20260812 06:20:19.834519 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4237,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.834932 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=1.000000
I20260812 06:20:19.978747 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.144s	user 0.111s	sys 0.032s 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":325,"lbm_read_time_us":11160,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22927,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":676480,"update_count":2000}
I20260812 06:20:19.979271 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=10.126437
I20260812 06:20:20.022585 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.043s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16382,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.023103 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=2.188937
I20260812 06:20:20.034358 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4099,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.035006 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=1.000000
I20260812 06:20:20.154106 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.119s	user 0.098s	sys 0.021s 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":385,"lbm_read_time_us":7808,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24056,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.154844 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=10.126437
I20260812 06:20:20.198027 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.043s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18453,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.198542 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=2.188937
I20260812 06:20:20.214260 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6029,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.214915 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=1.000000
I20260812 06:20:20.345178 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.130s	user 0.106s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":173,"lbm_read_time_us":8056,"lbm_reads_lt_1ms":468,"lbm_write_time_us":27252,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2000}
I20260812 06:20:20.345928 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=10.126437
I20260812 06:20:20.381639 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.036s	user 0.030s	sys 0.003s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":14902,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.382401 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=2.188937
I20260812 06:20:20.398181 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6144,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.398826 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushMRSOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=1.000000
I20260812 06:20:20.424875 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushMRSOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.026s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":259,"dirs.run_wall_time_us":1414,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1574,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:20.425654 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling LogGCOp(bda42f69d57544be90b7e5b5f9b5f7b4): free 112239302 bytes of WAL
I20260812 06:20:20.425889 31955 log_reader.cc:385] T bda42f69d57544be90b7e5b5f9b5f7b4: removed 11 log segments from log reader
I20260812 06:20:20.425935 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000003 (ops 12-16)
I20260812 06:20:20.425964 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000004 (ops 17-20)
I20260812 06:20:20.426031 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000005 (ops 21-25)
I20260812 06:20:20.426074 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000006 (ops 26-30)
I20260812 06:20:20.426119 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000007 (ops 31-35)
I20260812 06:20:20.426173 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000008 (ops 36-40)
I20260812 06:20:20.426209 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000009 (ops 41-45)
I20260812 06:20:20.426254 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000010 (ops 46-50)
I20260812 06:20:20.426294 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000011 (ops 51-55)
I20260812 06:20:20.426342 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000012 (ops 56-60)
I20260812 06:20:20.426383 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000013 (ops 61-65)
I20260812 06:20:20.450868 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: LogGCOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:20:20.451287 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling UndoDeltaBlockGCOp(bda42f69d57544be90b7e5b5f9b5f7b4): 447 bytes on disk
I20260812 06:20:20.451964 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: UndoDeltaBlockGCOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4}
I20260812 06:20:20.452472 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=2.188937
I20260812 06:20:20.472039 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.019s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6089,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.472460 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=2.188937
I20260812 06:20:20.482671 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3916,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.483093 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=1.000000
I20260812 06:20:20.652640 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.169s	user 0.135s	sys 0.032s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877342,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":746,"lbm_read_time_us":12227,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32312,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17024,"thread_start_us":77,"threads_started":1,"update_count":3000}
I20260812 06:20:20.653404 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=14.095187
I20260812 06:20:20.703262 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.050s	user 0.034s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21523,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.703845 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=2.188937
I20260812 06:20:20.721114 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.017s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6249,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.721705 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=1.000000
I20260812 06:20:20.884230 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.162s	user 0.121s	sys 0.038s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":748,"lbm_read_time_us":10101,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32951,"lbm_writes_lt_1ms":543,"mutex_wait_us":339,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2500}
I20260812 06:20:20.884842 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=14.095187
I20260812 06:20:20.940685 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.056s	user 0.043s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23065,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.941231 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=1.000000
I20260812 06:20:21.093475 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.152s	user 0.105s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":258,"lbm_read_time_us":8893,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25651,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.094194 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=14.095187
I20260812 06:20:21.144477 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.050s	user 0.022s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23688,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.145025 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=2.188937
I20260812 06:20:21.161059 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6068,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.161584 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=1.000000
I20260812 06:20:21.351675 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.190s	user 0.118s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1088,"lbm_read_time_us":14494,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32254,"lbm_writes_lt_1ms":543,"mutex_wait_us":347,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":2500}
I20260812 06:20:21.352353 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=11.118625
I20260812 06:20:21.388279 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.036s	user 0.015s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15057,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:21.388820 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=2.188937
I20260812 06:20:21.409595 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.021s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5856,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:21.410048 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=2.188937
I20260812 06:20:21.420351 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4094,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.420768 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=1.000000
I20260812 06:20:21.568568 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.148s	user 0.100s	sys 0.046s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1775,"lbm_read_time_us":9384,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29473,"lbm_writes_lt_1ms":543,"mutex_wait_us":882,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:21.569229 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=10.126437
I20260812 06:20:21.600574 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.031s	user 0.018s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13956,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.601145 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=2.188937
I20260812 06:20:21.611315 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3994,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.611829 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=1.000000
I20260812 06:20:21.729573 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.118s	user 0.084s	sys 0.033s 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":268,"lbm_read_time_us":8872,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22683,"lbm_writes_lt_1ms":443,"mutex_wait_us":74,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:20:21.730161 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=10.126437
I20260812 06:20:21.772293 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.042s	user 0.035s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17042,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.772816 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=2.188937
I20260812 06:20:21.783980 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4016,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.784721 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushMRSOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=1.000000
I20260812 06:20:21.816190 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushMRSOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.031s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":149,"dirs.run_cpu_time_us":152,"dirs.run_wall_time_us":1266,"drs_written":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1887,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:21.817132 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling LogGCOp(bda42f69d57544be90b7e5b5f9b5f7b4): free 124710298 bytes of WAL
I20260812 06:20:21.817380 31955 log_reader.cc:385] T bda42f69d57544be90b7e5b5f9b5f7b4: removed 12 log segments from log reader
I20260812 06:20:21.817438 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000014 (ops 66-70)
I20260812 06:20:21.817483 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000015 (ops 71-75)
I20260812 06:20:21.817533 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000016 (ops 76-80)
I20260812 06:20:21.817566 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000017 (ops 81-85)
I20260812 06:20:21.817610 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000018 (ops 86-90)
I20260812 06:20:21.817657 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000019 (ops 91-95)
I20260812 06:20:21.817700 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000020 (ops 96-100)
I20260812 06:20:21.817747 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000021 (ops 101-105)
I20260812 06:20:21.817792 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000022 (ops 106-110)
I20260812 06:20:21.817834 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000023 (ops 111-115)
I20260812 06:20:21.817874 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000024 (ops 116-120)
I20260812 06:20:21.817915 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000025 (ops 121-125)
I20260812 06:20:21.850414 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: LogGCOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.033s	user 0.003s	sys 0.027s Metrics: {}
I20260812 06:20:21.850908 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=2.188937
I20260812 06:20:21.876389 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.025s	user 0.014s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7510,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.876888 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=2.188937
I20260812 06:20:21.890429 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.013s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5138,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.890988 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=1.000000
I20260812 06:20:22.063891 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.173s	user 0.130s	sys 0.040s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877340,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2906,"lbm_read_time_us":12521,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34348,"lbm_writes_lt_1ms":643,"mutex_wait_us":2361,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:20:22.064471 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling UndoDeltaBlockGCOp(bda42f69d57544be90b7e5b5f9b5f7b4): 462 bytes on disk
I20260812 06:20:22.065209 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: UndoDeltaBlockGCOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:20:22.065805 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=14.095187
I20260812 06:20:22.122284 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.056s	user 0.033s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25012,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.122846 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=3.181125
I20260812 06:20:22.147179 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.024s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":6857,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:22.147715 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=2.188937
I20260812 06:20:22.156657 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3423,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:22.157075 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=1.000000
I20260812 06:20:22.338408 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.181s	user 0.135s	sys 0.038s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877205,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1091,"lbm_read_time_us":13676,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36624,"lbm_writes_lt_1ms":643,"mutex_wait_us":292,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:20:22.339053 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=14.095187
I20260812 06:20:22.393770 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.054s	user 0.037s	sys 0.013s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23174,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.394222 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=2.188937
I20260812 06:20:22.405139 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4088,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.405897 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=1.000000
I20260812 06:20:22.557224 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.151s	user 0.123s	sys 0.023s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":201,"lbm_read_time_us":9029,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30789,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:20:22.558766 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=13.103000
I20260812 06:20:22.609712 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.050s	user 0.036s	sys 0.011s Metrics: {"bytes_written":14809964,"delete_count":0,"lbm_write_time_us":21198,"lbm_writes_lt_1ms":364,"reinsert_count":0,"update_count":1805}
I20260812 06:20:22.610256 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=1.000000
I20260812 06:20:22.617226 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.007s	user 0.005s	sys 0.000s Metrics: {"bytes_written":2010381,"delete_count":0,"lbm_write_time_us":2149,"lbm_writes_lt_1ms":52,"reinsert_count":0,"update_count":245}
I20260812 06:20:22.617679 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=1.000000
I20260812 06:20:22.770001 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.152s	user 0.087s	sys 0.058s Metrics: {"cfile_cache_miss":442,"cfile_cache_miss_bytes":21082474,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":142,"lbm_read_time_us":10229,"lbm_reads_lt_1ms":474,"lbm_write_time_us":26029,"lbm_writes_lt_1ms":453,"mutex_wait_us":26,"peak_mem_usage":51099678,"reinsert_count":0,"spinlock_wait_cycles":41472,"update_count":2050}
I20260812 06:20:22.770690 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=14.095187
I20260812 06:20:22.823693 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.053s	user 0.027s	sys 0.021s Metrics: {"bytes_written":15999660,"delete_count":0,"lbm_write_time_us":21140,"lbm_writes_lt_1ms":393,"reinsert_count":0,"update_count":1950}
I20260812 06:20:22.824214 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=2.188937
I20260812 06:20:22.843719 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.019s	user 0.011s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3981,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.844237 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=1.000000
I20260812 06:20:23.019634 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.175s	user 0.116s	sys 0.052s Metrics: {"cfile_cache_miss":522,"cfile_cache_miss_bytes":24364447,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":569,"lbm_read_time_us":12255,"lbm_reads_lt_1ms":562,"lbm_write_time_us":28500,"lbm_writes_lt_1ms":533,"mutex_wait_us":106,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2450}
I20260812 06:20:23.020300 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=14.095187
I20260812 06:20:23.076856 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.056s	user 0.033s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22680,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.077382 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=2.188937
I20260812 06:20:23.089994 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4835,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.090595 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=1.000000
I20260812 06:20:23.247967 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.157s	user 0.113s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1063,"lbm_read_time_us":10905,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32055,"lbm_writes_lt_1ms":543,"mutex_wait_us":283,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2500}
I20260812 06:20:23.248747 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=11.118625
I20260812 06:20:23.292172 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.043s	user 0.034s	sys 0.009s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":18518,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:20:23.292824 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=2.188937
I20260812 06:20:23.314150 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.021s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4575,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.314675 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=2.188937
I20260812 06:20:23.324652 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3802,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.325062 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushMRSOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=1.000000
I20260812 06:20:23.359354 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushMRSOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.034s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":218,"dirs.run_wall_time_us":1426,"drs_written":1,"lbm_read_time_us":103,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1612,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:23.360034 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling LogGCOp(bda42f69d57544be90b7e5b5f9b5f7b4): free 124710558 bytes of WAL
I20260812 06:20:23.360273 31955 log_reader.cc:385] T bda42f69d57544be90b7e5b5f9b5f7b4: removed 12 log segments from log reader
I20260812 06:20:23.360318 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000026 (ops 126-130)
I20260812 06:20:23.360347 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000027 (ops 131-135)
I20260812 06:20:23.360409 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000028 (ops 136-140)
I20260812 06:20:23.360450 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000029 (ops 141-145)
I20260812 06:20:23.360487 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000030 (ops 146-150)
I20260812 06:20:23.360530 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000031 (ops 151-155)
I20260812 06:20:23.360565 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000032 (ops 156-160)
I20260812 06:20:23.360602 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000033 (ops 161-165)
I20260812 06:20:23.360643 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000034 (ops 166-170)
I20260812 06:20:23.360682 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000035 (ops 171-175)
I20260812 06:20:23.360720 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000036 (ops 176-180)
I20260812 06:20:23.360759 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000037 (ops 181-185)
I20260812 06:20:23.389362 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: LogGCOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.029s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:20:23.389916 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling UndoDeltaBlockGCOp(bda42f69d57544be90b7e5b5f9b5f7b4): 491 bytes on disk
I20260812 06:20:23.390448 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: UndoDeltaBlockGCOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:20:23.391080 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=4.173312
I20260812 06:20:23.409379 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":5497489,"delete_count":0,"lbm_write_time_us":7746,"lbm_writes_lt_1ms":137,"reinsert_count":0,"update_count":670}
I20260812 06:20:23.409847 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling LogGCOp(bda42f69d57544be90b7e5b5f9b5f7b4): free 12017952 bytes of WAL
I20260812 06:20:23.410072 31955 log_reader.cc:385] T bda42f69d57544be90b7e5b5f9b5f7b4: removed 1 log segments from log reader
I20260812 06:20:23.410118 31955 log.cc:1079] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/bda42f69d57544be90b7e5b5f9b5f7b4/wal-000000038 (ops 186-190)
I20260812 06:20:23.412695 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: LogGCOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:23.413015 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=1.196750
I20260812 06:20:23.421053 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.008s	user 0.001s	sys 0.005s Metrics: {"bytes_written":2707805,"delete_count":0,"lbm_write_time_us":2827,"lbm_writes_lt_1ms":69,"reinsert_count":0,"update_count":330}
I20260812 06:20:23.421521 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=1.000000
I20260812 06:20:23.653780 31835 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.737s	user 1.889s	sys 0.068s
I20260812 06:20:23.666498 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: MajorDeltaCompactionOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.245s	user 0.145s	sys 0.093s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979830,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":574,"lbm_read_time_us":16400,"lbm_reads_lt_1ms":775,"lbm_write_time_us":41119,"lbm_writes_lt_1ms":743,"mutex_wait_us":87,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:20:23.668005 32028 maintenance_manager.cc:419] P fb2cc0d7c3b44b59b48c54310e91a4ec: Scheduling FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4): perf score=18.063937
I20260812 06:20:23.728349 31835 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.074s	user 0.006s	sys 0.000s
I20260812 06:20:23.729228 31835 tablet_server.cc:179] TabletServer@127.31.22.193:0 shutting down...
I20260812 06:20:23.738890 31955 maintenance_manager.cc:643] P fb2cc0d7c3b44b59b48c54310e91a4ec: FlushDeltaMemStoresOp(bda42f69d57544be90b7e5b5f9b5f7b4) complete. Timing: real 0.071s	user 0.045s	sys 0.022s Metrics: {"bytes_written":20512328,"delete_count":0,"lbm_write_time_us":31580,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:23.739465 31835 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:23.739872 31835 tablet_replica.cc:333] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec: stopping tablet replica
I20260812 06:20:23.740177 31835 raft_consensus.cc:2243] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:23.740427 31835 raft_consensus.cc:2272] T bda42f69d57544be90b7e5b5f9b5f7b4 P fb2cc0d7c3b44b59b48c54310e91a4ec [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:23.755172 31835 tablet_server.cc:196] TabletServer@127.31.22.193:0 shutdown complete.
I20260812 06:20:23.759859 31835 master.cc:562] Master@127.31.22.254:37049 shutting down...
I20260812 06:20:23.763401 31835 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:23.763634 31835 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:23.763732 31835 tablet_replica.cc:333] T 00000000000000000000000000000000 P 05c4d402ae1b4a6f91c483c1dcea0cc0: stopping tablet replica
I20260812 06:20:23.776228 31835 master.cc:584] Master@127.31.22.254:37049 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5308 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:23.864015 31835 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.31.22.254:41369
I20260812 06:20:23.864423 31835 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:23.866716 32061 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:23.866824 31835 server_base.cc:1061] running on GCE node
W20260812 06:20:23.866779 32065 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:23.866894 32062 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:23.867332 31835 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:23.867388 31835 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:23.867405 31835 hybrid_clock.cc:648] HybridClock initialized: now 1786515623867406 us; error 0 us; skew 500 ppm
I20260812 06:20:23.868362 31835 webserver.cc:533] Webserver started at http://127.31.22.254:34375/ using document root <none> and password file <none>
I20260812 06:20:23.868497 31835 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:23.868541 31835 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:23.868599 31835 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:23.868974 31835 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/master-0-root/instance:
uuid: "8bfe00e151414289880fecc5720a6785"
format_stamp: "Formatted at 2026-08-12 06:20:23 on dist-test-slave-6k22"
I20260812 06:20:23.870474 31835 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:23.871474 32072 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:23.871793 31835 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:23.871891 31835 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/master-0-root
uuid: "8bfe00e151414289880fecc5720a6785"
format_stamp: "Formatted at 2026-08-12 06:20:23 on dist-test-slave-6k22"
I20260812 06:20:23.871984 31835 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:23.904595 31835 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:23.905049 31835 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:23.909689 31835 rpc_server.cc:307] RPC server started. Bound to: 127.31.22.254:41369
I20260812 06:20:23.913007 32138 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:23.913432 32137 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.22.254:41369 every 8 connection(s)
I20260812 06:20:23.920926 32138 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785: Bootstrap starting.
I20260812 06:20:23.921764 32138 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:23.922812 32138 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785: No bootstrap required, opened a new log
I20260812 06:20:23.923239 32138 raft_consensus.cc:359] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8bfe00e151414289880fecc5720a6785" member_type: VOTER }
I20260812 06:20:23.923328 32138 raft_consensus.cc:385] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:23.923389 32138 raft_consensus.cc:740] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8bfe00e151414289880fecc5720a6785, State: Initialized, Role: FOLLOWER
I20260812 06:20:23.923626 32138 consensus_queue.cc:260] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785 [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: "8bfe00e151414289880fecc5720a6785" member_type: VOTER }
I20260812 06:20:23.923713 32138 raft_consensus.cc:399] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:23.923770 32138 raft_consensus.cc:493] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:23.923828 32138 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:23.924551 32138 raft_consensus.cc:515] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8bfe00e151414289880fecc5720a6785" member_type: VOTER }
I20260812 06:20:23.924700 32138 leader_election.cc:304] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785 [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: 8bfe00e151414289880fecc5720a6785; no voters: 
I20260812 06:20:23.924917 32138 leader_election.cc:290] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:23.925040 32141 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:23.925256 32141 raft_consensus.cc:697] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785 [term 1 LEADER]: Becoming Leader. State: Replica: 8bfe00e151414289880fecc5720a6785, State: Running, Role: LEADER
I20260812 06:20:23.925375 32138 sys_catalog.cc:565] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:23.925410 32141 consensus_queue.cc:237] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785 [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: "8bfe00e151414289880fecc5720a6785" member_type: VOTER }
I20260812 06:20:23.925802 32142 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "8bfe00e151414289880fecc5720a6785" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8bfe00e151414289880fecc5720a6785" member_type: VOTER } }
I20260812 06:20:23.925845 32144 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 8bfe00e151414289880fecc5720a6785. Latest consensus state: current_term: 1 leader_uuid: "8bfe00e151414289880fecc5720a6785" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8bfe00e151414289880fecc5720a6785" member_type: VOTER } }
I20260812 06:20:23.925894 32142 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:23.925899 32144 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:23.926190 32146 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:23.926995 32146 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:23.927423 31835 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:23.928835 32146 catalog_manager.cc:1383] Generated new cluster ID: f2d9bd64e7554ed0b45b558cac46ae48
I20260812 06:20:23.928900 32146 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:23.941659 32146 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:23.942312 32146 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:23.954257 32146 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785: Generated new TSK 0
I20260812 06:20:23.954471 32146 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:23.959615 31835 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:23.961645 32162 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:23.961735 31835 server_base.cc:1061] running on GCE node
W20260812 06:20:23.961850 32164 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:23.961747 32166 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:23.962134 31835 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:23.962179 31835 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:23.962195 31835 hybrid_clock.cc:648] HybridClock initialized: now 1786515623962195 us; error 0 us; skew 500 ppm
I20260812 06:20:23.963078 31835 webserver.cc:533] Webserver started at http://127.31.22.193:39849/ using document root <none> and password file <none>
I20260812 06:20:23.963263 31835 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:23.963342 31835 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:23.963424 31835 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:23.963869 31835 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/instance:
uuid: "e5fb498d4352407d8c2fb720306cec73"
format_stamp: "Formatted at 2026-08-12 06:20:23 on dist-test-slave-6k22"
I20260812 06:20:23.965322 31835 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:23.966195 32174 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:23.966419 31835 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:23.966511 31835 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root
uuid: "e5fb498d4352407d8c2fb720306cec73"
format_stamp: "Formatted at 2026-08-12 06:20:23 on dist-test-slave-6k22"
I20260812 06:20:23.966598 31835 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:24.007238 31835 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:24.007746 31835 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:24.008126 31835 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:24.008635 31835 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:24.008702 31835 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:24.008761 31835 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:24.008811 31835 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:24.013059 31835 rpc_server.cc:307] RPC server started. Bound to: 127.31.22.193:33399
I20260812 06:20:24.013106 32254 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.22.193:33399 every 8 connection(s)
I20260812 06:20:24.022078 32256 heartbeater.cc:344] Connected to a master server at 127.31.22.254:41369
I20260812 06:20:24.022187 32256 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:24.022403 32256 heartbeater.cc:507] Master 127.31.22.254:41369 requested a full tablet report, sending...
I20260812 06:20:24.023020 32095 ts_manager.cc:194] Registered new tserver with Master: e5fb498d4352407d8c2fb720306cec73 (127.31.22.193:33399)
I20260812 06:20:24.023393 31835 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009842675s
I20260812 06:20:24.023947 32095 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:33552
I20260812 06:20:24.030453 32095 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:33554:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:24.039011 32210 tablet_service.cc:1511] Processing CreateTablet for tablet cb79f463b3134f4e92ef4c0b61880519 (DEFAULT_TABLE table=heavy-update-compaction-test [id=ce4ad8fbeae14b05bfb7369d458667a8]), partition=
I20260812 06:20:24.039283 32210 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet cb79f463b3134f4e92ef4c0b61880519. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:24.041307 32270 tablet_bootstrap.cc:492] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Bootstrap starting.
I20260812 06:20:24.042163 32270 tablet_bootstrap.cc:654] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:24.043174 32270 tablet_bootstrap.cc:492] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: No bootstrap required, opened a new log
I20260812 06:20:24.043272 32270 ts_tablet_manager.cc:1403] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:24.043751 32270 raft_consensus.cc:359] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e5fb498d4352407d8c2fb720306cec73" member_type: VOTER last_known_addr { host: "127.31.22.193" port: 33399 } }
I20260812 06:20:24.043843 32270 raft_consensus.cc:385] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:24.043865 32270 raft_consensus.cc:740] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e5fb498d4352407d8c2fb720306cec73, State: Initialized, Role: FOLLOWER
I20260812 06:20:24.044059 32270 consensus_queue.cc:260] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73 [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: "e5fb498d4352407d8c2fb720306cec73" member_type: VOTER last_known_addr { host: "127.31.22.193" port: 33399 } }
I20260812 06:20:24.044147 32270 raft_consensus.cc:399] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:24.044190 32270 raft_consensus.cc:493] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:24.044251 32270 raft_consensus.cc:3060] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:24.045106 32270 raft_consensus.cc:515] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e5fb498d4352407d8c2fb720306cec73" member_type: VOTER last_known_addr { host: "127.31.22.193" port: 33399 } }
I20260812 06:20:24.045261 32270 leader_election.cc:304] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73 [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: e5fb498d4352407d8c2fb720306cec73; no voters: 
I20260812 06:20:24.045483 32270 leader_election.cc:290] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:24.045629 32274 raft_consensus.cc:2804] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:24.045869 32270 ts_tablet_manager.cc:1434] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:24.045847 32274 raft_consensus.cc:697] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73 [term 1 LEADER]: Becoming Leader. State: Replica: e5fb498d4352407d8c2fb720306cec73, State: Running, Role: LEADER
I20260812 06:20:24.045864 32256 heartbeater.cc:499] Master 127.31.22.254:41369 was elected leader, sending a full tablet report...
I20260812 06:20:24.046047 32274 consensus_queue.cc:237] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73 [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: "e5fb498d4352407d8c2fb720306cec73" member_type: VOTER last_known_addr { host: "127.31.22.193" port: 33399 } }
I20260812 06:20:24.047302 32095 catalog_manager.cc:5719] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73 reported cstate change: term changed from 0 to 1, leader changed from <none> to e5fb498d4352407d8c2fb720306cec73 (127.31.22.193). New cstate: current_term: 1 leader_uuid: "e5fb498d4352407d8c2fb720306cec73" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e5fb498d4352407d8c2fb720306cec73" member_type: VOTER last_known_addr { host: "127.31.22.193" port: 33399 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:24.107060 31835 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.008s	sys 0.014s
I20260812 06:20:24.264008 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushMRSOp(cb79f463b3134f4e92ef4c0b61880519): perf score=19.054940
I20260812 06:20:24.421640 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushMRSOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.157s	user 0.112s	sys 0.040s Metrics: {"bytes_written":13661285,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":206,"dirs.run_wall_time_us":881,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40217,"lbm_writes_lt_1ms":800,"mutex_wait_us":1102,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":26880,"update_count":1665}
I20260812 06:20:24.423024 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=1.196750
I20260812 06:20:24.440711 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.018s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3241138,"delete_count":0,"lbm_write_time_us":3354,"lbm_writes_lt_1ms":82,"reinsert_count":0,"update_count":395}
I20260812 06:20:24.441170 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling LogGCOp(cb79f463b3134f4e92ef4c0b61880519): free 20743880 bytes of WAL
I20260812 06:20:24.441439 32181 log_reader.cc:385] T cb79f463b3134f4e92ef4c0b61880519: removed 2 log segments from log reader
I20260812 06:20:24.441517 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000001 (ops 1-6)
I20260812 06:20:24.441635 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000002 (ops 7-11)
I20260812 06:20:24.447173 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: LogGCOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.006s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:24.447499 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=2.188937
I20260812 06:20:24.459337 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3200105,"delete_count":0,"lbm_write_time_us":4035,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:20:24.459964 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling UndoDeltaBlockGCOp(cb79f463b3134f4e92ef4c0b61880519): 16821647 bytes on disk
I20260812 06:20:24.460534 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: UndoDeltaBlockGCOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:20:24.461107 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519): perf score=1.000000
I20260812 06:20:24.624432 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.163s	user 0.115s	sys 0.048s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405523,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":537,"lbm_read_time_us":12179,"lbm_reads_lt_1ms":559,"lbm_write_time_us":29417,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":7296,"thread_start_us":327,"threads_started":5,"update_count":2450}
I20260812 06:20:24.625069 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=14.095187
I20260812 06:20:24.680042 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.055s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21436,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.680516 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=2.188937
I20260812 06:20:24.691103 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3833,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.691636 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519): perf score=1.000000
I20260812 06:20:24.857267 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.165s	user 0.100s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":728,"lbm_read_time_us":11905,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28507,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24448,"update_count":2500}
I20260812 06:20:24.858033 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=14.095187
I20260812 06:20:24.909166 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.051s	user 0.025s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22032,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.910362 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519): perf score=1.000000
I20260812 06:20:25.079437 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.169s	user 0.129s	sys 0.028s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":149,"lbm_read_time_us":13641,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22924,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2000}
I20260812 06:20:25.080221 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=14.095187
I20260812 06:20:25.126407 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.046s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20276,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.126922 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=2.188937
I20260812 06:20:25.142915 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6299,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.143453 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519): perf score=1.000000
I20260812 06:20:25.338177 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.195s	user 0.103s	sys 0.085s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":771,"lbm_read_time_us":12698,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30143,"lbm_writes_lt_1ms":543,"mutex_wait_us":78,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2500}
I20260812 06:20:25.338815 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=14.095187
I20260812 06:20:25.395947 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.057s	user 0.027s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23115,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.396416 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=2.188937
I20260812 06:20:25.407322 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4053,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.407836 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519): perf score=1.000000
I20260812 06:20:25.566767 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.159s	user 0.118s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":695,"lbm_read_time_us":11994,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29735,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2500}
I20260812 06:20:25.567371 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=11.118625
I20260812 06:20:25.601379 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.034s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14952,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:25.601933 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=2.188937
I20260812 06:20:25.617511 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5598,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:25.618161 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519): perf score=1.000000
I20260812 06:20:25.752529 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.134s	user 0.098s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713264,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":394,"lbm_read_time_us":7854,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26449,"lbm_writes_lt_1ms":443,"mutex_wait_us":82,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:20:25.753412 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=10.126437
I20260812 06:20:25.804282 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.050s	user 0.027s	sys 0.016s Metrics: {"bytes_written":12307555,"delete_count":0,"lbm_write_time_us":19362,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:25.804831 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=2.188937
I20260812 06:20:25.816885 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4304,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.817412 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushMRSOp(cb79f463b3134f4e92ef4c0b61880519): perf score=1.000000
I20260812 06:20:25.854019 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushMRSOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.036s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":206,"dirs.run_wall_time_us":1316,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1724,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:25.854657 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling LogGCOp(cb79f463b3134f4e92ef4c0b61880519): free 133024383 bytes of WAL
I20260812 06:20:25.854920 32181 log_reader.cc:385] T cb79f463b3134f4e92ef4c0b61880519: removed 13 log segments from log reader
I20260812 06:20:25.854987 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000003 (ops 12-16)
I20260812 06:20:25.855018 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000004 (ops 17-21)
I20260812 06:20:25.855037 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000005 (ops 22-26)
I20260812 06:20:25.855114 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000006 (ops 27-31)
I20260812 06:20:25.855194 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000007 (ops 32-36)
I20260812 06:20:25.855247 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000008 (ops 37-41)
I20260812 06:20:25.855293 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000009 (ops 42-46)
I20260812 06:20:25.855337 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000010 (ops 47-50)
I20260812 06:20:25.855388 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000011 (ops 51-55)
I20260812 06:20:25.855429 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000012 (ops 56-60)
I20260812 06:20:25.855496 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000013 (ops 61-65)
I20260812 06:20:25.855541 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000014 (ops 66-70)
I20260812 06:20:25.855602 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000015 (ops 71-75)
I20260812 06:20:25.887202 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: LogGCOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.032s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:20:25.887686 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling UndoDeltaBlockGCOp(cb79f463b3134f4e92ef4c0b61880519): 483 bytes on disk
I20260812 06:20:25.888106 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: UndoDeltaBlockGCOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:20:25.888574 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=6.157687
I20260812 06:20:25.915149 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.026s	user 0.019s	sys 0.004s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":11097,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:25.915717 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519): perf score=1.000000
I20260812 06:20:26.103611 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.188s	user 0.146s	sys 0.041s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918280,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":477,"lbm_read_time_us":12307,"lbm_reads_lt_1ms":665,"lbm_write_time_us":40302,"lbm_writes_lt_1ms":643,"mutex_wait_us":37,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":75,"threads_started":1,"update_count":3000}
I20260812 06:20:26.105752 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=15.087375
I20260812 06:20:26.161237 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.055s	user 0.032s	sys 0.019s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":21054,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:26.161648 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=2.188937
I20260812 06:20:26.172066 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3985,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.172513 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=2.188937
I20260812 06:20:26.186368 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.014s	user 0.005s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5413,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:26.186780 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519): perf score=1.000000
I20260812 06:20:26.355536 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.169s	user 0.126s	sys 0.041s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918202,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1305,"lbm_read_time_us":10629,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36448,"lbm_writes_lt_1ms":643,"mutex_wait_us":355,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":3000}
I20260812 06:20:26.356181 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=14.095187
I20260812 06:20:26.410413 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.054s	user 0.015s	sys 0.033s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22470,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.410880 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=2.188937
I20260812 06:20:26.426312 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5836,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.426962 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519): perf score=1.000000
I20260812 06:20:26.584591 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.157s	user 0.110s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":694,"lbm_read_time_us":10785,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28949,"lbm_writes_lt_1ms":543,"mutex_wait_us":343,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19072,"update_count":2500}
I20260812 06:20:26.585258 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=14.095187
I20260812 06:20:26.630141 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.045s	user 0.032s	sys 0.010s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20111,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.630663 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519): perf score=1.000000
I20260812 06:20:26.792153 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.161s	user 0.111s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":858,"lbm_read_time_us":11325,"lbm_reads_lt_1ms":467,"lbm_write_time_us":25481,"lbm_writes_lt_1ms":443,"mutex_wait_us":282,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":2000}
I20260812 06:20:26.792694 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=14.095187
I20260812 06:20:26.848556 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.056s	user 0.037s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22548,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.849069 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=2.188937
I20260812 06:20:26.860208 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4105,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.860694 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519): perf score=1.000000
I20260812 06:20:27.063428 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.203s	user 0.140s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":331,"lbm_read_time_us":12040,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34413,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":40192,"update_count":2500}
I20260812 06:20:27.064232 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=14.095187
I20260812 06:20:27.120044 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.056s	user 0.041s	sys 0.009s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":22603,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.120625 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=2.188937
I20260812 06:20:27.131528 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4280,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.132339 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519): perf score=1.000000
I20260812 06:20:27.287781 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.155s	user 0.131s	sys 0.019s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815680,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":861,"lbm_read_time_us":11824,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29888,"lbm_writes_lt_1ms":543,"mutex_wait_us":297,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:20:27.288494 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=11.118625
I20260812 06:20:27.316779 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.028s	user 0.011s	sys 0.016s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":12152,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:27.317302 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=2.188937
I20260812 06:20:27.333478 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.016s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5404,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:27.334663 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushMRSOp(cb79f463b3134f4e92ef4c0b61880519): perf score=1.000000
I20260812 06:20:27.387683 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushMRSOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.053s	user 0.036s	sys 0.000s Metrics: {"bytes_written":1316415,"cfile_init":1,"dirs.queue_time_us":40,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":1423,"drs_written":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2031,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:27.388375 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling LogGCOp(cb79f463b3134f4e92ef4c0b61880519): free 128867486 bytes of WAL
I20260812 06:20:27.388626 32181 log_reader.cc:385] T cb79f463b3134f4e92ef4c0b61880519: removed 13 log segments from log reader
I20260812 06:20:27.388669 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000016 (ops 76-80)
I20260812 06:20:27.388697 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000017 (ops 81-84)
I20260812 06:20:27.388754 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000018 (ops 85-89)
I20260812 06:20:27.388818 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000019 (ops 90-94)
I20260812 06:20:27.388864 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000020 (ops 95-99)
I20260812 06:20:27.388904 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000021 (ops 100-104)
I20260812 06:20:27.388948 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000022 (ops 105-109)
I20260812 06:20:27.388988 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000023 (ops 110-114)
I20260812 06:20:27.389050 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000024 (ops 115-118)
I20260812 06:20:27.389091 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000025 (ops 119-123)
I20260812 06:20:27.389130 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000026 (ops 124-128)
I20260812 06:20:27.389169 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000027 (ops 129-132)
I20260812 06:20:27.389209 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000028 (ops 133-137)
I20260812 06:20:27.418164 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: LogGCOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.030s	user 0.001s	sys 0.026s Metrics: {}
I20260812 06:20:27.418664 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling UndoDeltaBlockGCOp(cb79f463b3134f4e92ef4c0b61880519): 492 bytes on disk
I20260812 06:20:27.419116 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: UndoDeltaBlockGCOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:20:27.419796 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=7.149875
I20260812 06:20:27.454918 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.035s	user 0.016s	sys 0.016s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":10082,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:20:27.455494 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=2.188937
I20260812 06:20:27.465035 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3542,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:27.465489 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519): perf score=1.000000
I20260812 06:20:27.699107 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.233s	user 0.152s	sys 0.074s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020728,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3128,"lbm_read_time_us":15801,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38659,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":116,"threads_started":1,"update_count":3500}
I20260812 06:20:27.699805 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=18.063937
I20260812 06:20:27.765965 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.066s	user 0.039s	sys 0.021s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":28292,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:27.766469 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=2.188937
I20260812 06:20:27.781594 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5753,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.782161 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519): perf score=1.000000
I20260812 06:20:28.011070 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.229s	user 0.127s	sys 0.090s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1027,"lbm_read_time_us":15470,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36282,"lbm_writes_lt_1ms":643,"mutex_wait_us":249,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":3000}
I20260812 06:20:28.011860 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=18.063937
I20260812 06:20:28.081420 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.069s	user 0.024s	sys 0.033s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":26118,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:28.081928 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=2.188937
I20260812 06:20:28.094146 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4654,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.094732 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519): perf score=1.000000
I20260812 06:20:28.322362 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.227s	user 0.128s	sys 0.091s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":321,"lbm_read_time_us":16491,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36843,"lbm_writes_lt_1ms":643,"mutex_wait_us":54,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:20:28.323055 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=18.063937
I20260812 06:20:28.389205 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.066s	user 0.017s	sys 0.036s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":24351,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:28.389680 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=2.188937
I20260812 06:20:28.400614 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4162,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.401466 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519): perf score=1.000000
I20260812 06:20:28.614703 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.213s	user 0.128s	sys 0.078s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":331,"lbm_read_time_us":14883,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35087,"lbm_writes_lt_1ms":643,"mutex_wait_us":43,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":37248,"update_count":3000}
I20260812 06:20:28.615465 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=16.079562
I20260812 06:20:28.668810 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.053s	user 0.026s	sys 0.021s Metrics: {"bytes_written":17927795,"delete_count":0,"lbm_write_time_us":21647,"lbm_writes_lt_1ms":440,"mutex_wait_us":33,"reinsert_count":0,"update_count":2185}
I20260812 06:20:28.669306 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=1.196750
I20260812 06:20:28.680281 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.011s	user 0.007s	sys 0.001s Metrics: {"bytes_written":2994984,"delete_count":0,"lbm_write_time_us":3135,"lbm_writes_lt_1ms":76,"reinsert_count":0,"update_count":365}
I20260812 06:20:28.680711 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=2.188937
I20260812 06:20:28.690120 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3722,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.690572 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519): perf score=1.000000
I20260812 06:20:28.904798 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.214s	user 0.146s	sys 0.063s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918179,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":233,"lbm_read_time_us":15064,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34530,"lbm_writes_lt_1ms":643,"mutex_wait_us":88,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":3000}
I20260812 06:20:28.905539 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=16.079562
I20260812 06:20:28.953641 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.048s	user 0.034s	sys 0.012s Metrics: {"bytes_written":17886769,"delete_count":0,"lbm_write_time_us":21039,"lbm_writes_lt_1ms":439,"reinsert_count":0,"update_count":2180}
I20260812 06:20:28.954366 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=1.196750
I20260812 06:20:28.964731 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3036009,"delete_count":0,"lbm_write_time_us":3452,"lbm_writes_lt_1ms":77,"reinsert_count":0,"update_count":370}
I20260812 06:20:28.965231 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushMRSOp(cb79f463b3134f4e92ef4c0b61880519): perf score=1.000000
I20260812 06:20:28.975719 31835 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.869s	user 1.757s	sys 0.205s
I20260812 06:20:29.011051 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushMRSOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.046s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1316415,"cfile_init":1,"dirs.queue_time_us":102,"dirs.run_cpu_time_us":220,"dirs.run_wall_time_us":1522,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1804,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:29.011855 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling LogGCOp(cb79f463b3134f4e92ef4c0b61880519): free 132571597 bytes of WAL
I20260812 06:20:29.012104 32181 log_reader.cc:385] T cb79f463b3134f4e92ef4c0b61880519: removed 13 log segments from log reader
I20260812 06:20:29.012156 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000029 (ops 138-142)
I20260812 06:20:29.012190 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000030 (ops 143-146)
I20260812 06:20:29.012265 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000031 (ops 147-151)
I20260812 06:20:29.012315 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000032 (ops 152-156)
I20260812 06:20:29.012365 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000033 (ops 157-161)
I20260812 06:20:29.012415 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000034 (ops 162-166)
I20260812 06:20:29.012460 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000035 (ops 167-171)
I20260812 06:20:29.012511 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000036 (ops 172-176)
I20260812 06:20:29.012559 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000037 (ops 177-181)
I20260812 06:20:29.012614 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000038 (ops 182-186)
I20260812 06:20:29.012660 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000039 (ops 187-191)
I20260812 06:20:29.012706 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000040 (ops 192-196)
I20260812 06:20:29.012751 32181 log.cc:1079] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: Deleting log segment in path: /tmp/dist-test-taskZOFqxd/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618545731-31835-0/minicluster-data/ts-0-root/wals/cb79f463b3134f4e92ef4c0b61880519/wal-000000041 (ops 197-200)
I20260812 06:20:29.037794 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: LogGCOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:20:29.038288 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling UndoDeltaBlockGCOp(cb79f463b3134f4e92ef4c0b61880519): 493 bytes on disk
I20260812 06:20:29.038761 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: UndoDeltaBlockGCOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:20:29.039331 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519): perf score=2.188937
I20260812 06:20:29.049994 31835 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.074s	user 0.001s	sys 0.000s
I20260812 06:20:29.050490 31835 tablet_server.cc:179] TabletServer@127.31.22.193:0 shutting down...
I20260812 06:20:29.051445 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: FlushDeltaMemStoresOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4457,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:29.052120 32257 maintenance_manager.cc:419] P e5fb498d4352407d8c2fb720306cec73: Scheduling MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519): perf score=1.000000
I20260812 06:20:29.191187 32181 maintenance_manager.cc:643] P e5fb498d4352407d8c2fb720306cec73: MajorDeltaCompactionOp(cb79f463b3134f4e92ef4c0b61880519) complete. Timing: real 0.139s	user 0.098s	sys 0.040s Metrics: {"cfile_cache_hit":542,"cfile_cache_hit_bytes":25225901,"cfile_cache_miss":91,"cfile_cache_miss_bytes":3692277,"cfile_init":3,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1793,"lbm_read_time_us":1545,"lbm_reads_lt_1ms":103,"lbm_write_time_us":30997,"lbm_writes_lt_1ms":643,"mutex_wait_us":917,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4480,"thread_start_us":93,"threads_started":1,"update_count":3000}
I20260812 06:20:29.191953 31835 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:29.192188 31835 tablet_replica.cc:333] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73: stopping tablet replica
I20260812 06:20:29.192328 31835 raft_consensus.cc:2243] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:29.192526 31835 raft_consensus.cc:2272] T cb79f463b3134f4e92ef4c0b61880519 P e5fb498d4352407d8c2fb720306cec73 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:29.197652 31835 tablet_server.cc:196] TabletServer@127.31.22.193:0 shutdown complete.
I20260812 06:20:29.242225 31835 master.cc:562] Master@127.31.22.254:41369 shutting down...
I20260812 06:20:29.245581 31835 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:29.245736 31835 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:29.245786 31835 tablet_replica.cc:333] T 00000000000000000000000000000000 P 8bfe00e151414289880fecc5720a6785: stopping tablet replica
I20260812 06:20:29.258065 31835 master.cc:584] Master@127.31.22.254:41369 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5479 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10788 ms total)

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