[==========] 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:18:31.340364 20668 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.20.47.62:46565
I20260812 06:18:31.341264 20668 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:18:31.341806 20668 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:31.348059 20679 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:18:31.348126 20681 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:18:31.348177 20668 server_base.cc:1061] running on GCE node
W20260812 06:18:31.348326 20678 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:18:31.348769 20668 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:31.348853 20668 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:18:31.348882 20668 hybrid_clock.cc:648] HybridClock initialized: now 1786515511348881 us; error 0 us; skew 500 ppm
I20260812 06:18:31.350430 20668 webserver.cc:533] Webserver started at http://127.20.47.62:41305/ using document root <none> and password file <none>
I20260812 06:18:31.350893 20668 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:31.350944 20668 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:31.351120 20668 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:31.352600 20668 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/master-0-root/instance:
uuid: "dd1a10e832404afa8dd11fe8c41638c8"
format_stamp: "Formatted at 2026-08-12 06:18:31 on dist-test-slave-6zbq"
I20260812 06:18:31.355659 20668 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.003s
I20260812 06:18:31.357446 20692 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:18:31.358316 20668 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:31.358444 20668 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/master-0-root
uuid: "dd1a10e832404afa8dd11fe8c41638c8"
format_stamp: "Formatted at 2026-08-12 06:18:31 on dist-test-slave-6zbq"
I20260812 06:18:31.358520 20668 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-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:18:31.371444 20668 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:31.371917 20668 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:18:31.372047 20668 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:31.378414 20668 rpc_server.cc:307] RPC server started. Bound to: 127.20.47.62:46565
I20260812 06:18:31.378430 20794 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.47.62:46565 every 8 connection(s)
I20260812 06:18:31.380319 20795 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:18:31.385116 20795 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8: Bootstrap starting.
I20260812 06:18:31.387217 20795 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:31.388006 20795 log.cc:826] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:31.389353 20795 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8: No bootstrap required, opened a new log
I20260812 06:18:31.391871 20795 raft_consensus.cc:359] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dd1a10e832404afa8dd11fe8c41638c8" member_type: VOTER }
I20260812 06:18:31.392007 20795 raft_consensus.cc:385] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:31.392078 20795 raft_consensus.cc:740] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: dd1a10e832404afa8dd11fe8c41638c8, State: Initialized, Role: FOLLOWER
I20260812 06:18:31.392570 20795 consensus_queue.cc:260] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8 [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: "dd1a10e832404afa8dd11fe8c41638c8" member_type: VOTER }
I20260812 06:18:31.392701 20795 raft_consensus.cc:399] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:31.392763 20795 raft_consensus.cc:493] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:31.392881 20795 raft_consensus.cc:3060] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:31.393525 20795 raft_consensus.cc:515] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dd1a10e832404afa8dd11fe8c41638c8" member_type: VOTER }
I20260812 06:18:31.393899 20795 leader_election.cc:304] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8 [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: dd1a10e832404afa8dd11fe8c41638c8; no voters: 
I20260812 06:18:31.394155 20795 leader_election.cc:290] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:31.394259 20801 raft_consensus.cc:2804] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:31.394462 20801 raft_consensus.cc:697] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8 [term 1 LEADER]: Becoming Leader. State: Replica: dd1a10e832404afa8dd11fe8c41638c8, State: Running, Role: LEADER
I20260812 06:18:31.394853 20801 consensus_queue.cc:237] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8 [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: "dd1a10e832404afa8dd11fe8c41638c8" member_type: VOTER }
I20260812 06:18:31.394961 20795 sys_catalog.cc:565] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:31.396385 20805 sys_catalog.cc:455] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8 [sys.catalog]: SysCatalogTable state changed. Reason: New leader dd1a10e832404afa8dd11fe8c41638c8. Latest consensus state: current_term: 1 leader_uuid: "dd1a10e832404afa8dd11fe8c41638c8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dd1a10e832404afa8dd11fe8c41638c8" member_type: VOTER } }
I20260812 06:18:31.396472 20805 sys_catalog.cc:458] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:31.396443 20802 sys_catalog.cc:455] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "dd1a10e832404afa8dd11fe8c41638c8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dd1a10e832404afa8dd11fe8c41638c8" member_type: VOTER } }
I20260812 06:18:31.396539 20802 sys_catalog.cc:458] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:31.396766 20819 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:31.396984 20668 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:31.398924 20819 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:31.402741 20819 catalog_manager.cc:1383] Generated new cluster ID: 746008e518f343a488864d4c39a22852
I20260812 06:18:31.402798 20819 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:31.412786 20819 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:31.413455 20819 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:31.423626 20819 catalog_manager.cc:6092] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8: Generated new TSK 0
I20260812 06:18:31.424067 20819 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:31.429431 20668 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:31.432262 20847 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:18:31.432312 20838 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:18:31.432374 20668 server_base.cc:1061] running on GCE node
W20260812 06:18:31.432503 20843 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:18:31.432705 20668 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:31.432751 20668 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:18:31.432765 20668 hybrid_clock.cc:648] HybridClock initialized: now 1786515511432765 us; error 0 us; skew 500 ppm
I20260812 06:18:31.433543 20668 webserver.cc:533] Webserver started at http://127.20.47.1:33855/ using document root <none> and password file <none>
I20260812 06:18:31.433699 20668 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:31.433753 20668 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:31.433820 20668 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:31.434121 20668 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/instance:
uuid: "7704508196c24971bcb2bb72eec3eb0f"
format_stamp: "Formatted at 2026-08-12 06:18:31 on dist-test-slave-6zbq"
I20260812 06:18:31.435456 20668 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:31.436362 20861 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:18:31.436573 20668 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:31.436636 20668 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root
uuid: "7704508196c24971bcb2bb72eec3eb0f"
format_stamp: "Formatted at 2026-08-12 06:18:31 on dist-test-slave-6zbq"
I20260812 06:18:31.436703 20668 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-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:18:31.461059 20668 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:31.461395 20668 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:31.461795 20668 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:31.462543 20668 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:31.462589 20668 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:31.462628 20668 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:31.462656 20668 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:31.468564 20668 rpc_server.cc:307] RPC server started. Bound to: 127.20.47.1:37531
I20260812 06:18:31.468612 20972 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.47.1:37531 every 8 connection(s)
I20260812 06:18:31.477622 20975 heartbeater.cc:344] Connected to a master server at 127.20.47.62:46565
I20260812 06:18:31.477820 20975 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:31.478183 20975 heartbeater.cc:507] Master 127.20.47.62:46565 requested a full tablet report, sending...
I20260812 06:18:31.479403 20724 ts_manager.cc:194] Registered new tserver with Master: 7704508196c24971bcb2bb72eec3eb0f (127.20.47.1:37531)
I20260812 06:18:31.480230 20668 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011133228s
I20260812 06:18:31.480440 20724 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:45976
I20260812 06:18:31.488299 20724 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:45982:
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:18:31.500504 20919 tablet_service.cc:1511] Processing CreateTablet for tablet d0df8aa207954daeaaa24ce34de9af66 (DEFAULT_TABLE table=heavy-update-compaction-test [id=0613e6a156f148a6af31b11c05b3d771]), partition=
I20260812 06:18:31.500829 20919 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet d0df8aa207954daeaaa24ce34de9af66. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:31.502883 20993 tablet_bootstrap.cc:492] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Bootstrap starting.
I20260812 06:18:31.503575 20993 tablet_bootstrap.cc:654] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:31.504482 20993 tablet_bootstrap.cc:492] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: No bootstrap required, opened a new log
I20260812 06:18:31.504558 20993 ts_tablet_manager.cc:1403] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:31.504949 20993 raft_consensus.cc:359] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7704508196c24971bcb2bb72eec3eb0f" member_type: VOTER last_known_addr { host: "127.20.47.1" port: 37531 } }
I20260812 06:18:31.505034 20993 raft_consensus.cc:385] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:31.505061 20993 raft_consensus.cc:740] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7704508196c24971bcb2bb72eec3eb0f, State: Initialized, Role: FOLLOWER
I20260812 06:18:31.505239 20993 consensus_queue.cc:260] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f [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: "7704508196c24971bcb2bb72eec3eb0f" member_type: VOTER last_known_addr { host: "127.20.47.1" port: 37531 } }
I20260812 06:18:31.505355 20993 raft_consensus.cc:399] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:31.505561 20993 raft_consensus.cc:493] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:31.505656 20993 raft_consensus.cc:3060] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:31.506319 20993 raft_consensus.cc:515] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7704508196c24971bcb2bb72eec3eb0f" member_type: VOTER last_known_addr { host: "127.20.47.1" port: 37531 } }
I20260812 06:18:31.506476 20993 leader_election.cc:304] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f [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: 7704508196c24971bcb2bb72eec3eb0f; no voters: 
I20260812 06:18:31.506644 20993 leader_election.cc:290] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:31.506747 20996 raft_consensus.cc:2804] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:31.506927 20996 raft_consensus.cc:697] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f [term 1 LEADER]: Becoming Leader. State: Replica: 7704508196c24971bcb2bb72eec3eb0f, State: Running, Role: LEADER
I20260812 06:18:31.506989 20993 ts_tablet_manager.cc:1434] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:31.507092 20996 consensus_queue.cc:237] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f [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: "7704508196c24971bcb2bb72eec3eb0f" member_type: VOTER last_known_addr { host: "127.20.47.1" port: 37531 } }
I20260812 06:18:31.507179 20975 heartbeater.cc:499] Master 127.20.47.62:46565 was elected leader, sending a full tablet report...
I20260812 06:18:31.509497 20724 catalog_manager.cc:5719] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f reported cstate change: term changed from 0 to 1, leader changed from <none> to 7704508196c24971bcb2bb72eec3eb0f (127.20.47.1). New cstate: current_term: 1 leader_uuid: "7704508196c24971bcb2bb72eec3eb0f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7704508196c24971bcb2bb72eec3eb0f" member_type: VOTER last_known_addr { host: "127.20.47.1" port: 37531 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:31.568822 20668 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.025s	sys 0.000s
I20260812 06:18:31.719475 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushMRSOp(d0df8aa207954daeaaa24ce34de9af66): perf score=23.023690
I20260812 06:18:31.894207 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushMRSOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.174s	user 0.141s	sys 0.020s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":209,"delete_count":0,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":195,"dirs.run_wall_time_us":788,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43062,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"thread_start_us":114,"threads_started":1,"update_count":1500}
I20260812 06:18:31.895237 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling LogGCOp(d0df8aa207954daeaaa24ce34de9af66): free 20743880 bytes of WAL
I20260812 06:18:31.895563 20868 log_reader.cc:385] T d0df8aa207954daeaaa24ce34de9af66: removed 2 log segments from log reader
I20260812 06:18:31.895622 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000001 (ops 1-6)
I20260812 06:18:31.895671 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000002 (ops 7-11)
I20260812 06:18:31.899317 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: LogGCOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:31.899580 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=2.188937
I20260812 06:18:31.908890 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3541,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.909214 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66): perf score=1.000000
I20260812 06:18:32.057293 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.148s	user 0.092s	sys 0.051s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":685,"lbm_read_time_us":9992,"lbm_reads_lt_1ms":468,"lbm_write_time_us":24753,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":288,"threads_started":5,"update_count":2000}
I20260812 06:18:32.057785 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling UndoDeltaBlockGCOp(d0df8aa207954daeaaa24ce34de9af66): 20513817 bytes on disk
I20260812 06:18:32.058213 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: UndoDeltaBlockGCOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:18:32.058629 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=10.126437
I20260812 06:18:32.100040 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.041s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14140,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:32.100543 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=2.188937
I20260812 06:18:32.110059 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3588,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.110641 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66): perf score=1.000000
I20260812 06:18:32.229066 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.118s	user 0.109s	sys 0.009s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":193,"lbm_read_time_us":9086,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22234,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2000}
I20260812 06:18:32.229573 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=10.126437
I20260812 06:18:32.274561 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.045s	user 0.020s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15903,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:32.275009 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=2.188937
I20260812 06:18:32.284649 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3745,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.285140 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66): perf score=1.000000
I20260812 06:18:32.397902 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.113s	user 0.076s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":213,"lbm_read_time_us":7601,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22446,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2000}
I20260812 06:18:32.398306 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=10.126437
I20260812 06:18:32.437661 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.039s	user 0.013s	sys 0.023s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14153,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:32.438144 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=2.188937
I20260812 06:18:32.447703 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3720,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.448045 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66): perf score=1.000000
I20260812 06:18:32.582928 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.135s	user 0.086s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":943,"lbm_read_time_us":9966,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21065,"lbm_writes_lt_1ms":443,"mutex_wait_us":254,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:32.583369 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=10.126437
I20260812 06:18:32.630221 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.047s	user 0.018s	sys 0.013s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14552,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":1500}
I20260812 06:18:32.630648 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=2.188937
I20260812 06:18:32.640084 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3673,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.640496 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66): perf score=1.000000
I20260812 06:18:32.761256 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.121s	user 0.100s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713274,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":244,"lbm_read_time_us":9475,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22287,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:32.761670 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=10.126437
I20260812 06:18:32.799144 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.037s	user 0.021s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":12833,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:32.799546 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=2.188937
I20260812 06:18:32.809295 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3707,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.809725 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66): perf score=1.000000
I20260812 06:18:32.918481 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.108s	user 0.085s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":279,"lbm_read_time_us":8346,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20707,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:32.919039 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=10.126437
I20260812 06:18:32.963666 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.044s	user 0.028s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16880,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:32.964182 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=2.188937
I20260812 06:18:32.973598 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3706,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.974018 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushMRSOp(d0df8aa207954daeaaa24ce34de9af66): perf score=1.000000
I20260812 06:18:33.012702 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushMRSOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.039s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":45,"dirs.run_cpu_time_us":211,"dirs.run_wall_time_us":1067,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1324,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:33.013454 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling LogGCOp(d0df8aa207954daeaaa24ce34de9af66): free 115943172 bytes of WAL
I20260812 06:18:33.013672 20868 log_reader.cc:385] T d0df8aa207954daeaaa24ce34de9af66: removed 11 log segments from log reader
I20260812 06:18:33.013731 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000003 (ops 12-16)
I20260812 06:18:33.013772 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000004 (ops 17-21)
I20260812 06:18:33.013800 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000005 (ops 22-26)
I20260812 06:18:33.013825 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000006 (ops 27-31)
I20260812 06:18:33.013856 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000007 (ops 32-36)
I20260812 06:18:33.013887 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000008 (ops 37-41)
I20260812 06:18:33.013916 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000009 (ops 42-46)
I20260812 06:18:33.013939 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000010 (ops 47-51)
I20260812 06:18:33.013964 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000011 (ops 52-56)
I20260812 06:18:33.013995 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000012 (ops 57-61)
I20260812 06:18:33.014026 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000013 (ops 62-66)
I20260812 06:18:33.037922 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: LogGCOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.024s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:18:33.038399 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=3.181125
I20260812 06:18:33.054553 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.016s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4091,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:33.054924 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=2.188937
I20260812 06:18:33.063498 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.008s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3172,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:33.063846 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66): perf score=1.000000
I20260812 06:18:33.244882 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.181s	user 0.089s	sys 0.091s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918325,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1049,"lbm_read_time_us":12860,"lbm_reads_lt_1ms":674,"lbm_write_time_us":28809,"lbm_writes_lt_1ms":643,"mutex_wait_us":510,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4992,"thread_start_us":74,"threads_started":1,"update_count":3000}
I20260812 06:18:33.246681 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=14.095187
I20260812 06:18:33.293160 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.046s	user 0.026s	sys 0.010s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":17088,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:33.293700 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling UndoDeltaBlockGCOp(d0df8aa207954daeaaa24ce34de9af66): 447 bytes on disk
I20260812 06:18:33.294096 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: UndoDeltaBlockGCOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:18:33.294597 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66): perf score=1.000000
I20260812 06:18:33.443641 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.149s	user 0.092s	sys 0.049s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713151,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":509,"lbm_read_time_us":10093,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23978,"lbm_writes_lt_1ms":443,"mutex_wait_us":313,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2000}
I20260812 06:18:33.444110 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=14.095187
I20260812 06:18:33.492635 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.048s	user 0.025s	sys 0.017s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19426,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:33.493147 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=2.188937
I20260812 06:18:33.503690 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3718,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.504199 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66): perf score=1.000000
I20260812 06:18:33.687150 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.183s	user 0.117s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":276,"lbm_read_time_us":10684,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27503,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:18:33.687593 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=14.095187
I20260812 06:18:33.746021 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.058s	user 0.030s	sys 0.014s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19291,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:33.746518 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=3.181125
I20260812 06:18:33.768219 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.022s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":6390,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:33.768642 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=2.188937
I20260812 06:18:33.784780 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.016s	user 0.004s	sys 0.010s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3209,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:33.785154 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66): perf score=1.000000
I20260812 06:18:33.972903 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.188s	user 0.133s	sys 0.047s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918206,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":731,"lbm_read_time_us":13320,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31148,"lbm_writes_lt_1ms":643,"mutex_wait_us":267,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:18:33.973462 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=14.095187
I20260812 06:18:34.031050 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.057s	user 0.038s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21155,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:34.031519 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=2.188937
I20260812 06:18:34.040938 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3633,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.041308 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66): perf score=1.000000
I20260812 06:18:34.198154 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.157s	user 0.128s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":130,"lbm_read_time_us":11584,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25909,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:34.198773 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=11.118625
I20260812 06:18:34.231480 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.033s	user 0.016s	sys 0.015s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14094,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:34.232129 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=2.188937
I20260812 06:18:34.245589 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4718,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:34.246117 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66): perf score=1.000000
I20260812 06:18:34.364884 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.119s	user 0.102s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713264,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":65,"lbm_read_time_us":8627,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22739,"lbm_writes_lt_1ms":443,"mutex_wait_us":60,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:34.365664 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=10.126437
I20260812 06:18:34.400084 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.034s	user 0.013s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15145,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:34.400507 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=2.188937
I20260812 06:18:34.411095 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3951,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.411496 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushMRSOp(d0df8aa207954daeaaa24ce34de9af66): perf score=1.000000
I20260812 06:18:34.442904 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushMRSOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.031s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":203,"dirs.run_wall_time_us":990,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1499,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:34.443621 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling LogGCOp(d0df8aa207954daeaaa24ce34de9af66): free 121459489 bytes of WAL
I20260812 06:18:34.443833 20868 log_reader.cc:385] T d0df8aa207954daeaaa24ce34de9af66: removed 12 log segments from log reader
I20260812 06:18:34.443876 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000014 (ops 67-71)
I20260812 06:18:34.443904 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000015 (ops 72-76)
I20260812 06:18:34.443936 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000016 (ops 77-81)
I20260812 06:18:34.443962 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000017 (ops 82-86)
I20260812 06:18:34.443993 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000018 (ops 87-91)
I20260812 06:18:34.444025 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000019 (ops 92-96)
I20260812 06:18:34.444058 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000020 (ops 97-101)
I20260812 06:18:34.444089 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000021 (ops 102-106)
I20260812 06:18:34.444120 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000022 (ops 107-111)
I20260812 06:18:34.444159 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000023 (ops 112-116)
I20260812 06:18:34.444191 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000024 (ops 117-121)
I20260812 06:18:34.444223 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000025 (ops 122-126)
I20260812 06:18:34.467162 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: LogGCOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.023s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:34.467519 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=4.173312
I20260812 06:18:34.483947 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.016s	user 0.014s	sys 0.001s Metrics: {"bytes_written":5948752,"delete_count":0,"lbm_write_time_us":6745,"lbm_writes_lt_1ms":148,"reinsert_count":0,"update_count":725}
I20260812 06:18:34.484335 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling LogGCOp(d0df8aa207954daeaaa24ce34de9af66): free 11564883 bytes of WAL
I20260812 06:18:34.484511 20868 log_reader.cc:385] T d0df8aa207954daeaaa24ce34de9af66: removed 1 log segments from log reader
I20260812 06:18:34.484552 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000026 (ops 127-130)
I20260812 06:18:34.486449 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: LogGCOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.002s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:34.486720 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=1.196750
I20260812 06:18:34.494482 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.008s	user 0.003s	sys 0.005s Metrics: {"bytes_written":2256529,"delete_count":0,"lbm_write_time_us":2496,"lbm_writes_lt_1ms":58,"reinsert_count":0,"update_count":275}
I20260812 06:18:34.494908 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66): perf score=1.000000
I20260812 06:18:34.646531 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.151s	user 0.107s	sys 0.042s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918291,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":4219,"lbm_read_time_us":10115,"lbm_reads_lt_1ms":674,"lbm_write_time_us":29761,"lbm_writes_lt_1ms":643,"mutex_wait_us":34,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":68,"threads_started":1,"update_count":3000}
I20260812 06:18:34.647079 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=14.095187
I20260812 06:18:34.692874 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.046s	user 0.021s	sys 0.022s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19819,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:34.693276 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=2.188937
I20260812 06:18:34.702703 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3619,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.703267 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66): perf score=1.000000
I20260812 06:18:34.842248 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.139s	user 0.113s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":140,"lbm_read_time_us":9634,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27457,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:18:34.842945 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling UndoDeltaBlockGCOp(d0df8aa207954daeaaa24ce34de9af66): 472 bytes on disk
I20260812 06:18:34.843405 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: UndoDeltaBlockGCOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:18:34.843951 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=11.118625
I20260812 06:18:34.874012 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.030s	user 0.014s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12123,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:34.874553 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=2.188937
I20260812 06:18:34.895697 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.021s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4659,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:34.896123 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=2.188937
I20260812 06:18:34.905571 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3733,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.905962 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66): perf score=1.000000
I20260812 06:18:35.053985 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.148s	user 0.116s	sys 0.028s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":700,"lbm_read_time_us":10587,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28633,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2500}
I20260812 06:18:35.054510 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=11.118625
I20260812 06:18:35.088903 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.034s	user 0.028s	sys 0.004s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":14029,"lbm_writes_lt_1ms":313,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":1550}
I20260812 06:18:35.089470 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=2.188937
I20260812 06:18:35.111948 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.022s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3632,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:35.112398 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=2.188937
I20260812 06:18:35.127081 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5479,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.127640 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66): perf score=1.000000
I20260812 06:18:35.279322 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.151s	user 0.106s	sys 0.043s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815793,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":291,"lbm_read_time_us":11145,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26877,"lbm_writes_lt_1ms":543,"mutex_wait_us":77,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2500}
I20260812 06:18:35.279882 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=12.110812
I20260812 06:18:35.317094 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.037s	user 0.025s	sys 0.010s Metrics: {"bytes_written":13743341,"delete_count":0,"lbm_write_time_us":15063,"lbm_writes_lt_1ms":338,"reinsert_count":0,"update_count":1675}
I20260812 06:18:35.317600 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=1.196750
I20260812 06:18:35.338599 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.021s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3077034,"delete_count":0,"lbm_write_time_us":4389,"lbm_writes_lt_1ms":78,"reinsert_count":0,"update_count":375}
I20260812 06:18:35.339020 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=2.188937
I20260812 06:18:35.347692 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3179,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:35.348086 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66): perf score=1.000000
I20260812 06:18:35.522913 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.175s	user 0.109s	sys 0.058s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815775,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":155,"lbm_read_time_us":11925,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31433,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":26112,"update_count":2500}
I20260812 06:18:35.523430 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=14.095187
I20260812 06:18:35.571794 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.048s	user 0.019s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20467,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:35.572329 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=2.188937
I20260812 06:18:35.581681 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3560,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.582233 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66): perf score=1.000000
I20260812 06:18:35.731364 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.149s	user 0.111s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":322,"lbm_read_time_us":12829,"lbm_reads_lt_1ms":572,"lbm_write_time_us":23732,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2500}
I20260812 06:18:35.732111 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=14.095187
I20260812 06:18:35.783823 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.052s	user 0.021s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18326,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:35.784363 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=2.188937
I20260812 06:18:35.798799 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5564,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.799265 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushMRSOp(d0df8aa207954daeaaa24ce34de9af66): perf score=1.000000
I20260812 06:18:35.836390 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushMRSOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.037s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":42,"dirs.run_cpu_time_us":204,"dirs.run_wall_time_us":1068,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1448,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:35.837174 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling LogGCOp(d0df8aa207954daeaaa24ce34de9af66): free 129320791 bytes of WAL
I20260812 06:18:35.837409 20868 log_reader.cc:385] T d0df8aa207954daeaaa24ce34de9af66: removed 13 log segments from log reader
I20260812 06:18:35.837455 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000027 (ops 131-135)
I20260812 06:18:35.837481 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000028 (ops 136-140)
I20260812 06:18:35.837497 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000029 (ops 141-145)
I20260812 06:18:35.837524 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000030 (ops 146-150)
I20260812 06:18:35.837548 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000031 (ops 151-154)
I20260812 06:18:35.837571 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000032 (ops 155-159)
I20260812 06:18:35.837602 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000033 (ops 160-164)
I20260812 06:18:35.837687 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000034 (ops 165-168)
I20260812 06:18:35.837720 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000035 (ops 169-173)
I20260812 06:18:35.837738 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000036 (ops 174-178)
I20260812 06:18:35.837754 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000037 (ops 179-183)
I20260812 06:18:35.837785 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000038 (ops 184-188)
I20260812 06:18:35.837815 20868 log.cc:1079] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/d0df8aa207954daeaaa24ce34de9af66/wal-000000039 (ops 189-193)
I20260812 06:18:35.859581 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: LogGCOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.022s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:18:35.860080 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling UndoDeltaBlockGCOp(d0df8aa207954daeaaa24ce34de9af66): 492 bytes on disk
I20260812 06:18:35.860775 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: UndoDeltaBlockGCOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":96,"lbm_reads_lt_1ms":4}
I20260812 06:18:35.861348 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=2.188937
I20260812 06:18:35.879657 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.018s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4646,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.880015 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=2.188937
I20260812 06:18:35.889472 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3770,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.889873 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66): perf score=1.000000
I20260812 06:18:36.023427 20668 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.455s	user 1.590s	sys 0.149s
I20260812 06:18:36.092639 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: MajorDeltaCompactionOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.203s	user 0.113s	sys 0.087s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020745,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":15612,"lbm_reads_lt_1ms":770,"lbm_write_time_us":34971,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"update_count":3500}
I20260812 06:18:36.093120 20977 maintenance_manager.cc:419] P 7704508196c24971bcb2bb72eec3eb0f: Scheduling FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66): perf score=10.126437
I20260812 06:18:36.117008 20668 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.093s	user 0.001s	sys 0.000s
I20260812 06:18:36.117592 20668 tablet_server.cc:179] TabletServer@127.20.47.1:0 shutting down...
I20260812 06:18:36.130460 20868 maintenance_manager.cc:643] P 7704508196c24971bcb2bb72eec3eb0f: FlushDeltaMemStoresOp(d0df8aa207954daeaaa24ce34de9af66) complete. Timing: real 0.037s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15573,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:36.130906 20668 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:36.131209 20668 tablet_replica.cc:333] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f: stopping tablet replica
I20260812 06:18:36.131403 20668 raft_consensus.cc:2243] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:36.131595 20668 raft_consensus.cc:2272] T d0df8aa207954daeaaa24ce34de9af66 P 7704508196c24971bcb2bb72eec3eb0f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:36.145506 20668 tablet_server.cc:196] TabletServer@127.20.47.1:0 shutdown complete.
I20260812 06:18:36.151672 20668 master.cc:562] Master@127.20.47.62:46565 shutting down...
I20260812 06:18:36.155246 20668 raft_consensus.cc:2243] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:36.155373 20668 raft_consensus.cc:2272] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:36.155444 20668 tablet_replica.cc:333] T 00000000000000000000000000000000 P dd1a10e832404afa8dd11fe8c41638c8: stopping tablet replica
I20260812 06:18:36.167222 20668 master.cc:584] Master@127.20.47.62:46565 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (4900 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:36.240851 20668 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.20.47.62:46227
I20260812 06:18:36.241225 20668 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:36.243054 21043 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:18:36.243031 21038 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:18:36.243141 21040 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:18:36.243186 20668 server_base.cc:1061] running on GCE node
I20260812 06:18:36.243415 20668 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:36.243455 20668 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:18:36.243469 20668 hybrid_clock.cc:648] HybridClock initialized: now 1786515516243469 us; error 0 us; skew 500 ppm
I20260812 06:18:36.244159 20668 webserver.cc:533] Webserver started at http://127.20.47.62:45057/ using document root <none> and password file <none>
I20260812 06:18:36.244292 20668 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:36.244331 20668 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:36.244382 20668 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:36.244680 20668 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/master-0-root/instance:
uuid: "f728af62a1064779b6ab2923df71a5fe"
format_stamp: "Formatted at 2026-08-12 06:18:36 on dist-test-slave-6zbq"
I20260812 06:18:36.245949 20668 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:36.246785 21052 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:18:36.246979 20668 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:18:36.247041 20668 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/master-0-root
uuid: "f728af62a1064779b6ab2923df71a5fe"
format_stamp: "Formatted at 2026-08-12 06:18:36 on dist-test-slave-6zbq"
I20260812 06:18:36.247105 20668 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-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:18:36.252169 20668 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:36.252439 20668 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:36.256125 20668 rpc_server.cc:307] RPC server started. Bound to: 127.20.47.62:46227
I20260812 06:18:36.268261 21136 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:18:36.268278 21135 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.47.62:46227 every 8 connection(s)
I20260812 06:18:36.269893 21136 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe: Bootstrap starting.
I20260812 06:18:36.270619 21136 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:36.271478 21136 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe: No bootstrap required, opened a new log
I20260812 06:18:36.271842 21136 raft_consensus.cc:359] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f728af62a1064779b6ab2923df71a5fe" member_type: VOTER }
I20260812 06:18:36.271919 21136 raft_consensus.cc:385] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:36.271947 21136 raft_consensus.cc:740] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f728af62a1064779b6ab2923df71a5fe, State: Initialized, Role: FOLLOWER
I20260812 06:18:36.272078 21136 consensus_queue.cc:260] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe [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: "f728af62a1064779b6ab2923df71a5fe" member_type: VOTER }
I20260812 06:18:36.272143 21136 raft_consensus.cc:399] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:36.272181 21136 raft_consensus.cc:493] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:36.272228 21136 raft_consensus.cc:3060] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:36.272841 21136 raft_consensus.cc:515] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f728af62a1064779b6ab2923df71a5fe" member_type: VOTER }
I20260812 06:18:36.272957 21136 leader_election.cc:304] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe [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: f728af62a1064779b6ab2923df71a5fe; no voters: 
I20260812 06:18:36.273113 21136 leader_election.cc:290] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:36.273207 21140 raft_consensus.cc:2804] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:36.273402 21140 raft_consensus.cc:697] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe [term 1 LEADER]: Becoming Leader. State: Replica: f728af62a1064779b6ab2923df71a5fe, State: Running, Role: LEADER
I20260812 06:18:36.273492 21136 sys_catalog.cc:565] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:36.273531 21140 consensus_queue.cc:237] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe [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: "f728af62a1064779b6ab2923df71a5fe" member_type: VOTER }
I20260812 06:18:36.273934 21143 sys_catalog.cc:455] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "f728af62a1064779b6ab2923df71a5fe" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f728af62a1064779b6ab2923df71a5fe" member_type: VOTER } }
I20260812 06:18:36.273959 21144 sys_catalog.cc:455] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe [sys.catalog]: SysCatalogTable state changed. Reason: New leader f728af62a1064779b6ab2923df71a5fe. Latest consensus state: current_term: 1 leader_uuid: "f728af62a1064779b6ab2923df71a5fe" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f728af62a1064779b6ab2923df71a5fe" member_type: VOTER } }
I20260812 06:18:36.274025 21143 sys_catalog.cc:458] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:36.274040 21144 sys_catalog.cc:458] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:36.275126 20668 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:18:36.275559 21168 catalog_manager.cc:1594] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:18:36.275616 21168 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:18:36.275693 21152 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:36.276242 21152 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:36.277850 21152 catalog_manager.cc:1383] Generated new cluster ID: d90c85bcddbf41ddb09b1ff1f230fc8e
I20260812 06:18:36.277905 21152 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:36.288324 21152 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:36.288786 21152 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:36.297392 21152 catalog_manager.cc:6092] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe: Generated new TSK 0
I20260812 06:18:36.297518 21152 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:36.307125 20668 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:36.308593 21171 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:18:36.308676 20668 server_base.cc:1061] running on GCE node
W20260812 06:18:36.308619 21172 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:18:36.308763 21176 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:18:36.308911 20668 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:36.308951 20668 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:18:36.308970 20668 hybrid_clock.cc:648] HybridClock initialized: now 1786515516308970 us; error 0 us; skew 500 ppm
I20260812 06:18:36.309674 20668 webserver.cc:533] Webserver started at http://127.20.47.1:40715/ using document root <none> and password file <none>
I20260812 06:18:36.309793 20668 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:36.309891 20668 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:36.309952 20668 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:36.310235 20668 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/instance:
uuid: "aa8a921f613a4fb1a5e08f73d697c1fa"
format_stamp: "Formatted at 2026-08-12 06:18:36 on dist-test-slave-6zbq"
I20260812 06:18:36.311499 20668 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:36.312266 21191 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:18:36.312464 20668 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:36.312521 20668 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root
uuid: "aa8a921f613a4fb1a5e08f73d697c1fa"
format_stamp: "Formatted at 2026-08-12 06:18:36 on dist-test-slave-6zbq"
I20260812 06:18:36.312572 20668 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-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:18:36.321024 20668 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:36.321280 20668 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:36.321498 20668 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:36.321843 20668 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:36.321875 20668 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:36.321903 20668 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:36.321923 20668 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:36.325613 20668 rpc_server.cc:307] RPC server started. Bound to: 127.20.47.1:45005
I20260812 06:18:36.325636 21290 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.47.1:45005 every 8 connection(s)
I20260812 06:18:36.333319 21293 heartbeater.cc:344] Connected to a master server at 127.20.47.62:46227
I20260812 06:18:36.333401 21293 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:36.333567 21293 heartbeater.cc:507] Master 127.20.47.62:46227 requested a full tablet report, sending...
I20260812 06:18:36.334093 21082 ts_manager.cc:194] Registered new tserver with Master: aa8a921f613a4fb1a5e08f73d697c1fa (127.20.47.1:45005)
I20260812 06:18:36.334647 20668 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008691843s
I20260812 06:18:36.334777 21082 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:57360
I20260812 06:18:36.340618 21082 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:57368:
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:18:36.347788 21232 tablet_service.cc:1511] Processing CreateTablet for tablet 6c21452f65d9445cad6eac1fcf3c249b (DEFAULT_TABLE table=heavy-update-compaction-test [id=db5d26796daa478c9fe5d1560b8a2f60]), partition=
I20260812 06:18:36.348040 21232 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 6c21452f65d9445cad6eac1fcf3c249b. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:36.349673 21312 tablet_bootstrap.cc:492] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Bootstrap starting.
I20260812 06:18:36.350589 21312 tablet_bootstrap.cc:654] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:36.351500 21312 tablet_bootstrap.cc:492] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: No bootstrap required, opened a new log
I20260812 06:18:36.351567 21312 ts_tablet_manager.cc:1403] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:36.351897 21312 raft_consensus.cc:359] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aa8a921f613a4fb1a5e08f73d697c1fa" member_type: VOTER last_known_addr { host: "127.20.47.1" port: 45005 } }
I20260812 06:18:36.351969 21312 raft_consensus.cc:385] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:36.351995 21312 raft_consensus.cc:740] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: aa8a921f613a4fb1a5e08f73d697c1fa, State: Initialized, Role: FOLLOWER
I20260812 06:18:36.352084 21312 consensus_queue.cc:260] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa [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: "aa8a921f613a4fb1a5e08f73d697c1fa" member_type: VOTER last_known_addr { host: "127.20.47.1" port: 45005 } }
I20260812 06:18:36.352139 21312 raft_consensus.cc:399] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:36.352165 21312 raft_consensus.cc:493] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:36.352206 21312 raft_consensus.cc:3060] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:36.353036 21312 raft_consensus.cc:515] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aa8a921f613a4fb1a5e08f73d697c1fa" member_type: VOTER last_known_addr { host: "127.20.47.1" port: 45005 } }
I20260812 06:18:36.353159 21312 leader_election.cc:304] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa [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: aa8a921f613a4fb1a5e08f73d697c1fa; no voters: 
I20260812 06:18:36.353341 21312 leader_election.cc:290] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:36.353464 21316 raft_consensus.cc:2804] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:36.353657 21312 ts_tablet_manager.cc:1434] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:36.353693 21316 raft_consensus.cc:697] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa [term 1 LEADER]: Becoming Leader. State: Replica: aa8a921f613a4fb1a5e08f73d697c1fa, State: Running, Role: LEADER
I20260812 06:18:36.353822 21293 heartbeater.cc:499] Master 127.20.47.62:46227 was elected leader, sending a full tablet report...
I20260812 06:18:36.353853 21316 consensus_queue.cc:237] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa [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: "aa8a921f613a4fb1a5e08f73d697c1fa" member_type: VOTER last_known_addr { host: "127.20.47.1" port: 45005 } }
I20260812 06:18:36.355085 21082 catalog_manager.cc:5719] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa reported cstate change: term changed from 0 to 1, leader changed from <none> to aa8a921f613a4fb1a5e08f73d697c1fa (127.20.47.1). New cstate: current_term: 1 leader_uuid: "aa8a921f613a4fb1a5e08f73d697c1fa" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aa8a921f613a4fb1a5e08f73d697c1fa" member_type: VOTER last_known_addr { host: "127.20.47.1" port: 45005 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:36.405066 20668 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.046s	user 0.014s	sys 0.006s
I20260812 06:18:36.576332 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushMRSOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=23.023690
I20260812 06:18:36.741824 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushMRSOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.165s	user 0.126s	sys 0.036s Metrics: {"bytes_written":15999660,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":50,"dirs.run_cpu_time_us":169,"dirs.run_wall_time_us":684,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45638,"lbm_writes_lt_1ms":957,"peak_mem_usage":0,"reinsert_count":0,"rows_written":106,"update_count":1950}
I20260812 06:18:36.742640 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling LogGCOp(6c21452f65d9445cad6eac1fcf3c249b): free 29057938 bytes of WAL
I20260812 06:18:36.742867 21198 log_reader.cc:385] T 6c21452f65d9445cad6eac1fcf3c249b: removed 3 log segments from log reader
I20260812 06:18:36.742925 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000001 (ops 1-6)
I20260812 06:18:36.742966 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000002 (ops 7-10)
I20260812 06:18:36.743003 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000003 (ops 11-15)
I20260812 06:18:36.748510 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: LogGCOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.006s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:18:36.748927 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling UndoDeltaBlockGCOp(6c21452f65d9445cad6eac1fcf3c249b): 20924070 bytes on disk
I20260812 06:18:36.749325 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: UndoDeltaBlockGCOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:18:36.749810 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=3.181125
I20260812 06:18:36.769244 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.019s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6318,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:36.769616 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=2.188937
I20260812 06:18:36.778667 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3438,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:36.779000 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=1.000000
I20260812 06:18:36.944312 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.165s	user 0.117s	sys 0.048s Metrics: {"cfile_cache_miss":623,"cfile_cache_miss_bytes":28548933,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":874,"lbm_read_time_us":13573,"lbm_reads_lt_1ms":659,"lbm_write_time_us":28218,"lbm_writes_lt_1ms":633,"peak_mem_usage":74091738,"reinsert_count":0,"spinlock_wait_cycles":2816,"thread_start_us":411,"threads_started":5,"update_count":2950}
I20260812 06:18:36.944957 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=14.095187
I20260812 06:18:36.994242 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.049s	user 0.034s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21565,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:36.994699 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=2.188937
I20260812 06:18:37.004509 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3471,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.005023 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=1.000000
I20260812 06:18:37.142409 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.137s	user 0.098s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856653,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":840,"lbm_read_time_us":11186,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24772,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2500}
I20260812 06:18:37.142912 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=11.118625
I20260812 06:18:37.173765 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.031s	user 0.016s	sys 0.011s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":13054,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:37.174162 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=2.188937
I20260812 06:18:37.198028 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.024s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5249,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.198483 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=2.188937
I20260812 06:18:37.206776 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.008s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3171,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:37.207226 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=1.000000
I20260812 06:18:37.344780 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.137s	user 0.109s	sys 0.027s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24856763,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":626,"lbm_read_time_us":11460,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26560,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:18:37.345379 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=11.118625
I20260812 06:18:37.383140 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.038s	user 0.013s	sys 0.024s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":16562,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:37.383589 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=2.188937
I20260812 06:18:37.393013 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3311,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:37.393399 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=1.000000
I20260812 06:18:37.509588 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.116s	user 0.096s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20754232,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":454,"lbm_read_time_us":7293,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22555,"lbm_writes_lt_1ms":443,"mutex_wait_us":18,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":78336,"update_count":2000}
I20260812 06:18:37.510036 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=10.126437
I20260812 06:18:37.549007 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.039s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12594,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:37.549448 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=2.188937
I20260812 06:18:37.558975 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3687,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.559340 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=1.000000
I20260812 06:18:37.692497 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.133s	user 0.093s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20754243,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":97,"lbm_read_time_us":9879,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21248,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":58752,"update_count":2000}
I20260812 06:18:37.693104 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=10.126437
I20260812 06:18:37.739912 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.047s	user 0.034s	sys 0.011s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":22963,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:18:37.740424 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=2.188937
I20260812 06:18:37.759356 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.019s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5606,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.759909 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushMRSOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=1.000000
I20260812 06:18:37.795509 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushMRSOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.035s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":48,"dirs.run_cpu_time_us":141,"dirs.run_wall_time_us":1022,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1717,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:37.796316 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=3.181125
I20260812 06:18:37.821648 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.025s	user 0.013s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6376,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:37.822075 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling LogGCOp(6c21452f65d9445cad6eac1fcf3c249b): free 108535447 bytes of WAL
I20260812 06:18:37.822283 21198 log_reader.cc:385] T 6c21452f65d9445cad6eac1fcf3c249b: removed 11 log segments from log reader
I20260812 06:18:37.822328 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000004 (ops 16-20)
I20260812 06:18:37.822383 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000005 (ops 21-25)
I20260812 06:18:37.822420 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000006 (ops 26-30)
I20260812 06:18:37.822443 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000007 (ops 31-34)
I20260812 06:18:37.822464 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000008 (ops 35-39)
I20260812 06:18:37.822496 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000009 (ops 40-44)
I20260812 06:18:37.822528 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000010 (ops 45-48)
I20260812 06:18:37.822561 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000011 (ops 49-53)
I20260812 06:18:37.822592 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000012 (ops 54-58)
I20260812 06:18:37.822624 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000013 (ops 59-63)
I20260812 06:18:37.822664 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000014 (ops 64-68)
I20260812 06:18:37.841120 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: LogGCOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.019s	user 0.000s	sys 0.016s Metrics: {}
I20260812 06:18:37.841461 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling UndoDeltaBlockGCOp(6c21452f65d9445cad6eac1fcf3c249b): 447 bytes on disk
I20260812 06:18:37.841823 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: UndoDeltaBlockGCOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:18:37.842268 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=2.188937
I20260812 06:18:37.854079 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4246,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":450}
I20260812 06:18:37.854550 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling LogGCOp(6c21452f65d9445cad6eac1fcf3c249b): free 11564875 bytes of WAL
I20260812 06:18:37.854732 21198 log_reader.cc:385] T 6c21452f65d9445cad6eac1fcf3c249b: removed 1 log segments from log reader
I20260812 06:18:37.854773 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000015 (ops 69-72)
I20260812 06:18:37.857283 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: LogGCOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:37.857560 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=1.000000
I20260812 06:18:38.061547 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.204s	user 0.130s	sys 0.061s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28959296,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1108,"lbm_read_time_us":13118,"lbm_reads_lt_1ms":670,"lbm_write_time_us":32239,"lbm_writes_lt_1ms":643,"mutex_wait_us":307,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"thread_start_us":84,"threads_started":1,"update_count":3000}
I20260812 06:18:38.062074 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=18.063937
I20260812 06:18:38.122541 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.060s	user 0.033s	sys 0.027s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":23343,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:38.122998 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=2.188937
I20260812 06:18:38.132289 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3666,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:38.132647 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=1.000000
I20260812 06:18:38.315930 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.183s	user 0.114s	sys 0.069s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28959067,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":115,"lbm_read_time_us":12886,"lbm_reads_lt_1ms":672,"lbm_write_time_us":28670,"lbm_writes_lt_1ms":643,"mutex_wait_us":24,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":3000}
I20260812 06:18:38.316735 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=15.087375
I20260812 06:18:38.352638 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.036s	user 0.025s	sys 0.008s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":15752,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:38.353104 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=2.188937
I20260812 06:18:38.366592 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.013s	user 0.004s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4142,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:38.367149 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=1.000000
I20260812 06:18:38.542507 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.175s	user 0.118s	sys 0.054s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856641,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":390,"dirs.run_cpu_time_us":1078,"dirs.run_wall_time_us":7343,"lbm_read_time_us":12728,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29637,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14464,"update_count":2500}
I20260812 06:18:38.543011 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=14.095187
I20260812 06:18:38.595110 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.052s	user 0.039s	sys 0.012s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":18544,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:38.595610 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=2.188937
I20260812 06:18:38.609701 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5535,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:38.610141 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=1.000000
I20260812 06:18:38.780442 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.170s	user 0.113s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856657,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":891,"lbm_read_time_us":11885,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29081,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2500}
I20260812 06:18:38.780913 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=14.095187
I20260812 06:18:38.835156 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.054s	user 0.027s	sys 0.019s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17131,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:38.835665 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=2.188937
I20260812 06:18:38.845079 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3696,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:38.845506 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=1.000000
I20260812 06:18:39.018494 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.173s	user 0.112s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856656,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":512,"lbm_read_time_us":12453,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26844,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2500}
I20260812 06:18:39.018934 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=14.095187
I20260812 06:18:39.069180 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.050s	user 0.018s	sys 0.030s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21480,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:39.069655 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=2.188937
I20260812 06:18:39.091442 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.022s	user 0.004s	sys 0.017s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5451,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.092190 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=1.000000
I20260812 06:18:39.257083 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.165s	user 0.095s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856653,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":879,"lbm_read_time_us":10525,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26181,"lbm_writes_lt_1ms":543,"mutex_wait_us":282,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24064,"update_count":2500}
I20260812 06:18:39.257589 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=14.095187
I20260812 06:18:39.299813 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.040s	user 0.026s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17405,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:39.300307 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=2.188937
I20260812 06:18:39.314666 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5572,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.315155 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushMRSOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=1.000000
I20260812 06:18:39.354993 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushMRSOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.040s	user 0.030s	sys 0.005s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":48,"dirs.run_cpu_time_us":155,"dirs.run_wall_time_us":1072,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2227,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:39.356210 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling LogGCOp(6c21452f65d9445cad6eac1fcf3c249b): free 124710315 bytes of WAL
I20260812 06:18:39.356422 21198 log_reader.cc:385] T 6c21452f65d9445cad6eac1fcf3c249b: removed 12 log segments from log reader
I20260812 06:18:39.356498 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000016 (ops 73-77)
I20260812 06:18:39.356601 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000017 (ops 78-82)
I20260812 06:18:39.356654 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000018 (ops 83-87)
I20260812 06:18:39.356679 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000019 (ops 88-92)
I20260812 06:18:39.356752 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000020 (ops 93-97)
I20260812 06:18:39.356791 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000021 (ops 98-102)
I20260812 06:18:39.356849 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000022 (ops 103-107)
I20260812 06:18:39.357102 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000023 (ops 108-112)
I20260812 06:18:39.357185 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000024 (ops 113-117)
I20260812 06:18:39.357218 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000025 (ops 118-122)
I20260812 06:18:39.357241 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000026 (ops 123-127)
I20260812 06:18:39.357286 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000027 (ops 128-132)
I20260812 06:18:39.381376 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: LogGCOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:18:39.381758 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling UndoDeltaBlockGCOp(6c21452f65d9445cad6eac1fcf3c249b): 492 bytes on disk
I20260812 06:18:39.382202 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: UndoDeltaBlockGCOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:18:39.382727 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=4.173312
I20260812 06:18:39.399678 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":5907728,"delete_count":0,"lbm_write_time_us":6943,"lbm_writes_lt_1ms":147,"reinsert_count":0,"update_count":720}
I20260812 06:18:39.400050 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=1.196750
I20260812 06:18:39.406258 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.006s	user 0.001s	sys 0.003s Metrics: {"bytes_written":2297554,"delete_count":0,"lbm_write_time_us":1965,"lbm_writes_lt_1ms":59,"reinsert_count":0,"update_count":280}
I20260812 06:18:39.406785 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=1.000000
I20260812 06:18:39.625590 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.219s	user 0.144s	sys 0.071s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33061673,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":496,"lbm_read_time_us":14106,"lbm_reads_lt_1ms":774,"lbm_write_time_us":33585,"lbm_writes_lt_1ms":743,"mutex_wait_us":292,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4224,"thread_start_us":85,"threads_started":1,"update_count":3500}
I20260812 06:18:39.626151 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=18.063937
I20260812 06:18:39.686836 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.060s	user 0.031s	sys 0.020s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":22989,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:39.687355 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=2.188937
I20260812 06:18:39.696635 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3565,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.697005 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=1.000000
I20260812 06:18:39.877308 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.180s	user 0.108s	sys 0.072s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28959069,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":940,"lbm_read_time_us":12549,"lbm_reads_lt_1ms":672,"lbm_write_time_us":30010,"lbm_writes_lt_1ms":643,"mutex_wait_us":348,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19328,"update_count":3000}
I20260812 06:18:39.877885 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=14.095187
I20260812 06:18:39.920310 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.042s	user 0.029s	sys 0.011s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18435,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:39.920802 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=2.188937
I20260812 06:18:39.935266 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5561,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.935678 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=1.000000
I20260812 06:18:40.107620 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.172s	user 0.123s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856656,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":547,"lbm_read_time_us":12713,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29280,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2500}
I20260812 06:18:40.108053 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=14.095187
I20260812 06:18:40.166697 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.058s	user 0.039s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":18883,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:18:40.167243 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=2.188937
I20260812 06:18:40.181957 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5565,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:40.185328 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=1.000000
I20260812 06:18:40.357421 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.172s	user 0.113s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856651,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":160,"lbm_read_time_us":12791,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26843,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":56576,"update_count":2500}
I20260812 06:18:40.357880 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=14.095187
I20260812 06:18:40.410687 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.053s	user 0.030s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17223,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:40.411265 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=2.188937
I20260812 06:18:40.425716 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5542,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:40.426158 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=1.000000
I20260812 06:18:40.606776 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.180s	user 0.129s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856653,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":163,"lbm_read_time_us":13151,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29245,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2500}
I20260812 06:18:40.607337 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=14.095187
I20260812 06:18:40.662767 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.055s	user 0.031s	sys 0.023s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":20623,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:40.663228 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=2.188937
I20260812 06:18:40.672878 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3615,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:40.673388 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushMRSOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=1.000000
I20260812 06:18:40.707926 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushMRSOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.034s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":48,"dirs.run_cpu_time_us":142,"dirs.run_wall_time_us":1073,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1313,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:40.708531 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling LogGCOp(6c21452f65d9445cad6eac1fcf3c249b): free 112692617 bytes of WAL
I20260812 06:18:40.708727 21198 log_reader.cc:385] T 6c21452f65d9445cad6eac1fcf3c249b: removed 11 log segments from log reader
I20260812 06:18:40.708770 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000028 (ops 133-137)
I20260812 06:18:40.708796 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000029 (ops 138-142)
I20260812 06:18:40.708835 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000030 (ops 143-147)
I20260812 06:18:40.708869 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000031 (ops 148-152)
I20260812 06:18:40.708900 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000032 (ops 153-157)
I20260812 06:18:40.708932 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000033 (ops 158-162)
I20260812 06:18:40.708963 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000034 (ops 163-167)
I20260812 06:18:40.708999 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000035 (ops 168-172)
I20260812 06:18:40.709030 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000036 (ops 173-177)
I20260812 06:18:40.709061 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000037 (ops 178-182)
I20260812 06:18:40.709092 21198 log.cc:1079] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: Deleting log segment in path: /tmp/dist-test-taskUJAyWF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515511330277-20668-0/minicluster-data/ts-0-root/wals/6c21452f65d9445cad6eac1fcf3c249b/wal-000000038 (ops 183-187)
I20260812 06:18:40.730291 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: LogGCOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.022s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:18:40.730768 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling UndoDeltaBlockGCOp(6c21452f65d9445cad6eac1fcf3c249b): 447 bytes on disk
I20260812 06:18:40.731236 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: UndoDeltaBlockGCOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:18:40.732036 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=2.188937
I20260812 06:18:40.748667 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.015s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4225735,"delete_count":0,"lbm_write_time_us":4000,"lbm_writes_lt_1ms":106,"mutex_wait_us":403,"reinsert_count":0,"update_count":515}
I20260812 06:18:40.749029 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=2.188937
I20260812 06:18:40.757790 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3979583,"delete_count":0,"lbm_write_time_us":3326,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:18:40.758131 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=1.000000
I20260812 06:18:40.926823 20668 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.522s	user 1.671s	sys 0.157s
I20260812 06:18:40.963483 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.205s	user 0.138s	sys 0.066s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33061720,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":14024,"lbm_reads_lt_1ms":770,"lbm_write_time_us":34647,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"update_count":3500}
I20260812 06:18:40.963963 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=14.095187
I20260812 06:18:41.009738 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: FlushDeltaMemStoresOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.046s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21373,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:18:41.010125 21294 maintenance_manager.cc:419] P aa8a921f613a4fb1a5e08f73d697c1fa: Scheduling MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b): perf score=1.000000
I20260812 06:18:41.032248 20668 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.105s	user 0.002s	sys 0.000s
I20260812 06:18:41.032797 20668 tablet_server.cc:179] TabletServer@127.20.47.1:0 shutting down...
I20260812 06:18:41.123314 21198 maintenance_manager.cc:643] P aa8a921f613a4fb1a5e08f73d697c1fa: MajorDeltaCompactionOp(6c21452f65d9445cad6eac1fcf3c249b) complete. Timing: real 0.113s	user 0.085s	sys 0.028s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20754122,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":229,"lbm_read_time_us":9718,"lbm_reads_lt_1ms":467,"lbm_write_time_us":20934,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":18,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22784,"update_count":2000}
I20260812 06:18:41.123858 20668 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:41.124128 20668 tablet_replica.cc:333] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa: stopping tablet replica
I20260812 06:18:41.124261 20668 raft_consensus.cc:2243] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:41.124416 20668 raft_consensus.cc:2272] T 6c21452f65d9445cad6eac1fcf3c249b P aa8a921f613a4fb1a5e08f73d697c1fa [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:41.127785 20668 tablet_server.cc:196] TabletServer@127.20.47.1:0 shutdown complete.
I20260812 06:18:41.160868 20668 master.cc:562] Master@127.20.47.62:46227 shutting down...
I20260812 06:18:41.163637 20668 raft_consensus.cc:2243] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:41.163781 20668 raft_consensus.cc:2272] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:41.163846 20668 tablet_replica.cc:333] T 00000000000000000000000000000000 P f728af62a1064779b6ab2923df71a5fe: stopping tablet replica
I20260812 06:18:41.175598 20668 master.cc:584] Master@127.20.47.62:46227 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5008 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (9910 ms total)

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