[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:16:23.531327 31466 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.30.186.190:44483
I20260812 06:16:23.532698 31466 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:16:23.533747 31466 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:23.542655 31476 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:16:23.542976 31466 server_base.cc:1061] running on GCE node
W20260812 06:16:23.543023 31473 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:23.542892 31474 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:23.544001 31466 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:23.544129 31466 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:23.544193 31466 hybrid_clock.cc:648] HybridClock initialized: now 1786515383544188 us; error 0 us; skew 500 ppm
I20260812 06:16:23.546670 31466 webserver.cc:533] Webserver started at http://127.30.186.190:46467/ using document root <none> and password file <none>
I20260812 06:16:23.547403 31466 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:23.547497 31466 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:23.547812 31466 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:23.550084 31466 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/master-0-root/instance:
uuid: "4fb047b5b1e1482ca2f590b03e484419"
format_stamp: "Formatted at 2026-08-12 06:16:23 on dist-test-slave-77v9"
I20260812 06:16:23.555207 31466 fs_manager.cc:696] Time spent creating directory manager: real 0.005s	user 0.003s	sys 0.002s
I20260812 06:16:23.558845 31481 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:23.560292 31466 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:16:23.560523 31466 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/master-0-root
uuid: "4fb047b5b1e1482ca2f590b03e484419"
format_stamp: "Formatted at 2026-08-12 06:16:23 on dist-test-slave-77v9"
I20260812 06:16:23.560683 31466 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:23.591892 31466 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:23.592773 31466 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:16:23.593241 31466 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:23.603408 31466 rpc_server.cc:307] RPC server started. Bound to: 127.30.186.190:44483
I20260812 06:16:23.603408 31541 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.186.190:44483 every 8 connection(s)
I20260812 06:16:23.606400 31542 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:23.614660 31542 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419: Bootstrap starting.
I20260812 06:16:23.617590 31542 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:23.619196 31542 log.cc:826] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:23.621682 31542 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419: No bootstrap required, opened a new log
I20260812 06:16:23.625221 31542 raft_consensus.cc:359] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4fb047b5b1e1482ca2f590b03e484419" member_type: VOTER }
I20260812 06:16:23.625479 31542 raft_consensus.cc:385] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:23.625579 31542 raft_consensus.cc:740] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4fb047b5b1e1482ca2f590b03e484419, State: Initialized, Role: FOLLOWER
I20260812 06:16:23.626428 31542 consensus_queue.cc:260] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419 [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: "4fb047b5b1e1482ca2f590b03e484419" member_type: VOTER }
I20260812 06:16:23.626646 31542 raft_consensus.cc:399] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:23.626703 31542 raft_consensus.cc:493] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:23.626807 31542 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:23.627789 31542 raft_consensus.cc:515] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4fb047b5b1e1482ca2f590b03e484419" member_type: VOTER }
I20260812 06:16:23.628325 31542 leader_election.cc:304] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419 [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: 4fb047b5b1e1482ca2f590b03e484419; no voters: 
I20260812 06:16:23.628671 31542 leader_election.cc:290] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:23.628957 31545 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:23.629272 31545 raft_consensus.cc:697] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419 [term 1 LEADER]: Becoming Leader. State: Replica: 4fb047b5b1e1482ca2f590b03e484419, State: Running, Role: LEADER
I20260812 06:16:23.629787 31545 consensus_queue.cc:237] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419 [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: "4fb047b5b1e1482ca2f590b03e484419" member_type: VOTER }
I20260812 06:16:23.630015 31542 sys_catalog.cc:565] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:23.632108 31548 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 4fb047b5b1e1482ca2f590b03e484419. Latest consensus state: current_term: 1 leader_uuid: "4fb047b5b1e1482ca2f590b03e484419" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4fb047b5b1e1482ca2f590b03e484419" member_type: VOTER } }
I20260812 06:16:23.632294 31548 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:23.632143 31547 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "4fb047b5b1e1482ca2f590b03e484419" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4fb047b5b1e1482ca2f590b03e484419" member_type: VOTER } }
I20260812 06:16:23.632369 31547 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:23.632723 31562 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:23.632758 31466 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:23.635483 31562 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:23.641827 31562 catalog_manager.cc:1383] Generated new cluster ID: 1592b7578dd9476a9a3a66db51a0ae2a
I20260812 06:16:23.641947 31562 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:23.669103 31562 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:23.670259 31562 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:23.679059 31562 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419: Generated new TSK 0
I20260812 06:16:23.679965 31562 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:23.698658 31466 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:23.703070 31568 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:23.703042 31569 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:23.703636 31466 server_base.cc:1061] running on GCE node
W20260812 06:16:23.703987 31572 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:16:23.704350 31466 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:23.704449 31466 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:23.704493 31466 hybrid_clock.cc:648] HybridClock initialized: now 1786515383704492 us; error 0 us; skew 500 ppm
I20260812 06:16:23.705760 31466 webserver.cc:533] Webserver started at http://127.30.186.129:43419/ using document root <none> and password file <none>
I20260812 06:16:23.706004 31466 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:23.706092 31466 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:23.706192 31466 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:23.706718 31466 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/instance:
uuid: "8a05876fb979470daf7232b16ff13d5b"
format_stamp: "Formatted at 2026-08-12 06:16:23 on dist-test-slave-77v9"
I20260812 06:16:23.710088 31466 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.002s
I20260812 06:16:23.711565 31578 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:23.711941 31466 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:23.712037 31466 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root
uuid: "8a05876fb979470daf7232b16ff13d5b"
format_stamp: "Formatted at 2026-08-12 06:16:23 on dist-test-slave-77v9"
I20260812 06:16:23.712172 31466 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:23.718031 31466 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:23.718672 31466 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:23.719316 31466 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:23.720526 31466 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:23.720640 31466 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:23.721027 31466 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:23.721263 31466 ts_tablet_manager.cc:595] Time spent register tablets: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:23.738597 31466 rpc_server.cc:307] RPC server started. Bound to: 127.30.186.129:34577
I20260812 06:16:23.738863 31650 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.186.129:34577 every 8 connection(s)
I20260812 06:16:23.757993 31651 heartbeater.cc:344] Connected to a master server at 127.30.186.190:44483
I20260812 06:16:23.758638 31651 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:23.759485 31651 heartbeater.cc:507] Master 127.30.186.190:44483 requested a full tablet report, sending...
I20260812 06:16:23.762068 31499 ts_manager.cc:194] Registered new tserver with Master: 8a05876fb979470daf7232b16ff13d5b (127.30.186.129:34577)
I20260812 06:16:23.762128 31466 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.022489036s
I20260812 06:16:23.763808 31499 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:33916
I20260812 06:16:23.776254 31499 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:33930:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:16:23.802048 31610 tablet_service.cc:1511] Processing CreateTablet for tablet dc4fbadaaa284589912b2297a69ba479 (DEFAULT_TABLE table=heavy-update-compaction-test [id=e47e423e668f46978da218c0c953ce36]), partition=
I20260812 06:16:23.802654 31610 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet dc4fbadaaa284589912b2297a69ba479. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:23.805640 31666 tablet_bootstrap.cc:492] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Bootstrap starting.
I20260812 06:16:23.807268 31666 tablet_bootstrap.cc:654] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:23.809973 31666 tablet_bootstrap.cc:492] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: No bootstrap required, opened a new log
I20260812 06:16:23.810158 31666 ts_tablet_manager.cc:1403] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Time spent bootstrapping tablet: real 0.005s	user 0.003s	sys 0.000s
I20260812 06:16:23.810895 31666 raft_consensus.cc:359] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8a05876fb979470daf7232b16ff13d5b" member_type: VOTER last_known_addr { host: "127.30.186.129" port: 34577 } }
I20260812 06:16:23.811107 31666 raft_consensus.cc:385] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:23.811158 31666 raft_consensus.cc:740] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8a05876fb979470daf7232b16ff13d5b, State: Initialized, Role: FOLLOWER
I20260812 06:16:23.811326 31666 consensus_queue.cc:260] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b [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: "8a05876fb979470daf7232b16ff13d5b" member_type: VOTER last_known_addr { host: "127.30.186.129" port: 34577 } }
I20260812 06:16:23.811473 31666 raft_consensus.cc:399] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:23.811535 31666 raft_consensus.cc:493] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:23.811597 31666 raft_consensus.cc:3060] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:23.812958 31666 raft_consensus.cc:515] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8a05876fb979470daf7232b16ff13d5b" member_type: VOTER last_known_addr { host: "127.30.186.129" port: 34577 } }
I20260812 06:16:23.813265 31666 leader_election.cc:304] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b [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: 8a05876fb979470daf7232b16ff13d5b; no voters: 
I20260812 06:16:23.813606 31666 leader_election.cc:290] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:23.813989 31668 raft_consensus.cc:2804] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:23.814271 31668 raft_consensus.cc:697] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b [term 1 LEADER]: Becoming Leader. State: Replica: 8a05876fb979470daf7232b16ff13d5b, State: Running, Role: LEADER
I20260812 06:16:23.814266 31666 ts_tablet_manager.cc:1434] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Time spent starting tablet: real 0.004s	user 0.000s	sys 0.005s
I20260812 06:16:23.814494 31651 heartbeater.cc:499] Master 127.30.186.190:44483 was elected leader, sending a full tablet report...
I20260812 06:16:23.815171 31668 consensus_queue.cc:237] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b [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: "8a05876fb979470daf7232b16ff13d5b" member_type: VOTER last_known_addr { host: "127.30.186.129" port: 34577 } }
I20260812 06:16:23.820192 31499 catalog_manager.cc:5719] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b reported cstate change: term changed from 0 to 1, leader changed from <none> to 8a05876fb979470daf7232b16ff13d5b (127.30.186.129). New cstate: current_term: 1 leader_uuid: "8a05876fb979470daf7232b16ff13d5b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8a05876fb979470daf7232b16ff13d5b" member_type: VOTER last_known_addr { host: "127.30.186.129" port: 34577 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:23.910406 31466 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.078s	user 0.024s	sys 0.008s
I20260812 06:16:23.990550 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushMRSOp(dc4fbadaaa284589912b2297a69ba479): perf score=7.148690
I20260812 06:16:24.197525 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushMRSOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.206s	user 0.120s	sys 0.071s Metrics: {"bytes_written":8902491,"cfile_init":1,"compiler_manager_pool.queue_time_us":263,"delete_count":0,"dirs.queue_time_us":111,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":1090,"drs_written":1,"lbm_read_time_us":87,"lbm_reads_lt_1ms":4,"lbm_write_time_us":70097,"lbm_writes_lt_1ms":384,"mutex_wait_us":713,"peak_mem_usage":0,"reinsert_count":0,"rows_written":102,"spinlock_wait_cycles":155904,"thread_start_us":174,"threads_started":1,"update_count":1085}
I20260812 06:16:24.199203 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling LogGCOp(dc4fbadaaa284589912b2297a69ba479): free 8725963 bytes of WAL
I20260812 06:16:24.199635 31584 log_reader.cc:385] T dc4fbadaaa284589912b2297a69ba479: removed 1 log segments from log reader
I20260812 06:16:24.199717 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000001 (ops 1-6)
I20260812 06:16:24.203122 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: LogGCOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:24.203682 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=5.165500
I20260812 06:16:24.243435 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.039s	user 0.013s	sys 0.012s Metrics: {"bytes_written":7097429,"delete_count":0,"lbm_write_time_us":12050,"lbm_writes_lt_1ms":176,"reinsert_count":0,"update_count":865}
I20260812 06:16:24.244175 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=2.188937
I20260812 06:16:24.262759 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.018s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7440,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.263317 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479): perf score=1.000000
I20260812 06:16:24.454749 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.191s	user 0.136s	sys 0.055s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24282642,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":713,"lbm_read_time_us":13146,"lbm_reads_lt_1ms":563,"lbm_write_time_us":35741,"lbm_writes_lt_1ms":533,"mutex_wait_us":26,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":13696,"thread_start_us":359,"threads_started":5,"update_count":2450}
I20260812 06:16:24.455521 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=10.126437
I20260812 06:16:24.509620 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.054s	user 0.034s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":24781,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:24.510352 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling UndoDeltaBlockGCOp(dc4fbadaaa284589912b2297a69ba479): 4514099 bytes on disk
I20260812 06:16:24.511030 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: UndoDeltaBlockGCOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4}
I20260812 06:16:24.511655 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=2.188937
I20260812 06:16:24.527300 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6309,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.528000 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479): perf score=1.000000
I20260812 06:16:24.704779 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.177s	user 0.134s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1252,"lbm_read_time_us":11251,"lbm_reads_lt_1ms":472,"lbm_write_time_us":36355,"lbm_writes_lt_1ms":443,"mutex_wait_us":140,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2000}
I20260812 06:16:24.705842 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=11.118625
I20260812 06:16:24.764595 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.059s	user 0.017s	sys 0.037s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":21590,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:24.765352 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=2.188937
I20260812 06:16:24.779341 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.014s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4809,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:24.780103 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479): perf score=1.000000
I20260812 06:16:24.971372 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.191s	user 0.142s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1019,"lbm_read_time_us":15530,"lbm_reads_lt_1ms":472,"lbm_write_time_us":32518,"lbm_writes_lt_1ms":443,"mutex_wait_us":182,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:16:24.972221 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=10.126437
I20260812 06:16:25.016135 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.044s	user 0.030s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19693,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:25.016896 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=2.188937
I20260812 06:16:25.031913 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5639,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.032497 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479): perf score=1.000000
I20260812 06:16:25.188179 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.155s	user 0.123s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590348,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":345,"lbm_read_time_us":10236,"lbm_reads_lt_1ms":464,"lbm_write_time_us":31772,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":25088,"update_count":2000}
I20260812 06:16:25.188901 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=10.126437
I20260812 06:16:25.234733 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.045s	user 0.027s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20963,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:25.235407 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=2.188937
I20260812 06:16:25.249897 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4939,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.250546 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479): perf score=1.000000
I20260812 06:16:25.405720 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.155s	user 0.115s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":281,"lbm_read_time_us":9811,"lbm_reads_lt_1ms":472,"lbm_write_time_us":32198,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22144,"update_count":2000}
I20260812 06:16:25.407004 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=10.126437
I20260812 06:16:25.467820 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.061s	user 0.028s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":23200,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:25.468513 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=2.188937
I20260812 06:16:25.480079 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4217,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.480815 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479): perf score=1.000000
I20260812 06:16:25.630965 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.150s	user 0.124s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1184,"lbm_read_time_us":10611,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29708,"lbm_writes_lt_1ms":443,"mutex_wait_us":476,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":40704,"update_count":2000}
I20260812 06:16:25.632105 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=10.126437
I20260812 06:16:25.688107 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.056s	user 0.029s	sys 0.023s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19083,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:25.689114 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=2.188937
I20260812 06:16:25.708281 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.019s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7251,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.709764 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushMRSOp(dc4fbadaaa284589912b2297a69ba479): perf score=1.000000
I20260812 06:16:25.762652 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushMRSOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.053s	user 0.035s	sys 0.001s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":259,"dirs.run_wall_time_us":2180,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2547,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:25.763878 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling LogGCOp(dc4fbadaaa284589912b2297a69ba479): free 115943135 bytes of WAL
I20260812 06:16:25.764134 31584 log_reader.cc:385] T dc4fbadaaa284589912b2297a69ba479: removed 11 log segments from log reader
I20260812 06:16:25.764179 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000002 (ops 7-11)
I20260812 06:16:25.764235 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000003 (ops 12-16)
I20260812 06:16:25.764285 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000004 (ops 17-21)
I20260812 06:16:25.764325 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000005 (ops 22-26)
I20260812 06:16:25.764381 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000006 (ops 27-31)
I20260812 06:16:25.764423 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000007 (ops 32-36)
I20260812 06:16:25.764462 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000008 (ops 37-41)
I20260812 06:16:25.764500 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000009 (ops 42-46)
I20260812 06:16:25.764539 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000010 (ops 47-51)
I20260812 06:16:25.764576 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000011 (ops 52-56)
I20260812 06:16:25.764614 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000012 (ops 57-61)
I20260812 06:16:25.795904 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: LogGCOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.032s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:16:25.796452 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling UndoDeltaBlockGCOp(dc4fbadaaa284589912b2297a69ba479): 448 bytes on disk
I20260812 06:16:25.797108 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: UndoDeltaBlockGCOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":101,"lbm_reads_lt_1ms":4}
I20260812 06:16:25.797899 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=3.181125
I20260812 06:16:25.826020 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.028s	user 0.016s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":8294,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:25.826683 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=2.188937
I20260812 06:16:25.840447 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.014s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4960,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:25.841104 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479): perf score=1.000000
I20260812 06:16:26.082435 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.241s	user 0.170s	sys 0.064s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28795398,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":988,"lbm_read_time_us":15795,"lbm_reads_lt_1ms":674,"lbm_write_time_us":42751,"lbm_writes_lt_1ms":643,"mutex_wait_us":454,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4608,"thread_start_us":91,"threads_started":1,"update_count":3000}
I20260812 06:16:26.083242 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=14.095187
I20260812 06:16:26.144282 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.061s	user 0.038s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25654,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:26.145241 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479): perf score=1.000000
I20260812 06:16:26.326243 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.181s	user 0.132s	sys 0.041s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20590228,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":253,"lbm_read_time_us":13063,"lbm_reads_lt_1ms":463,"lbm_write_time_us":29646,"lbm_writes_lt_1ms":443,"mutex_wait_us":59,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2000}
I20260812 06:16:26.327062 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=14.095187
I20260812 06:16:26.391515 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.064s	user 0.047s	sys 0.008s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":25755,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:26.392549 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=2.188937
I20260812 06:16:26.407451 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5361,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.408493 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479): perf score=1.000000
I20260812 06:16:26.640303 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.232s	user 0.148s	sys 0.075s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692762,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2493,"lbm_read_time_us":13882,"lbm_reads_lt_1ms":572,"lbm_write_time_us":38950,"lbm_writes_lt_1ms":543,"mutex_wait_us":663,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:16:26.641687 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=14.095187
I20260812 06:16:26.718927 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.077s	user 0.039s	sys 0.034s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":35340,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:16:26.720471 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=2.188937
I20260812 06:16:26.740367 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.020s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6264,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.741078 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479): perf score=1.000000
I20260812 06:16:26.927341 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.186s	user 0.132s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692759,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":367,"lbm_read_time_us":10799,"lbm_reads_lt_1ms":564,"lbm_write_time_us":35084,"lbm_writes_lt_1ms":543,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:16:26.928190 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=14.095187
I20260812 06:16:26.991756 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.063s	user 0.033s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26270,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:26.992491 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=2.188937
I20260812 06:16:27.005894 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.013s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4639,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.006743 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479): perf score=1.000000
I20260812 06:16:27.199833 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.193s	user 0.130s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692758,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":699,"lbm_read_time_us":13669,"lbm_reads_lt_1ms":572,"lbm_write_time_us":38643,"lbm_writes_lt_1ms":543,"mutex_wait_us":325,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2500}
I20260812 06:16:27.200675 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=14.095187
I20260812 06:16:27.276927 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.076s	user 0.057s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":33829,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:27.277737 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=2.188937
I20260812 06:16:27.307924 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.030s	user 0.017s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":15080,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.308506 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479): perf score=1.000000
I20260812 06:16:27.491333 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.183s	user 0.142s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692758,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":479,"lbm_read_time_us":13905,"lbm_reads_lt_1ms":564,"lbm_write_time_us":37172,"lbm_writes_lt_1ms":543,"mutex_wait_us":30,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16640,"update_count":2500}
I20260812 06:16:27.492136 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=10.126437
I20260812 06:16:27.543313 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.051s	user 0.031s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21629,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:27.544075 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=2.188937
I20260812 06:16:27.575873 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.032s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7025,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.576719 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=2.188937
I20260812 06:16:27.588665 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4417,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.589570 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushMRSOp(dc4fbadaaa284589912b2297a69ba479): perf score=1.000000
I20260812 06:16:27.628429 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushMRSOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.039s	user 0.032s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":99,"dirs.run_cpu_time_us":334,"dirs.run_wall_time_us":2092,"drs_written":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1985,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:27.629748 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling LogGCOp(dc4fbadaaa284589912b2297a69ba479): free 128867448 bytes of WAL
I20260812 06:16:27.630162 31584 log_reader.cc:385] T dc4fbadaaa284589912b2297a69ba479: removed 13 log segments from log reader
I20260812 06:16:27.630244 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000013 (ops 62-66)
I20260812 06:16:27.630318 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000014 (ops 67-71)
I20260812 06:16:27.630386 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000015 (ops 72-76)
I20260812 06:16:27.630432 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000016 (ops 77-80)
I20260812 06:16:27.630478 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000017 (ops 81-85)
I20260812 06:16:27.630522 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000018 (ops 86-90)
I20260812 06:16:27.630563 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000019 (ops 91-94)
I20260812 06:16:27.630604 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000020 (ops 95-99)
I20260812 06:16:27.630648 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000021 (ops 100-104)
I20260812 06:16:27.630695 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000022 (ops 105-109)
I20260812 06:16:27.630738 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000023 (ops 110-114)
I20260812 06:16:27.630780 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000024 (ops 115-118)
I20260812 06:16:27.630822 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000025 (ops 119-123)
I20260812 06:16:27.676425 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: LogGCOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.046s	user 0.000s	sys 0.043s Metrics: {}
I20260812 06:16:27.677356 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=3.181125
I20260812 06:16:27.701596 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.024s	user 0.012s	sys 0.009s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":8479,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:27.702219 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling UndoDeltaBlockGCOp(dc4fbadaaa284589912b2297a69ba479): 482 bytes on disk
I20260812 06:16:27.702713 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: UndoDeltaBlockGCOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:16:27.703284 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=2.188937
I20260812 06:16:27.715160 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4125,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:27.715827 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479): perf score=1.000000
I20260812 06:16:27.947048 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.231s	user 0.175s	sys 0.056s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32897929,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":564,"lbm_read_time_us":18012,"lbm_reads_lt_1ms":775,"lbm_write_time_us":45365,"lbm_writes_lt_1ms":743,"mutex_wait_us":59,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":38400,"thread_start_us":88,"threads_started":1,"update_count":3500}
I20260812 06:16:27.947799 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=14.095187
I20260812 06:16:28.014715 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.064s	user 0.038s	sys 0.023s Metrics: {"bytes_written":16615021,"delete_count":0,"lbm_write_time_us":28027,"lbm_writes_lt_1ms":408,"mutex_wait_us":497,"reinsert_count":0,"update_count":2025}
I20260812 06:16:28.015599 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=2.188937
I20260812 06:16:28.035445 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.020s	user 0.009s	sys 0.008s Metrics: {"bytes_written":3897534,"delete_count":0,"lbm_write_time_us":7281,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:16:28.036134 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479): perf score=1.000000
I20260812 06:16:28.218336 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.182s	user 0.156s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692753,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":324,"lbm_read_time_us":13125,"lbm_reads_lt_1ms":568,"lbm_write_time_us":34778,"lbm_writes_lt_1ms":543,"mutex_wait_us":100,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2500}
I20260812 06:16:28.219574 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=14.095187
I20260812 06:16:28.279562 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.060s	user 0.038s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23925,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:28.280465 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479): perf score=1.000000
I20260812 06:16:28.452639 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.171s	user 0.125s	sys 0.044s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20590227,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1280,"lbm_read_time_us":11177,"lbm_reads_lt_1ms":463,"lbm_write_time_us":29124,"lbm_writes_lt_1ms":443,"mutex_wait_us":537,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:16:28.453496 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=11.118625
I20260812 06:16:28.504091 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.050s	user 0.024s	sys 0.023s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18795,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:28.504863 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=2.188937
I20260812 06:16:28.519484 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.014s	user 0.002s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4875,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:28.520161 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479): perf score=1.000000
I20260812 06:16:28.705694 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.185s	user 0.102s	sys 0.076s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":238,"lbm_read_time_us":13533,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28322,"lbm_writes_lt_1ms":443,"mutex_wait_us":75,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":902144,"update_count":2000}
I20260812 06:16:28.706561 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=11.118625
I20260812 06:16:28.755023 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.048s	user 0.015s	sys 0.028s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":20125,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:28.755555 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=2.188937
I20260812 06:16:28.768667 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4401,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:28.769325 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=2.188937
I20260812 06:16:28.780261 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3827,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:28.781399 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479): perf score=1.000000
I20260812 06:16:28.955790 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.174s	user 0.125s	sys 0.048s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24692871,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":838,"lbm_read_time_us":13774,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32224,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:16:28.956679 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=10.126437
I20260812 06:16:29.004609 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.048s	user 0.038s	sys 0.006s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20414,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:29.005548 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=2.188937
I20260812 06:16:29.028903 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.023s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7026,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.029731 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479): perf score=1.000000
I20260812 06:16:29.185721 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.156s	user 0.123s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590348,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":267,"lbm_read_time_us":9737,"lbm_reads_lt_1ms":464,"lbm_write_time_us":30493,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":68352,"update_count":2000}
I20260812 06:16:29.186573 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=10.126437
I20260812 06:16:29.238792 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.052s	user 0.034s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19630,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:29.239622 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=2.188937
I20260812 06:16:29.254554 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4830,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.255204 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushMRSOp(dc4fbadaaa284589912b2297a69ba479): perf score=1.000000
I20260812 06:16:29.294844 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushMRSOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.039s	user 0.033s	sys 0.004s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":294,"dirs.run_cpu_time_us":520,"dirs.run_wall_time_us":2281,"drs_written":1,"lbm_read_time_us":89,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2524,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:29.295748 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling LogGCOp(dc4fbadaaa284589912b2297a69ba479): free 112239589 bytes of WAL
I20260812 06:16:29.296031 31584 log_reader.cc:385] T dc4fbadaaa284589912b2297a69ba479: removed 11 log segments from log reader
I20260812 06:16:29.296100 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000026 (ops 124-128)
I20260812 06:16:29.296166 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000027 (ops 129-133)
I20260812 06:16:29.296226 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000028 (ops 134-138)
I20260812 06:16:29.296272 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000029 (ops 139-142)
I20260812 06:16:29.296315 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000030 (ops 143-147)
I20260812 06:16:29.296358 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000031 (ops 148-152)
I20260812 06:16:29.296411 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000032 (ops 153-157)
I20260812 06:16:29.296451 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000033 (ops 158-162)
I20260812 06:16:29.296494 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000034 (ops 163-167)
I20260812 06:16:29.296535 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000035 (ops 168-172)
I20260812 06:16:29.296577 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000036 (ops 173-177)
I20260812 06:16:29.324733 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: LogGCOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.029s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:16:29.325409 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=2.188937
I20260812 06:16:29.352218 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.027s	user 0.017s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7886,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.352970 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling LogGCOp(dc4fbadaaa284589912b2297a69ba479): free 12017954 bytes of WAL
I20260812 06:16:29.353206 31584 log_reader.cc:385] T dc4fbadaaa284589912b2297a69ba479: removed 1 log segments from log reader
I20260812 06:16:29.353257 31584 log.cc:1079] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/dc4fbadaaa284589912b2297a69ba479/wal-000000037 (ops 178-182)
I20260812 06:16:29.356715 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: LogGCOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.004s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:16:29.357293 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling UndoDeltaBlockGCOp(dc4fbadaaa284589912b2297a69ba479): 447 bytes on disk
I20260812 06:16:29.357867 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: UndoDeltaBlockGCOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4}
I20260812 06:16:29.358562 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=2.188937
I20260812 06:16:29.375466 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.017s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5996,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.376186 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479): perf score=1.000000
I20260812 06:16:29.588554 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.212s	user 0.137s	sys 0.064s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28795407,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1344,"lbm_read_time_us":14835,"lbm_reads_lt_1ms":674,"lbm_write_time_us":40920,"lbm_writes_lt_1ms":643,"mutex_wait_us":406,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":113,"threads_started":1,"update_count":3000}
I20260812 06:16:29.589633 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=14.095187
I20260812 06:16:29.651512 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.062s	user 0.031s	sys 0.028s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":29167,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":399,"reinsert_count":0,"update_count":2000}
I20260812 06:16:29.652199 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=2.188937
I20260812 06:16:29.669262 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.017s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5942,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.670138 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479): perf score=1.000000
I20260812 06:16:29.862949 31466 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.952s	user 2.162s	sys 0.137s
I20260812 06:16:29.866277 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.196s	user 0.138s	sys 0.046s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692757,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":321,"lbm_read_time_us":14417,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":571,"lbm_write_time_us":39931,"lbm_writes_lt_1ms":543,"mutex_wait_us":63,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:16:29.867034 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479): perf score=14.095187
I20260812 06:16:29.913971 31466 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.050s	user 0.008s	sys 0.000s
I20260812 06:16:29.914776 31466 tablet_server.cc:179] TabletServer@127.30.186.129:0 shutting down...
I20260812 06:16:29.915557 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: FlushDeltaMemStoresOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.048s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21508,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:29.916671 31652 maintenance_manager.cc:419] P 8a05876fb979470daf7232b16ff13d5b: Scheduling MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479): perf score=1.000000
I20260812 06:16:30.043882 31584 maintenance_manager.cc:643] P 8a05876fb979470daf7232b16ff13d5b: MajorDeltaCompactionOp(dc4fbadaaa284589912b2297a69ba479) complete. Timing: real 0.127s	user 0.105s	sys 0.022s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4180460,"cfile_cache_miss":401,"cfile_cache_miss_bytes":16409768,"cfile_init":3,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1149,"lbm_read_time_us":6932,"lbm_reads_lt_1ms":413,"lbm_write_time_us":23127,"lbm_writes_lt_1ms":443,"mutex_wait_us":177,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2000}
I20260812 06:16:30.044740 31466 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:30.045364 31466 tablet_replica.cc:333] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b: stopping tablet replica
I20260812 06:16:30.045666 31466 raft_consensus.cc:2243] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:30.046054 31466 raft_consensus.cc:2272] T dc4fbadaaa284589912b2297a69ba479 P 8a05876fb979470daf7232b16ff13d5b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:30.063781 31466 tablet_server.cc:196] TabletServer@127.30.186.129:0 shutdown complete.
I20260812 06:16:30.087285 31466 master.cc:562] Master@127.30.186.190:44483 shutting down...
I20260812 06:16:30.091688 31466 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:30.091979 31466 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:30.092056 31466 tablet_replica.cc:333] T 00000000000000000000000000000000 P 4fb047b5b1e1482ca2f590b03e484419: stopping tablet replica
I20260812 06:16:30.105471 31466 master.cc:584] Master@127.30.186.190:44483 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6681 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:30.212069 31466 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.30.186.190:39041
I20260812 06:16:30.213039 31466 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:30.216974 31695 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:30.217060 31692 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:30.217188 31466 server_base.cc:1061] running on GCE node
W20260812 06:16:30.217322 31693 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:30.217617 31466 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:30.217670 31466 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:30.217687 31466 hybrid_clock.cc:648] HybridClock initialized: now 1786515390217687 us; error 0 us; skew 500 ppm
I20260812 06:16:30.218747 31466 webserver.cc:533] Webserver started at http://127.30.186.190:45465/ using document root <none> and password file <none>
I20260812 06:16:30.219003 31466 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:30.219059 31466 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:30.219137 31466 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:30.219556 31466 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/master-0-root/instance:
uuid: "7721d8a991e0427094567661dcbbb7dc"
format_stamp: "Formatted at 2026-08-12 06:16:30 on dist-test-slave-77v9"
I20260812 06:16:30.221715 31466 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:16:30.223308 31701 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:30.223727 31466 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:30.223814 31466 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/master-0-root
uuid: "7721d8a991e0427094567661dcbbb7dc"
format_stamp: "Formatted at 2026-08-12 06:16:30 on dist-test-slave-77v9"
I20260812 06:16:30.223893 31466 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:30.234795 31466 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:30.235261 31466 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:30.240159 31466 rpc_server.cc:307] RPC server started. Bound to: 127.30.186.190:39041
I20260812 06:16:30.244366 31757 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.186.190:39041 every 8 connection(s)
I20260812 06:16:30.260692 31758 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:30.263226 31758 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc: Bootstrap starting.
I20260812 06:16:30.264211 31758 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:30.265715 31758 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc: No bootstrap required, opened a new log
I20260812 06:16:30.266263 31758 raft_consensus.cc:359] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7721d8a991e0427094567661dcbbb7dc" member_type: VOTER }
I20260812 06:16:30.266376 31758 raft_consensus.cc:385] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:30.266404 31758 raft_consensus.cc:740] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7721d8a991e0427094567661dcbbb7dc, State: Initialized, Role: FOLLOWER
I20260812 06:16:30.266589 31758 consensus_queue.cc:260] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc [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: "7721d8a991e0427094567661dcbbb7dc" member_type: VOTER }
I20260812 06:16:30.266666 31758 raft_consensus.cc:399] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:30.266691 31758 raft_consensus.cc:493] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:30.266743 31758 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:30.267701 31758 raft_consensus.cc:515] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7721d8a991e0427094567661dcbbb7dc" member_type: VOTER }
I20260812 06:16:30.267860 31758 leader_election.cc:304] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc [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: 7721d8a991e0427094567661dcbbb7dc; no voters: 
I20260812 06:16:30.268117 31758 leader_election.cc:290] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:30.268383 31761 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:30.268649 31758 sys_catalog.cc:565] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:30.268703 31761 raft_consensus.cc:697] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc [term 1 LEADER]: Becoming Leader. State: Replica: 7721d8a991e0427094567661dcbbb7dc, State: Running, Role: LEADER
I20260812 06:16:30.268956 31761 consensus_queue.cc:237] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc [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: "7721d8a991e0427094567661dcbbb7dc" member_type: VOTER }
I20260812 06:16:30.269613 31763 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc [sys.catalog]: SysCatalogTable state changed. Reason: New leader 7721d8a991e0427094567661dcbbb7dc. Latest consensus state: current_term: 1 leader_uuid: "7721d8a991e0427094567661dcbbb7dc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7721d8a991e0427094567661dcbbb7dc" member_type: VOTER } }
I20260812 06:16:30.269733 31763 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:30.269851 31762 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "7721d8a991e0427094567661dcbbb7dc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7721d8a991e0427094567661dcbbb7dc" member_type: VOTER } }
I20260812 06:16:30.269966 31762 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:30.270136 31771 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:30.271287 31771 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:30.271656 31466 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:30.273604 31771 catalog_manager.cc:1383] Generated new cluster ID: 4fa81a6d9789437aabce6225b1ace42a
I20260812 06:16:30.273692 31771 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:30.284646 31771 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:30.285415 31771 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:30.302703 31771 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc: Generated new TSK 0
I20260812 06:16:30.302984 31771 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:30.304217 31466 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:30.307014 31786 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:16:30.307065 31466 server_base.cc:1061] running on GCE node
W20260812 06:16:30.307025 31784 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:30.307049 31783 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:30.307797 31466 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:30.307850 31466 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:30.307868 31466 hybrid_clock.cc:648] HybridClock initialized: now 1786515390307867 us; error 0 us; skew 500 ppm
I20260812 06:16:30.309070 31466 webserver.cc:533] Webserver started at http://127.30.186.129:37015/ using document root <none> and password file <none>
I20260812 06:16:30.309240 31466 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:30.309291 31466 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:30.309360 31466 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:30.309767 31466 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/instance:
uuid: "27ea6687c7f04354b83cd90d4dac23fc"
format_stamp: "Formatted at 2026-08-12 06:16:30 on dist-test-slave-77v9"
I20260812 06:16:30.312191 31466 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:16:30.313746 31794 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:30.314404 31466 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:30.314656 31466 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root
uuid: "27ea6687c7f04354b83cd90d4dac23fc"
format_stamp: "Formatted at 2026-08-12 06:16:30 on dist-test-slave-77v9"
I20260812 06:16:30.314908 31466 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:30.333720 31466 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:30.334584 31466 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:30.335058 31466 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:30.335634 31466 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:30.335712 31466 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:30.335767 31466 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:30.335813 31466 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:30.340652 31466 rpc_server.cc:307] RPC server started. Bound to: 127.30.186.129:43961
I20260812 06:16:30.340721 31864 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.186.129:43961 every 8 connection(s)
I20260812 06:16:30.351697 31865 heartbeater.cc:344] Connected to a master server at 127.30.186.190:39041
I20260812 06:16:30.351976 31865 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:30.352360 31865 heartbeater.cc:507] Master 127.30.186.190:39041 requested a full tablet report, sending...
I20260812 06:16:30.353654 31719 ts_manager.cc:194] Registered new tserver with Master: 27ea6687c7f04354b83cd90d4dac23fc (127.30.186.129:43961)
I20260812 06:16:30.354064 31466 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012869687s
I20260812 06:16:30.354643 31719 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:51792
I20260812 06:16:30.365221 31719 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:51808:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:16:30.376673 31827 tablet_service.cc:1511] Processing CreateTablet for tablet 2de30c046acc4411b2cf23e07101bdbf (DEFAULT_TABLE table=heavy-update-compaction-test [id=20b27e493ae14c8ea61179220452aef9]), partition=
I20260812 06:16:30.377159 31827 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 2de30c046acc4411b2cf23e07101bdbf. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:30.380110 31879 tablet_bootstrap.cc:492] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Bootstrap starting.
I20260812 06:16:30.381333 31879 tablet_bootstrap.cc:654] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:30.383159 31879 tablet_bootstrap.cc:492] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: No bootstrap required, opened a new log
I20260812 06:16:30.383320 31879 ts_tablet_manager.cc:1403] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:30.383857 31879 raft_consensus.cc:359] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "27ea6687c7f04354b83cd90d4dac23fc" member_type: VOTER last_known_addr { host: "127.30.186.129" port: 43961 } }
I20260812 06:16:30.383991 31879 raft_consensus.cc:385] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:30.384027 31879 raft_consensus.cc:740] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 27ea6687c7f04354b83cd90d4dac23fc, State: Initialized, Role: FOLLOWER
I20260812 06:16:30.384204 31879 consensus_queue.cc:260] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc [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: "27ea6687c7f04354b83cd90d4dac23fc" member_type: VOTER last_known_addr { host: "127.30.186.129" port: 43961 } }
I20260812 06:16:30.384297 31879 raft_consensus.cc:399] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:30.384325 31879 raft_consensus.cc:493] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:30.384366 31879 raft_consensus.cc:3060] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:30.385468 31879 raft_consensus.cc:515] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "27ea6687c7f04354b83cd90d4dac23fc" member_type: VOTER last_known_addr { host: "127.30.186.129" port: 43961 } }
I20260812 06:16:30.385649 31879 leader_election.cc:304] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc [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: 27ea6687c7f04354b83cd90d4dac23fc; no voters: 
I20260812 06:16:30.385880 31879 leader_election.cc:290] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:30.386176 31881 raft_consensus.cc:2804] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:30.386330 31879 ts_tablet_manager.cc:1434] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Time spent starting tablet: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:16:30.386366 31865 heartbeater.cc:499] Master 127.30.186.190:39041 was elected leader, sending a full tablet report...
I20260812 06:16:30.386417 31881 raft_consensus.cc:697] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc [term 1 LEADER]: Becoming Leader. State: Replica: 27ea6687c7f04354b83cd90d4dac23fc, State: Running, Role: LEADER
I20260812 06:16:30.386579 31881 consensus_queue.cc:237] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc [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: "27ea6687c7f04354b83cd90d4dac23fc" member_type: VOTER last_known_addr { host: "127.30.186.129" port: 43961 } }
I20260812 06:16:30.388164 31719 catalog_manager.cc:5719] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc reported cstate change: term changed from 0 to 1, leader changed from <none> to 27ea6687c7f04354b83cd90d4dac23fc (127.30.186.129). New cstate: current_term: 1 leader_uuid: "27ea6687c7f04354b83cd90d4dac23fc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "27ea6687c7f04354b83cd90d4dac23fc" member_type: VOTER last_known_addr { host: "127.30.186.129" port: 43961 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:30.458087 31466 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.063s	user 0.016s	sys 0.010s
I20260812 06:16:30.591881 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushMRSOp(2de30c046acc4411b2cf23e07101bdbf): perf score=15.086190
I20260812 06:16:30.742276 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushMRSOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.150s	user 0.105s	sys 0.044s Metrics: {"bytes_written":9025564,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":102,"dirs.run_cpu_time_us":327,"dirs.run_wall_time_us":1251,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36582,"lbm_writes_lt_1ms":577,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"spinlock_wait_cycles":4864,"update_count":1100}
I20260812 06:16:30.743157 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling LogGCOp(2de30c046acc4411b2cf23e07101bdbf): free 11976772 bytes of WAL
I20260812 06:16:30.743459 31799 log_reader.cc:385] T 2de30c046acc4411b2cf23e07101bdbf: removed 1 log segments from log reader
I20260812 06:16:30.743547 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000001 (ops 1-6)
I20260812 06:16:30.747687 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: LogGCOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:30.748355 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=2.188937
I20260812 06:16:30.763603 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3282155,"delete_count":0,"lbm_write_time_us":4945,"lbm_writes_lt_1ms":83,"reinsert_count":0,"update_count":400}
I20260812 06:16:30.764147 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling UndoDeltaBlockGCOp(2de30c046acc4411b2cf23e07101bdbf): 12308958 bytes on disk
I20260812 06:16:30.764694 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: UndoDeltaBlockGCOp(2de30c046acc4411b2cf23e07101bdbf) 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:16:30.765237 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf): perf score=1.000000
I20260812 06:16:30.902755 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.137s	user 0.093s	sys 0.044s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528882,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1067,"lbm_read_time_us":10520,"lbm_reads_lt_1ms":360,"lbm_write_time_us":25165,"lbm_writes_lt_1ms":343,"mutex_wait_us":27,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":13696,"thread_start_us":412,"threads_started":5,"update_count":1500}
I20260812 06:16:30.903584 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=10.126437
I20260812 06:16:30.957422 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.054s	user 0.026s	sys 0.017s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":20157,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:30.958081 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=2.188937
I20260812 06:16:30.972275 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5402,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.973088 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf): perf score=1.000000
I20260812 06:16:31.120035 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.147s	user 0.117s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1046,"lbm_read_time_us":9638,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27729,"lbm_writes_lt_1ms":443,"mutex_wait_us":360,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:16:31.120851 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=10.126437
I20260812 06:16:31.181993 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.061s	user 0.025s	sys 0.033s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20856,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:31.182667 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=2.188937
I20260812 06:16:31.195359 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4915,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.195919 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf): perf score=1.000000
I20260812 06:16:31.396459 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.200s	user 0.131s	sys 0.068s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1641,"lbm_read_time_us":14031,"lbm_reads_lt_1ms":472,"lbm_write_time_us":32284,"lbm_writes_lt_1ms":443,"mutex_wait_us":415,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:16:31.397439 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=10.126437
I20260812 06:16:31.450007 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.052s	user 0.027s	sys 0.023s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":22607,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:31.450842 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=2.188937
I20260812 06:16:31.466382 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6020,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.467046 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf): perf score=1.000000
I20260812 06:16:31.617050 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.150s	user 0.121s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":487,"lbm_read_time_us":11423,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28919,"lbm_writes_lt_1ms":443,"mutex_wait_us":101,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":71552,"update_count":2000}
I20260812 06:16:31.617992 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=10.126437
I20260812 06:16:31.670305 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.052s	user 0.039s	sys 0.004s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19225,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:31.671103 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=2.188937
I20260812 06:16:31.685387 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5235,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.686406 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf): perf score=1.000000
I20260812 06:16:31.837268 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.151s	user 0.112s	sys 0.034s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1800,"lbm_read_time_us":11529,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28675,"lbm_writes_lt_1ms":443,"mutex_wait_us":362,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":27008,"update_count":2000}
I20260812 06:16:31.838020 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=10.126437
I20260812 06:16:31.906610 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.068s	user 0.035s	sys 0.024s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":21109,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:31.907418 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=2.188937
I20260812 06:16:31.925340 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.018s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6565,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.926072 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf): perf score=1.000000
I20260812 06:16:32.099052 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.173s	user 0.128s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":333,"lbm_read_time_us":13368,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24748,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":2000}
I20260812 06:16:32.099840 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=10.126437
I20260812 06:16:32.158408 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.058s	user 0.020s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19476,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:32.159080 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=2.188937
I20260812 06:16:32.174687 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5963,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.175271 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf): perf score=1.000000
I20260812 06:16:32.323376 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.148s	user 0.107s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":236,"lbm_read_time_us":10072,"lbm_reads_lt_1ms":464,"lbm_write_time_us":32216,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2000}
I20260812 06:16:32.324378 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=10.126437
I20260812 06:16:32.377601 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.053s	user 0.034s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18270,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:32.378646 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=2.188937
I20260812 06:16:32.394671 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5265,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.395316 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushMRSOp(2de30c046acc4411b2cf23e07101bdbf): perf score=1.000000
I20260812 06:16:32.434650 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushMRSOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.039s	user 0.037s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":116,"dirs.run_cpu_time_us":262,"dirs.run_wall_time_us":1458,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1839,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:32.435456 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling LogGCOp(2de30c046acc4411b2cf23e07101bdbf): free 133024357 bytes of WAL
I20260812 06:16:32.435719 31799 log_reader.cc:385] T 2de30c046acc4411b2cf23e07101bdbf: removed 13 log segments from log reader
I20260812 06:16:32.435765 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000002 (ops 7-11)
I20260812 06:16:32.435796 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000003 (ops 12-16)
I20260812 06:16:32.435832 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000004 (ops 17-20)
I20260812 06:16:32.435874 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000005 (ops 21-25)
I20260812 06:16:32.435927 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000006 (ops 26-30)
I20260812 06:16:32.435966 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000007 (ops 31-35)
I20260812 06:16:32.435986 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000008 (ops 36-40)
I20260812 06:16:32.436036 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000009 (ops 41-45)
I20260812 06:16:32.436079 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000010 (ops 46-50)
I20260812 06:16:32.436133 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000011 (ops 51-55)
I20260812 06:16:32.436169 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000012 (ops 56-60)
I20260812 06:16:32.436197 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000013 (ops 61-65)
I20260812 06:16:32.436260 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000014 (ops 66-70)
I20260812 06:16:32.471113 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: LogGCOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.035s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:16:32.471626 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=6.157687
I20260812 06:16:32.503927 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.032s	user 0.011s	sys 0.018s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":13879,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:32.504540 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf): perf score=1.000000
I20260812 06:16:32.719635 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.215s	user 0.158s	sys 0.053s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836254,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1469,"lbm_read_time_us":15462,"lbm_reads_lt_1ms":665,"lbm_write_time_us":43483,"lbm_writes_lt_1ms":643,"mutex_wait_us":515,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13056,"thread_start_us":98,"threads_started":1,"update_count":3000}
I20260812 06:16:32.720582 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=14.095187
I20260812 06:16:32.789938 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.069s	user 0.052s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28942,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:32.790650 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=2.188937
I20260812 06:16:32.805927 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.015s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5685,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.806421 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling UndoDeltaBlockGCOp(2de30c046acc4411b2cf23e07101bdbf): 483 bytes on disk
I20260812 06:16:32.806888 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: UndoDeltaBlockGCOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:16:32.807371 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf): perf score=1.000000
I20260812 06:16:32.987498 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.180s	user 0.138s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":259,"lbm_read_time_us":12096,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36179,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21376,"update_count":2500}
I20260812 06:16:32.988269 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=12.110812
I20260812 06:16:33.037089 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.049s	user 0.033s	sys 0.015s Metrics: {"bytes_written":13579242,"delete_count":0,"lbm_write_time_us":20505,"lbm_writes_lt_1ms":334,"reinsert_count":0,"update_count":1655}
I20260812 06:16:33.037731 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=2.188937
I20260812 06:16:33.063508 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.026s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3241134,"delete_count":0,"lbm_write_time_us":5183,"lbm_writes_lt_1ms":82,"reinsert_count":0,"update_count":395}
I20260812 06:16:33.064136 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=2.188937
I20260812 06:16:33.077731 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4986,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:33.078852 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf): perf score=1.000000
I20260812 06:16:33.280185 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.201s	user 0.133s	sys 0.067s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733816,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":542,"lbm_read_time_us":13971,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33344,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:16:33.281065 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=14.095187
I20260812 06:16:33.344183 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.063s	user 0.026s	sys 0.033s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":28491,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:33.344924 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=2.188937
I20260812 06:16:33.358398 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.013s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5233,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.358949 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf): perf score=1.000000
I20260812 06:16:33.562005 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.203s	user 0.128s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":538,"lbm_read_time_us":13192,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36948,"lbm_writes_lt_1ms":543,"mutex_wait_us":114,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19712,"update_count":2500}
I20260812 06:16:33.562975 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=14.095187
I20260812 06:16:33.637897 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.075s	user 0.038s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28445,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:33.639120 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=2.188937
I20260812 06:16:33.667050 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.028s	user 0.014s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7378,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.667811 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf): perf score=1.000000
I20260812 06:16:33.885584 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.217s	user 0.153s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1378,"lbm_read_time_us":14236,"lbm_reads_lt_1ms":564,"lbm_write_time_us":38527,"lbm_writes_lt_1ms":543,"mutex_wait_us":228,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2500}
I20260812 06:16:33.886401 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=14.095187
I20260812 06:16:33.956337 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.070s	user 0.054s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24217,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:33.957284 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=2.188937
I20260812 06:16:33.976930 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.019s	user 0.015s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7174,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.977664 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf): perf score=1.000000
I20260812 06:16:34.201311 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.223s	user 0.136s	sys 0.080s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":114,"lbm_read_time_us":16388,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36616,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":70400,"update_count":2500}
I20260812 06:16:34.202195 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=14.095187
I20260812 06:16:34.253343 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.051s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21639,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:34.254000 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=2.188937
I20260812 06:16:34.279820 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.026s	user 0.011s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4969,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.280478 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushMRSOp(2de30c046acc4411b2cf23e07101bdbf): perf score=1.000000
I20260812 06:16:34.315066 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushMRSOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.034s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1357580,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":313,"dirs.run_wall_time_us":1633,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1938,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:16:34.315866 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling LogGCOp(2de30c046acc4411b2cf23e07101bdbf): free 129773589 bytes of WAL
I20260812 06:16:34.316119 31799 log_reader.cc:385] T 2de30c046acc4411b2cf23e07101bdbf: removed 13 log segments from log reader
I20260812 06:16:34.316165 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000015 (ops 71-75)
I20260812 06:16:34.316196 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000016 (ops 76-80)
I20260812 06:16:34.316332 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000017 (ops 81-85)
I20260812 06:16:34.316376 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000018 (ops 86-90)
I20260812 06:16:34.316395 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000019 (ops 91-95)
I20260812 06:16:34.316432 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000020 (ops 96-100)
I20260812 06:16:34.316468 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000021 (ops 101-104)
I20260812 06:16:34.316525 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000022 (ops 105-109)
I20260812 06:16:34.316566 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000023 (ops 110-114)
I20260812 06:16:34.316610 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000024 (ops 115-119)
I20260812 06:16:34.316650 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000025 (ops 120-124)
I20260812 06:16:34.316689 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000026 (ops 125-129)
I20260812 06:16:34.316727 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000027 (ops 130-134)
I20260812 06:16:34.348875 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: LogGCOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.033s	user 0.003s	sys 0.025s Metrics: {}
I20260812 06:16:34.349411 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=3.181125
I20260812 06:16:34.375641 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.026s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5270,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:34.376330 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=2.188937
I20260812 06:16:34.391248 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5459,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:34.391884 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf): perf score=1.000000
I20260812 06:16:34.669816 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.278s	user 0.190s	sys 0.084s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938775,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":881,"lbm_read_time_us":20100,"lbm_reads_lt_1ms":774,"lbm_write_time_us":44648,"lbm_writes_lt_1ms":743,"mutex_wait_us":122,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17664,"thread_start_us":98,"threads_started":1,"update_count":3500}
I20260812 06:16:34.670795 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=14.095187
I20260812 06:16:34.734247 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.063s	user 0.045s	sys 0.015s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":28873,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:34.734917 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling UndoDeltaBlockGCOp(2de30c046acc4411b2cf23e07101bdbf): 508 bytes on disk
I20260812 06:16:34.735423 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: UndoDeltaBlockGCOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:16:34.735962 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=2.188937
I20260812 06:16:34.751641 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5777,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.752236 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf): perf score=1.000000
I20260812 06:16:34.951910 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.199s	user 0.143s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733726,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2207,"lbm_read_time_us":15277,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33593,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":125696,"update_count":2500}
I20260812 06:16:34.953668 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=14.095187
I20260812 06:16:35.026559 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.072s	user 0.033s	sys 0.038s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":27077,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:35.027251 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=2.188937
I20260812 06:16:35.039080 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4533,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:35.039633 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf): perf score=1.000000
I20260812 06:16:35.227917 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.188s	user 0.112s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733721,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":546,"lbm_read_time_us":14349,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35503,"lbm_writes_lt_1ms":543,"mutex_wait_us":300,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2500}
I20260812 06:16:35.228694 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=10.126437
I20260812 06:16:35.275997 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.047s	user 0.027s	sys 0.017s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20682,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:35.276652 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=2.188937
I20260812 06:16:35.290203 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5321,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:35.290701 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf): perf score=1.000000
I20260812 06:16:35.476140 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.185s	user 0.141s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1031,"lbm_read_time_us":12983,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26976,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":2000}
I20260812 06:16:35.476930 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=11.118625
I20260812 06:16:35.519848 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.043s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18162,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:35.520653 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=2.188937
I20260812 06:16:35.538337 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.017s	user 0.014s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6313,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:35.538955 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf): perf score=1.000000
I20260812 06:16:35.691596 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.152s	user 0.118s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":117,"lbm_read_time_us":9667,"lbm_reads_lt_1ms":464,"lbm_write_time_us":30258,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:16:35.692931 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=10.126437
I20260812 06:16:35.741645 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.048s	user 0.031s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19316,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:35.742288 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=2.188937
I20260812 06:16:35.755442 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4479,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:35.756227 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf): perf score=1.000000
I20260812 06:16:35.903214 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.147s	user 0.110s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":395,"lbm_read_time_us":10427,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27798,"lbm_writes_lt_1ms":443,"mutex_wait_us":54,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":124672,"update_count":2000}
I20260812 06:16:35.903869 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=10.126437
I20260812 06:16:35.969166 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.065s	user 0.033s	sys 0.030s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22263,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:35.969882 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=2.188937
I20260812 06:16:35.987248 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.017s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6332,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:35.988086 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf): perf score=1.000000
I20260812 06:16:36.157720 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.169s	user 0.102s	sys 0.065s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1048,"lbm_read_time_us":13282,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28568,"lbm_writes_lt_1ms":443,"mutex_wait_us":353,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":97536,"update_count":2000}
I20260812 06:16:36.158434 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=10.126437
I20260812 06:16:36.215325 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.057s	user 0.014s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19262,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:36.216629 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=2.188937
I20260812 06:16:36.231178 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5067,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:36.232016 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushMRSOp(2de30c046acc4411b2cf23e07101bdbf): perf score=1.000000
I20260812 06:16:36.269738 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushMRSOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.037s	user 0.033s	sys 0.004s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":127,"dirs.run_cpu_time_us":365,"dirs.run_wall_time_us":1906,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2519,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:36.270578 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling LogGCOp(2de30c046acc4411b2cf23e07101bdbf): free 133024646 bytes of WAL
I20260812 06:16:36.270922 31799 log_reader.cc:385] T 2de30c046acc4411b2cf23e07101bdbf: removed 13 log segments from log reader
I20260812 06:16:36.270967 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000028 (ops 135-139)
I20260812 06:16:36.270998 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000029 (ops 140-144)
I20260812 06:16:36.271015 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000030 (ops 145-148)
I20260812 06:16:36.271032 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000031 (ops 149-153)
I20260812 06:16:36.271107 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000032 (ops 154-158)
I20260812 06:16:36.271160 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000033 (ops 159-163)
I20260812 06:16:36.271205 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000034 (ops 164-168)
I20260812 06:16:36.271265 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000035 (ops 169-173)
I20260812 06:16:36.271312 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000036 (ops 174-178)
I20260812 06:16:36.271350 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000037 (ops 179-183)
I20260812 06:16:36.271427 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000038 (ops 184-188)
I20260812 06:16:36.271467 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000039 (ops 189-193)
I20260812 06:16:36.271507 31799 log.cc:1079] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: Deleting log segment in path: /tmp/dist-test-tasktnsGIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515383517906-31466-0/minicluster-data/ts-0-root/wals/2de30c046acc4411b2cf23e07101bdbf/wal-000000040 (ops 194-198)
I20260812 06:16:36.305562 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: LogGCOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.035s	user 0.003s	sys 0.031s Metrics: {}
I20260812 06:16:36.306169 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling UndoDeltaBlockGCOp(2de30c046acc4411b2cf23e07101bdbf): 483 bytes on disk
I20260812 06:16:36.306715 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: UndoDeltaBlockGCOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:16:36.307415 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=3.181125
I20260812 06:16:36.328568 31466 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.870s	user 2.139s	sys 0.165s
I20260812 06:16:36.330525 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.023s	user 0.007s	sys 0.011s Metrics: {"bytes_written":4389828,"delete_count":0,"lbm_write_time_us":8202,"lbm_writes_lt_1ms":110,"reinsert_count":0,"update_count":535}
I20260812 06:16:36.331223 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf): perf score=2.188937
I20260812 06:16:36.344336 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: FlushDeltaMemStoresOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.013s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":5368,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:16:36.345085 31866 maintenance_manager.cc:419] P 27ea6687c7f04354b83cd90d4dac23fc: Scheduling MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf): perf score=1.000000
I20260812 06:16:36.410368 31466 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.081s	user 0.002s	sys 0.000s
I20260812 06:16:36.411022 31466 tablet_server.cc:179] TabletServer@127.30.186.129:0 shutting down...
I20260812 06:16:36.521167 31799 maintenance_manager.cc:643] P 27ea6687c7f04354b83cd90d4dac23fc: MajorDeltaCompactionOp(2de30c046acc4411b2cf23e07101bdbf) complete. Timing: real 0.176s	user 0.122s	sys 0.053s Metrics: {"cfile_cache_hit":298,"cfile_cache_hit_bytes":12105255,"cfile_cache_miss":336,"cfile_cache_miss_bytes":16731113,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":754,"lbm_read_time_us":8456,"lbm_reads_lt_1ms":368,"lbm_write_time_us":37478,"lbm_writes_lt_1ms":643,"mutex_wait_us":68,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":220928,"thread_start_us":105,"threads_started":1,"update_count":3000}
I20260812 06:16:36.522107 31466 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:36.522655 31466 tablet_replica.cc:333] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc: stopping tablet replica
I20260812 06:16:36.522907 31466 raft_consensus.cc:2243] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:36.523146 31466 raft_consensus.cc:2272] T 2de30c046acc4411b2cf23e07101bdbf P 27ea6687c7f04354b83cd90d4dac23fc [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:36.528033 31466 tablet_server.cc:196] TabletServer@127.30.186.129:0 shutdown complete.
I20260812 06:16:36.572469 31466 master.cc:562] Master@127.30.186.190:39041 shutting down...
I20260812 06:16:36.577363 31466 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:36.577584 31466 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:36.577632 31466 tablet_replica.cc:333] T 00000000000000000000000000000000 P 7721d8a991e0427094567661dcbbb7dc: stopping tablet replica
I20260812 06:16:36.590935 31466 master.cc:584] Master@127.30.186.190:39041 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6480 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (13163 ms total)

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