[==========] 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:17:12.052999 14778 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.14.110.190:37639
I20260812 06:17:12.053964 14778 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:17:12.054538 14778 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:12.060472 14795 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:12.060737 14791 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:17:12.060971 14778 server_base.cc:1061] running on GCE node
W20260812 06:17:12.061123 14793 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:12.061573 14778 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:12.061676 14778 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:12.061704 14778 hybrid_clock.cc:648] HybridClock initialized: now 1786515432061703 us; error 0 us; skew 500 ppm
I20260812 06:17:12.063295 14778 webserver.cc:533] Webserver started at http://127.14.110.190:41805/ using document root <none> and password file <none>
I20260812 06:17:12.063823 14778 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:12.063900 14778 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:12.064136 14778 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:12.065691 14778 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/master-0-root/instance:
uuid: "7f326e73a8a643ff8a5540317c343478"
format_stamp: "Formatted at 2026-08-12 06:17:12 on dist-test-slave-jlzn"
I20260812 06:17:12.068948 14778 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:17:12.070904 14806 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:12.072162 14778 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:12.072268 14778 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/master-0-root
uuid: "7f326e73a8a643ff8a5540317c343478"
format_stamp: "Formatted at 2026-08-12 06:17:12 on dist-test-slave-jlzn"
I20260812 06:17:12.072367 14778 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:12.082201 14778 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:12.082770 14778 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:17:12.082922 14778 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:12.090159 14778 rpc_server.cc:307] RPC server started. Bound to: 127.14.110.190:37639
I20260812 06:17:12.090181 14897 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.110.190:37639 every 8 connection(s)
I20260812 06:17:12.092383 14898 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:12.097632 14898 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478: Bootstrap starting.
I20260812 06:17:12.099967 14898 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:12.100859 14898 log.cc:826] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:12.102516 14898 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478: No bootstrap required, opened a new log
I20260812 06:17:12.105329 14898 raft_consensus.cc:359] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7f326e73a8a643ff8a5540317c343478" member_type: VOTER }
I20260812 06:17:12.105497 14898 raft_consensus.cc:385] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:12.105543 14898 raft_consensus.cc:740] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7f326e73a8a643ff8a5540317c343478, State: Initialized, Role: FOLLOWER
I20260812 06:17:12.106141 14898 consensus_queue.cc:260] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478 [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: "7f326e73a8a643ff8a5540317c343478" member_type: VOTER }
I20260812 06:17:12.106289 14898 raft_consensus.cc:399] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:12.106338 14898 raft_consensus.cc:493] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:12.106428 14898 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:12.107162 14898 raft_consensus.cc:515] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7f326e73a8a643ff8a5540317c343478" member_type: VOTER }
I20260812 06:17:12.107544 14898 leader_election.cc:304] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478 [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: 7f326e73a8a643ff8a5540317c343478; no voters: 
I20260812 06:17:12.107857 14898 leader_election.cc:290] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:12.108004 14901 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:12.108238 14901 raft_consensus.cc:697] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478 [term 1 LEADER]: Becoming Leader. State: Replica: 7f326e73a8a643ff8a5540317c343478, State: Running, Role: LEADER
I20260812 06:17:12.108649 14901 consensus_queue.cc:237] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478 [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: "7f326e73a8a643ff8a5540317c343478" member_type: VOTER }
I20260812 06:17:12.108798 14898 sys_catalog.cc:565] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:12.110514 14904 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 7f326e73a8a643ff8a5540317c343478. Latest consensus state: current_term: 1 leader_uuid: "7f326e73a8a643ff8a5540317c343478" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7f326e73a8a643ff8a5540317c343478" member_type: VOTER } }
I20260812 06:17:12.110500 14903 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "7f326e73a8a643ff8a5540317c343478" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7f326e73a8a643ff8a5540317c343478" member_type: VOTER } }
I20260812 06:17:12.110632 14903 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:12.110632 14904 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:12.110970 14929 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:12.110992 14778 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:12.113261 14929 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:12.117367 14929 catalog_manager.cc:1383] Generated new cluster ID: c0caa4fa40a6419eab4a943dd71e40eb
I20260812 06:17:12.117435 14929 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:12.138507 14929 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:12.139396 14929 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:12.148128 14929 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478: Generated new TSK 0
I20260812 06:17:12.148749 14929 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:12.176011 14778 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:12.178915 14936 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:12.178973 14939 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:12.179210 14778 server_base.cc:1061] running on GCE node
W20260812 06:17:12.179055 14942 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:12.179504 14778 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:12.179553 14778 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:12.179567 14778 hybrid_clock.cc:648] HybridClock initialized: now 1786515432179567 us; error 0 us; skew 500 ppm
I20260812 06:17:12.180424 14778 webserver.cc:533] Webserver started at http://127.14.110.129:34469/ using document root <none> and password file <none>
I20260812 06:17:12.180575 14778 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:12.180634 14778 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:12.180711 14778 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:12.181068 14778 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/instance:
uuid: "279c1b6336a54215861b6163143bc2f4"
format_stamp: "Formatted at 2026-08-12 06:17:12 on dist-test-slave-jlzn"
I20260812 06:17:12.182507 14778 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:12.183409 14947 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:12.183650 14778 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:12.183719 14778 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root
uuid: "279c1b6336a54215861b6163143bc2f4"
format_stamp: "Formatted at 2026-08-12 06:17:12 on dist-test-slave-jlzn"
I20260812 06:17:12.183787 14778 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:12.198989 14778 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:12.199640 14778 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:12.200162 14778 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:12.200984 14778 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:12.201036 14778 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:12.201081 14778 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:12.201109 14778 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:12.207094 14778 rpc_server.cc:307] RPC server started. Bound to: 127.14.110.129:42725
I20260812 06:17:12.207129 15054 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.110.129:42725 every 8 connection(s)
I20260812 06:17:12.220522 15055 heartbeater.cc:344] Connected to a master server at 127.14.110.190:37639
I20260812 06:17:12.220834 15055 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:12.221277 15055 heartbeater.cc:507] Master 127.14.110.190:37639 requested a full tablet report, sending...
I20260812 06:17:12.222748 14831 ts_manager.cc:194] Registered new tserver with Master: 279c1b6336a54215861b6163143bc2f4 (127.14.110.129:42725)
I20260812 06:17:12.223299 14778 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015616538s
I20260812 06:17:12.224347 14831 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39944
I20260812 06:17:12.232758 14831 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39946:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:12.245708 14987 tablet_service.cc:1511] Processing CreateTablet for tablet 70a878eae14b4b97b257c17066ec0ada (DEFAULT_TABLE table=heavy-update-compaction-test [id=05bce04f36254b90a32592921d7156e7]), partition=
I20260812 06:17:12.246115 14987 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 70a878eae14b4b97b257c17066ec0ada. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:12.248450 15076 tablet_bootstrap.cc:492] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Bootstrap starting.
I20260812 06:17:12.249662 15076 tablet_bootstrap.cc:654] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:12.250872 15076 tablet_bootstrap.cc:492] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: No bootstrap required, opened a new log
I20260812 06:17:12.250990 15076 ts_tablet_manager.cc:1403] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:12.251538 15076 raft_consensus.cc:359] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "279c1b6336a54215861b6163143bc2f4" member_type: VOTER last_known_addr { host: "127.14.110.129" port: 42725 } }
I20260812 06:17:12.251667 15076 raft_consensus.cc:385] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:12.251719 15076 raft_consensus.cc:740] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 279c1b6336a54215861b6163143bc2f4, State: Initialized, Role: FOLLOWER
I20260812 06:17:12.251873 15076 consensus_queue.cc:260] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4 [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: "279c1b6336a54215861b6163143bc2f4" member_type: VOTER last_known_addr { host: "127.14.110.129" port: 42725 } }
I20260812 06:17:12.251983 15076 raft_consensus.cc:399] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:12.252032 15076 raft_consensus.cc:493] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:12.252084 15076 raft_consensus.cc:3060] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:12.253022 15076 raft_consensus.cc:515] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "279c1b6336a54215861b6163143bc2f4" member_type: VOTER last_known_addr { host: "127.14.110.129" port: 42725 } }
I20260812 06:17:12.253175 15076 leader_election.cc:304] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4 [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: 279c1b6336a54215861b6163143bc2f4; no voters: 
I20260812 06:17:12.253378 15076 leader_election.cc:290] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:12.253485 15080 raft_consensus.cc:2804] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:12.253681 15076 ts_tablet_manager.cc:1434] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:17:12.253754 15080 raft_consensus.cc:697] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4 [term 1 LEADER]: Becoming Leader. State: Replica: 279c1b6336a54215861b6163143bc2f4, State: Running, Role: LEADER
I20260812 06:17:12.254069 15055 heartbeater.cc:499] Master 127.14.110.190:37639 was elected leader, sending a full tablet report...
I20260812 06:17:12.254349 15080 consensus_queue.cc:237] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4 [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: "279c1b6336a54215861b6163143bc2f4" member_type: VOTER last_known_addr { host: "127.14.110.129" port: 42725 } }
I20260812 06:17:12.256933 14831 catalog_manager.cc:5719] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4 reported cstate change: term changed from 0 to 1, leader changed from <none> to 279c1b6336a54215861b6163143bc2f4 (127.14.110.129). New cstate: current_term: 1 leader_uuid: "279c1b6336a54215861b6163143bc2f4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "279c1b6336a54215861b6163143bc2f4" member_type: VOTER last_known_addr { host: "127.14.110.129" port: 42725 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:12.318620 14778 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.018s	sys 0.008s
I20260812 06:17:12.458092 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushMRSOp(70a878eae14b4b97b257c17066ec0ada): perf score=19.054940
I20260812 06:17:12.646988 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushMRSOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.189s	user 0.149s	sys 0.035s Metrics: {"bytes_written":15999657,"cfile_init":1,"compiler_manager_pool.queue_time_us":191,"delete_count":0,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":219,"dirs.run_wall_time_us":897,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45614,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"thread_start_us":102,"threads_started":1,"update_count":1950}
I20260812 06:17:12.648197 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling LogGCOp(70a878eae14b4b97b257c17066ec0ada): free 20743880 bytes of WAL
I20260812 06:17:12.648504 14955 log_reader.cc:385] T 70a878eae14b4b97b257c17066ec0ada: removed 2 log segments from log reader
I20260812 06:17:12.648576 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000001 (ops 1-6)
I20260812 06:17:12.648633 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000002 (ops 7-11)
I20260812 06:17:12.653157 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: LogGCOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:12.653843 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=4.173312
I20260812 06:17:12.670348 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":5333393,"delete_count":0,"lbm_write_time_us":6562,"lbm_writes_lt_1ms":133,"reinsert_count":0,"update_count":650}
I20260812 06:17:12.670740 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling UndoDeltaBlockGCOp(70a878eae14b4b97b257c17066ec0ada): 16821646 bytes on disk
I20260812 06:17:12.671237 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: UndoDeltaBlockGCOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:17:12.671617 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.196750
I20260812 06:17:12.678815 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.007s	user 0.002s	sys 0.004s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":2518,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:17:12.679194 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.000000
I20260812 06:17:12.876639 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.197s	user 0.146s	sys 0.035s Metrics: {"cfile_cache_miss":623,"cfile_cache_miss_bytes":28507944,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":344,"lbm_read_time_us":13300,"lbm_reads_lt_1ms":659,"lbm_write_time_us":29926,"lbm_writes_lt_1ms":633,"mutex_wait_us":34,"peak_mem_usage":74091738,"reinsert_count":0,"spinlock_wait_cycles":14848,"thread_start_us":282,"threads_started":5,"update_count":2950}
I20260812 06:17:12.877108 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=14.095187
I20260812 06:17:12.932554 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.055s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20813,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:12.933274 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=2.188937
I20260812 06:17:12.945214 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4494,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.945788 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.000000
I20260812 06:17:13.102752 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.157s	user 0.104s	sys 0.051s 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":797,"lbm_read_time_us":12065,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27741,"lbm_writes_lt_1ms":543,"mutex_wait_us":279,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":2500}
I20260812 06:17:13.103238 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=11.118625
I20260812 06:17:13.141237 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.038s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":13056,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:13.141810 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=2.188937
I20260812 06:17:13.153367 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4001,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:13.153885 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.000000
I20260812 06:17:13.291708 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.138s	user 0.095s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713262,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":984,"lbm_read_time_us":10053,"lbm_reads_lt_1ms":472,"lbm_write_time_us":19872,"lbm_writes_lt_1ms":443,"mutex_wait_us":63,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:13.292236 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=10.126437
I20260812 06:17:13.335176 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.043s	user 0.018s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15239,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:13.335702 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=2.188937
I20260812 06:17:13.345589 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.010s	user 0.004s	sys 0.004s 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:17:13.346257 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.000000
I20260812 06:17:13.453151 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.107s	user 0.078s	sys 0.028s 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":645,"lbm_read_time_us":7195,"lbm_reads_lt_1ms":472,"lbm_write_time_us":19673,"lbm_writes_lt_1ms":443,"mutex_wait_us":320,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:13.453660 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=10.126437
I20260812 06:17:13.495090 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.041s	user 0.020s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12850,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:13.495631 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=2.188937
I20260812 06:17:13.510561 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5354,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.511076 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.000000
I20260812 06:17:13.630033 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.119s	user 0.095s	sys 0.024s 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":247,"lbm_read_time_us":7831,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23015,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:17:13.630561 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=10.126437
I20260812 06:17:13.678469 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.048s	user 0.017s	sys 0.018s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13983,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:13.678972 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=2.188937
I20260812 06:17:13.689144 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3785,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.689551 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.000000
I20260812 06:17:13.822816 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.133s	user 0.089s	sys 0.044s 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":176,"lbm_read_time_us":10067,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20768,"lbm_writes_lt_1ms":443,"mutex_wait_us":77,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:13.823287 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=10.126437
I20260812 06:17:13.862788 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.039s	user 0.024s	sys 0.004s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":13129,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:13.863332 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=2.188937
I20260812 06:17:13.873099 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3647,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.873569 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushMRSOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.000000
I20260812 06:17:13.906064 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushMRSOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.032s	user 0.028s	sys 0.003s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":241,"dirs.run_wall_time_us":1382,"drs_written":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1464,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:13.906967 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling LogGCOp(70a878eae14b4b97b257c17066ec0ada): free 121006435 bytes of WAL
I20260812 06:17:13.907209 14955 log_reader.cc:385] T 70a878eae14b4b97b257c17066ec0ada: removed 12 log segments from log reader
I20260812 06:17:13.907258 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000003 (ops 12-16)
I20260812 06:17:13.907297 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000004 (ops 17-21)
I20260812 06:17:13.907330 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000005 (ops 22-26)
I20260812 06:17:13.907362 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000006 (ops 27-31)
I20260812 06:17:13.907393 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000007 (ops 32-36)
I20260812 06:17:13.907424 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000008 (ops 37-41)
I20260812 06:17:13.907454 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000009 (ops 42-46)
I20260812 06:17:13.907485 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000010 (ops 47-50)
I20260812 06:17:13.907514 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000011 (ops 51-55)
I20260812 06:17:13.907544 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000012 (ops 56-60)
I20260812 06:17:13.907574 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000013 (ops 61-65)
I20260812 06:17:13.907603 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000014 (ops 66-70)
I20260812 06:17:13.928470 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: LogGCOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.021s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:17:13.928894 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling UndoDeltaBlockGCOp(70a878eae14b4b97b257c17066ec0ada): 473 bytes on disk
I20260812 06:17:13.929431 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: UndoDeltaBlockGCOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:17:13.929905 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=3.181125
I20260812 06:17:13.947892 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.018s	user 0.009s	sys 0.009s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":3869,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:13.948350 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=2.188937
I20260812 06:17:13.962617 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5336,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:13.963150 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.000000
I20260812 06:17:14.163617 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.200s	user 0.121s	sys 0.069s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":528,"lbm_read_time_us":13860,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31908,"lbm_writes_lt_1ms":643,"mutex_wait_us":58,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":72,"threads_started":1,"update_count":3000}
I20260812 06:17:14.164126 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=14.095187
I20260812 06:17:14.222008 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.058s	user 0.024s	sys 0.023s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":16359,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:14.222563 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=2.188937
I20260812 06:17:14.235014 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4613,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.235489 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.000000
I20260812 06:17:14.397645 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.162s	user 0.114s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":157,"lbm_read_time_us":12384,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26013,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2500}
I20260812 06:17:14.398120 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=10.126437
I20260812 06:17:14.439965 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.042s	user 0.024s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14778,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:14.440469 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=2.188937
I20260812 06:17:14.450940 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3701,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.451426 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.000000
I20260812 06:17:14.579435 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.128s	user 0.107s	sys 0.020s 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":490,"lbm_read_time_us":7932,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23621,"lbm_writes_lt_1ms":443,"mutex_wait_us":34,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":80640,"update_count":2000}
I20260812 06:17:14.580021 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=10.126437
I20260812 06:17:14.628705 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.049s	user 0.031s	sys 0.005s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15629,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:14.629163 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=2.188937
I20260812 06:17:14.639310 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3711,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.639945 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.000000
I20260812 06:17:14.757421 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.117s	user 0.096s	sys 0.021s 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":205,"lbm_read_time_us":7880,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20855,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2000}
I20260812 06:17:14.757912 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=10.126437
I20260812 06:17:14.800463 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.042s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13466,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:14.801038 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=2.188937
I20260812 06:17:14.810823 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3610,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.811493 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.000000
I20260812 06:17:14.935371 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.124s	user 0.099s	sys 0.024s 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":523,"lbm_read_time_us":9098,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23679,"lbm_writes_lt_1ms":443,"mutex_wait_us":277,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2000}
I20260812 06:17:14.935868 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=10.126437
I20260812 06:17:14.983470 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.047s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13422,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:14.984093 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=2.188937
I20260812 06:17:14.994318 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3798,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.994771 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.000000
I20260812 06:17:15.132313 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.137s	user 0.106s	sys 0.028s 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":128,"lbm_read_time_us":9490,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22851,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":2000}
I20260812 06:17:15.132789 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=10.126437
I20260812 06:17:15.177280 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.044s	user 0.019s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18386,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:15.177731 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=2.188937
I20260812 06:17:15.187736 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3776,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.188287 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.000000
I20260812 06:17:15.297278 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.109s	user 0.095s	sys 0.013s 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":1014,"lbm_read_time_us":7848,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20135,"lbm_writes_lt_1ms":443,"mutex_wait_us":257,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2000}
I20260812 06:17:15.297777 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=10.126437
I20260812 06:17:15.339769 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.042s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15243,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:15.340296 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=2.188937
I20260812 06:17:15.350354 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.010s	user 0.007s	sys 0.001s 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:17:15.350878 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushMRSOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.000000
I20260812 06:17:15.382869 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushMRSOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":185,"dirs.run_wall_time_us":1517,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1394,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31,"spinlock_wait_cycles":4480}
I20260812 06:17:15.383668 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling LogGCOp(70a878eae14b4b97b257c17066ec0ada): free 136728255 bytes of WAL
I20260812 06:17:15.383963 14955 log_reader.cc:385] T 70a878eae14b4b97b257c17066ec0ada: removed 13 log segments from log reader
I20260812 06:17:15.384020 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000015 (ops 71-75)
I20260812 06:17:15.384059 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000016 (ops 76-80)
I20260812 06:17:15.384091 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000017 (ops 81-85)
I20260812 06:17:15.384125 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000018 (ops 86-90)
I20260812 06:17:15.384157 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000019 (ops 91-95)
I20260812 06:17:15.384188 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000020 (ops 96-100)
I20260812 06:17:15.384218 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000021 (ops 101-105)
I20260812 06:17:15.384248 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000022 (ops 106-110)
I20260812 06:17:15.384279 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000023 (ops 111-115)
I20260812 06:17:15.384310 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000024 (ops 116-120)
I20260812 06:17:15.384336 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000025 (ops 121-125)
I20260812 06:17:15.384359 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000026 (ops 126-130)
I20260812 06:17:15.384382 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000027 (ops 131-135)
I20260812 06:17:15.407917 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: LogGCOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.024s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:17:15.408360 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=3.181125
I20260812 06:17:15.424710 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.016s	user 0.010s	sys 0.005s Metrics: {"bytes_written":5169287,"delete_count":0,"lbm_write_time_us":6429,"lbm_writes_lt_1ms":129,"reinsert_count":0,"update_count":630}
I20260812 06:17:15.425098 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.196750
I20260812 06:17:15.433470 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.008s	user 0.000s	sys 0.006s Metrics: {"bytes_written":3036005,"delete_count":0,"lbm_write_time_us":2671,"lbm_writes_lt_1ms":77,"reinsert_count":0,"update_count":370}
I20260812 06:17:15.433905 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling UndoDeltaBlockGCOp(70a878eae14b4b97b257c17066ec0ada): 482 bytes on disk
I20260812 06:17:15.434320 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: UndoDeltaBlockGCOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:17:15.435091 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.000000
I20260812 06:17:15.592056 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.157s	user 0.110s	sys 0.044s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918308,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":190,"lbm_read_time_us":10031,"lbm_reads_lt_1ms":674,"lbm_write_time_us":28549,"lbm_writes_lt_1ms":643,"mutex_wait_us":18,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14976,"thread_start_us":73,"threads_started":1,"update_count":3000}
I20260812 06:17:15.592489 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=14.095187
I20260812 06:17:15.642421 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.050s	user 0.031s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19792,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:15.642992 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=2.188937
I20260812 06:17:15.658596 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5741,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.659184 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.000000
I20260812 06:17:15.826217 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.167s	user 0.111s	sys 0.036s 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":594,"lbm_read_time_us":9330,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29573,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:15.826730 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=14.095187
I20260812 06:17:15.872817 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.046s	user 0.023s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19119,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:15.873315 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.000000
I20260812 06:17:16.022382 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.149s	user 0.111s	sys 0.031s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713153,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1242,"lbm_read_time_us":11605,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24680,"lbm_writes_lt_1ms":443,"mutex_wait_us":459,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2000}
I20260812 06:17:16.022854 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=11.118625
I20260812 06:17:16.068317 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.045s	user 0.022s	sys 0.022s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15964,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:16.068856 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=2.188937
I20260812 06:17:16.084419 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.015s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4826,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:16.085126 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.000000
I20260812 06:17:16.216152 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.131s	user 0.095s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":252,"lbm_read_time_us":7815,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22172,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:17:16.216775 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=10.126437
I20260812 06:17:16.259405 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.042s	user 0.016s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13569,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.259936 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=2.188937
I20260812 06:17:16.270407 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3869,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.271135 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.000000
I20260812 06:17:16.385392 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.114s	user 0.106s	sys 0.008s 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":282,"lbm_read_time_us":10096,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21201,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":86016,"update_count":2000}
I20260812 06:17:16.385924 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=10.126437
I20260812 06:17:16.423089 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.037s	user 0.023s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18167,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.423592 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=2.188937
I20260812 06:17:16.434887 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3743,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.435611 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.000000
I20260812 06:17:16.558513 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.123s	user 0.095s	sys 0.027s 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":273,"lbm_read_time_us":10120,"lbm_reads_lt_1ms":468,"lbm_write_time_us":23679,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":59264,"update_count":2000}
I20260812 06:17:16.559010 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=10.126437
I20260812 06:17:16.607944 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.049s	user 0.021s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18643,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.608510 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=2.188937
I20260812 06:17:16.618609 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3754,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.619136 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.000000
I20260812 06:17:16.750614 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.131s	user 0.082s	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":208,"lbm_read_time_us":10698,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20770,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:16.751360 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=10.126437
I20260812 06:17:16.791337 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.040s	user 0.017s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16322,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.792009 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=2.188937
I20260812 06:17:16.807754 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.016s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5962,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.808244 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushMRSOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.000000
I20260812 06:17:16.836643 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushMRSOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.028s	user 0.026s	sys 0.001s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":174,"dirs.run_wall_time_us":1187,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1726,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:16.837306 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling LogGCOp(70a878eae14b4b97b257c17066ec0ada): free 124257514 bytes of WAL
I20260812 06:17:16.837540 14955 log_reader.cc:385] T 70a878eae14b4b97b257c17066ec0ada: removed 12 log segments from log reader
I20260812 06:17:16.837597 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000028 (ops 136-140)
I20260812 06:17:16.837633 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000029 (ops 141-145)
I20260812 06:17:16.837710 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000030 (ops 146-150)
I20260812 06:17:16.837754 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000031 (ops 151-155)
I20260812 06:17:16.837777 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000032 (ops 156-160)
I20260812 06:17:16.837855 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000033 (ops 161-165)
I20260812 06:17:16.837919 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000034 (ops 166-170)
I20260812 06:17:16.837972 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000035 (ops 171-174)
I20260812 06:17:16.838021 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000036 (ops 175-179)
I20260812 06:17:16.838066 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000037 (ops 180-184)
I20260812 06:17:16.838136 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000038 (ops 185-189)
I20260812 06:17:16.838186 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000039 (ops 190-194)
I20260812 06:17:16.859586 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: LogGCOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.022s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:17:16.860078 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling UndoDeltaBlockGCOp(70a878eae14b4b97b257c17066ec0ada): 492 bytes on disk
I20260812 06:17:16.860493 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: UndoDeltaBlockGCOp(70a878eae14b4b97b257c17066ec0ada) 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:17:16.861030 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada): perf score=6.157687
I20260812 06:17:16.894297 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: FlushDeltaMemStoresOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.033s	user 0.022s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11782,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:16.894847 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling LogGCOp(70a878eae14b4b97b257c17066ec0ada): free 8767088 bytes of WAL
I20260812 06:17:16.895083 14955 log_reader.cc:385] T 70a878eae14b4b97b257c17066ec0ada: removed 1 log segments from log reader
I20260812 06:17:16.895155 14955 log.cc:1079] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/70a878eae14b4b97b257c17066ec0ada/wal-000000040 (ops 195-199)
I20260812 06:17:16.896751 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: LogGCOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:16.897075 15058 maintenance_manager.cc:419] P 279c1b6336a54215861b6163143bc2f4: Scheduling MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada): perf score=1.000000
I20260812 06:17:16.922685 14778 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.604s	user 1.638s	sys 0.154s
I20260812 06:17:17.011411 14778 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.088s	user 0.004s	sys 0.000s
I20260812 06:17:17.012235 14778 tablet_server.cc:179] TabletServer@127.14.110.129:0 shutting down...
I20260812 06:17:17.060300 14955 maintenance_manager.cc:643] P 279c1b6336a54215861b6163143bc2f4: MajorDeltaCompactionOp(70a878eae14b4b97b257c17066ec0ada) complete. Timing: real 0.163s	user 0.120s	sys 0.042s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918215,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":3126,"lbm_read_time_us":12475,"lbm_reads_lt_1ms":661,"lbm_write_time_us":27301,"lbm_writes_lt_1ms":643,"mutex_wait_us":1020,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5504,"thread_start_us":73,"threads_started":1,"update_count":3000}
I20260812 06:17:17.061308 14778 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:17.061683 14778 tablet_replica.cc:333] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4: stopping tablet replica
I20260812 06:17:17.061896 14778 raft_consensus.cc:2243] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:17.062402 14778 raft_consensus.cc:2272] T 70a878eae14b4b97b257c17066ec0ada P 279c1b6336a54215861b6163143bc2f4 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:17.078961 14778 tablet_server.cc:196] TabletServer@127.14.110.129:0 shutdown complete.
I20260812 06:17:17.110400 14778 master.cc:562] Master@127.14.110.190:37639 shutting down...
I20260812 06:17:17.113894 14778 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:17.114063 14778 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:17.114137 14778 tablet_replica.cc:333] T 00000000000000000000000000000000 P 7f326e73a8a643ff8a5540317c343478: stopping tablet replica
I20260812 06:17:17.126233 14778 master.cc:584] Master@127.14.110.190:37639 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5139 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:17.203181 14778 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.14.110.190:37623
I20260812 06:17:17.203572 14778 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:17.205546 15110 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:17:17.205598 14778 server_base.cc:1061] running on GCE node
W20260812 06:17:17.205686 15111 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:17.205768 15113 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:17.206020 14778 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:17.206071 14778 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:17.206101 14778 hybrid_clock.cc:648] HybridClock initialized: now 1786515437206101 us; error 0 us; skew 500 ppm
I20260812 06:17:17.206907 14778 webserver.cc:533] Webserver started at http://127.14.110.190:32933/ using document root <none> and password file <none>
I20260812 06:17:17.207062 14778 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:17.207121 14778 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:17.207196 14778 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:17.207559 14778 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/master-0-root/instance:
uuid: "a7874b02d696473ea29edf7b4463ae81"
format_stamp: "Formatted at 2026-08-12 06:17:17 on dist-test-slave-jlzn"
I20260812 06:17:17.209184 14778 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:17.210022 15118 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:17.210234 14778 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:17.210302 14778 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/master-0-root
uuid: "a7874b02d696473ea29edf7b4463ae81"
format_stamp: "Formatted at 2026-08-12 06:17:17 on dist-test-slave-jlzn"
I20260812 06:17:17.210371 14778 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:17.220875 14778 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:17.221174 14778 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:17.225104 14778 rpc_server.cc:307] RPC server started. Bound to: 127.14.110.190:37623
I20260812 06:17:17.227679 15206 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.110.190:37623 every 8 connection(s)
I20260812 06:17:17.228179 15208 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:17.229836 15208 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81: Bootstrap starting.
I20260812 06:17:17.230553 15208 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:17.231451 15208 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81: No bootstrap required, opened a new log
I20260812 06:17:17.231848 15208 raft_consensus.cc:359] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a7874b02d696473ea29edf7b4463ae81" member_type: VOTER }
I20260812 06:17:17.231930 15208 raft_consensus.cc:385] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:17.231961 15208 raft_consensus.cc:740] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a7874b02d696473ea29edf7b4463ae81, State: Initialized, Role: FOLLOWER
I20260812 06:17:17.232108 15208 consensus_queue.cc:260] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81 [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: "a7874b02d696473ea29edf7b4463ae81" member_type: VOTER }
I20260812 06:17:17.232195 15208 raft_consensus.cc:399] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:17.232232 15208 raft_consensus.cc:493] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:17.232280 15208 raft_consensus.cc:3060] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:17.232980 15208 raft_consensus.cc:515] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a7874b02d696473ea29edf7b4463ae81" member_type: VOTER }
I20260812 06:17:17.233115 15208 leader_election.cc:304] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81 [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: a7874b02d696473ea29edf7b4463ae81; no voters: 
I20260812 06:17:17.233287 15208 leader_election.cc:290] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:17.233373 15214 raft_consensus.cc:2804] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:17.233551 15214 raft_consensus.cc:697] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81 [term 1 LEADER]: Becoming Leader. State: Replica: a7874b02d696473ea29edf7b4463ae81, State: Running, Role: LEADER
I20260812 06:17:17.233686 15208 sys_catalog.cc:565] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:17.233685 15214 consensus_queue.cc:237] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81 [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: "a7874b02d696473ea29edf7b4463ae81" member_type: VOTER }
I20260812 06:17:17.234089 15216 sys_catalog.cc:455] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "a7874b02d696473ea29edf7b4463ae81" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a7874b02d696473ea29edf7b4463ae81" member_type: VOTER } }
I20260812 06:17:17.234112 15220 sys_catalog.cc:455] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81 [sys.catalog]: SysCatalogTable state changed. Reason: New leader a7874b02d696473ea29edf7b4463ae81. Latest consensus state: current_term: 1 leader_uuid: "a7874b02d696473ea29edf7b4463ae81" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a7874b02d696473ea29edf7b4463ae81" member_type: VOTER } }
I20260812 06:17:17.234237 15216 sys_catalog.cc:458] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:17.234253 15220 sys_catalog.cc:458] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:17.234707 15226 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:17.235569 15226 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:17.235821 14778 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:17.237310 15226 catalog_manager.cc:1383] Generated new cluster ID: cbd1dc81be0f4dbaa3393850891c4d19
I20260812 06:17:17.237360 15226 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:17.251385 15226 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:17.251966 15226 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:17.256933 15226 catalog_manager.cc:6092] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81: Generated new TSK 0
I20260812 06:17:17.257069 15226 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:17.268092 14778 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:17.269825 15243 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:17.269919 15242 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:17:17.269961 14778 server_base.cc:1061] running on GCE node
W20260812 06:17:17.269913 15245 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:17.270228 14778 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:17.270273 14778 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:17.270288 14778 hybrid_clock.cc:648] HybridClock initialized: now 1786515437270288 us; error 0 us; skew 500 ppm
I20260812 06:17:17.271101 14778 webserver.cc:533] Webserver started at http://127.14.110.129:39477/ using document root <none> and password file <none>
I20260812 06:17:17.271252 14778 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:17.271306 14778 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:17.271380 14778 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:17.271750 14778 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/instance:
uuid: "9f4390b6576a4033b2d20a65e7f260c0"
format_stamp: "Formatted at 2026-08-12 06:17:17 on dist-test-slave-jlzn"
I20260812 06:17:17.273157 14778 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:17.273989 15253 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:17.274199 14778 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:17.274266 14778 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root
uuid: "9f4390b6576a4033b2d20a65e7f260c0"
format_stamp: "Formatted at 2026-08-12 06:17:17 on dist-test-slave-jlzn"
I20260812 06:17:17.274328 14778 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:17.299109 14778 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:17.299506 14778 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:17.299836 14778 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:17.300320 14778 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:17.300362 14778 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:17.300407 14778 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:17.300436 14778 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:17.304389 14778 rpc_server.cc:307] RPC server started. Bound to: 127.14.110.129:43489
I20260812 06:17:17.305439 15362 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.110.129:43489 every 8 connection(s)
I20260812 06:17:17.314523 15363 heartbeater.cc:344] Connected to a master server at 127.14.110.190:37623
I20260812 06:17:17.314626 15363 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:17.314828 15363 heartbeater.cc:507] Master 127.14.110.190:37623 requested a full tablet report, sending...
I20260812 06:17:17.315500 15147 ts_manager.cc:194] Registered new tserver with Master: 9f4390b6576a4033b2d20a65e7f260c0 (127.14.110.129:43489)
I20260812 06:17:17.316001 14778 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010935897s
I20260812 06:17:17.316294 15147 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:45068
I20260812 06:17:17.322350 15147 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:45078:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:17.330466 15310 tablet_service.cc:1511] Processing CreateTablet for tablet 8f85bff13f6940da92e87e492deda721 (DEFAULT_TABLE table=heavy-update-compaction-test [id=0276fc65f1394690a8cfdb42c764674b]), partition=
I20260812 06:17:17.330754 15310 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 8f85bff13f6940da92e87e492deda721. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:17.332602 15382 tablet_bootstrap.cc:492] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Bootstrap starting.
I20260812 06:17:17.333505 15382 tablet_bootstrap.cc:654] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:17.334501 15382 tablet_bootstrap.cc:492] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: No bootstrap required, opened a new log
I20260812 06:17:17.334578 15382 ts_tablet_manager.cc:1403] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:17.334975 15382 raft_consensus.cc:359] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9f4390b6576a4033b2d20a65e7f260c0" member_type: VOTER last_known_addr { host: "127.14.110.129" port: 43489 } }
I20260812 06:17:17.335060 15382 raft_consensus.cc:385] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:17.335101 15382 raft_consensus.cc:740] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9f4390b6576a4033b2d20a65e7f260c0, State: Initialized, Role: FOLLOWER
I20260812 06:17:17.335237 15382 consensus_queue.cc:260] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0 [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: "9f4390b6576a4033b2d20a65e7f260c0" member_type: VOTER last_known_addr { host: "127.14.110.129" port: 43489 } }
I20260812 06:17:17.335317 15382 raft_consensus.cc:399] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:17.335357 15382 raft_consensus.cc:493] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:17.335391 15382 raft_consensus.cc:3060] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:17.336179 15382 raft_consensus.cc:515] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9f4390b6576a4033b2d20a65e7f260c0" member_type: VOTER last_known_addr { host: "127.14.110.129" port: 43489 } }
I20260812 06:17:17.336315 15382 leader_election.cc:304] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0 [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: 9f4390b6576a4033b2d20a65e7f260c0; no voters: 
I20260812 06:17:17.336499 15382 leader_election.cc:290] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:17.336607 15384 raft_consensus.cc:2804] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:17.336822 15382 ts_tablet_manager.cc:1434] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:17.336828 15384 raft_consensus.cc:697] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0 [term 1 LEADER]: Becoming Leader. State: Replica: 9f4390b6576a4033b2d20a65e7f260c0, State: Running, Role: LEADER
I20260812 06:17:17.336828 15363 heartbeater.cc:499] Master 127.14.110.190:37623 was elected leader, sending a full tablet report...
I20260812 06:17:17.337014 15384 consensus_queue.cc:237] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0 [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: "9f4390b6576a4033b2d20a65e7f260c0" member_type: VOTER last_known_addr { host: "127.14.110.129" port: 43489 } }
I20260812 06:17:17.338251 15147 catalog_manager.cc:5719] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0 reported cstate change: term changed from 0 to 1, leader changed from <none> to 9f4390b6576a4033b2d20a65e7f260c0 (127.14.110.129). New cstate: current_term: 1 leader_uuid: "9f4390b6576a4033b2d20a65e7f260c0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9f4390b6576a4033b2d20a65e7f260c0" member_type: VOTER last_known_addr { host: "127.14.110.129" port: 43489 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:17.389858 14778 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.048s	user 0.013s	sys 0.008s
I20260812 06:17:17.556052 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushMRSOp(8f85bff13f6940da92e87e492deda721): perf score=23.023690
I20260812 06:17:17.720598 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushMRSOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.164s	user 0.107s	sys 0.055s Metrics: {"bytes_written":13210025,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":916,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41433,"lbm_writes_lt_1ms":879,"mutex_wait_us":1498,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1610}
I20260812 06:17:17.721298 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling LogGCOp(8f85bff13f6940da92e87e492deda721): free 20743880 bytes of WAL
I20260812 06:17:17.721560 15261 log_reader.cc:385] T 8f85bff13f6940da92e87e492deda721: removed 2 log segments from log reader
I20260812 06:17:17.721629 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000001 (ops 1-6)
I20260812 06:17:17.721686 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000002 (ops 7-11)
I20260812 06:17:17.725720 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: LogGCOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:17.726028 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=2.188937
I20260812 06:17:17.738396 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.012s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3610359,"delete_count":0,"lbm_write_time_us":3102,"lbm_writes_lt_1ms":91,"reinsert_count":0,"update_count":440}
I20260812 06:17:17.738752 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=2.188937
I20260812 06:17:17.747359 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.008s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3232,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:17.747714 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721): perf score=1.000000
I20260812 06:17:17.928972 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.181s	user 0.120s	sys 0.060s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815784,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":738,"lbm_read_time_us":11912,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26727,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"thread_start_us":306,"threads_started":5,"update_count":2500}
I20260812 06:17:17.929437 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling UndoDeltaBlockGCOp(8f85bff13f6940da92e87e492deda721): 20513814 bytes on disk
I20260812 06:17:17.929872 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: UndoDeltaBlockGCOp(8f85bff13f6940da92e87e492deda721) 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:17:17.930275 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=14.095187
I20260812 06:17:17.998906 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.068s	user 0.040s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20948,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:17.999356 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=2.188937
I20260812 06:17:18.009253 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3390,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.009805 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721): perf score=1.000000
I20260812 06:17:18.171926 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.162s	user 0.101s	sys 0.059s 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":586,"lbm_read_time_us":10745,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26030,"lbm_writes_lt_1ms":543,"mutex_wait_us":36,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2500}
I20260812 06:17:18.172382 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=14.095187
I20260812 06:17:18.224013 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.051s	user 0.026s	sys 0.021s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19616,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:18.224443 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=2.188937
I20260812 06:17:18.234668 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3968,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.235109 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721): perf score=1.000000
I20260812 06:17:18.398020 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.163s	user 0.112s	sys 0.043s 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":234,"lbm_read_time_us":11111,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25491,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13056,"update_count":2500}
I20260812 06:17:18.398541 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=14.095187
I20260812 06:17:18.455034 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.056s	user 0.027s	sys 0.022s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19800,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:18.455554 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=2.188937
I20260812 06:17:18.465345 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3658,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.465772 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721): perf score=1.000000
I20260812 06:17:18.634963 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.169s	user 0.096s	sys 0.064s 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":94,"lbm_read_time_us":11198,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25075,"lbm_writes_lt_1ms":543,"mutex_wait_us":19,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":57088,"update_count":2500}
I20260812 06:17:18.635655 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=14.095187
I20260812 06:17:18.692258 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.056s	user 0.029s	sys 0.022s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19054,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:18.692878 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=2.188937
I20260812 06:17:18.702987 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3772,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.703498 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721): perf score=1.000000
I20260812 06:17:18.888162 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.184s	user 0.114s	sys 0.060s 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":252,"lbm_read_time_us":12099,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27900,"lbm_writes_lt_1ms":543,"mutex_wait_us":63,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:17:18.888695 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=14.095187
I20260812 06:17:18.933725 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.045s	user 0.019s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":15641,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:18.934329 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=2.188937
I20260812 06:17:18.946250 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4292,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.946738 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushMRSOp(8f85bff13f6940da92e87e492deda721): perf score=1.000000
I20260812 06:17:18.981199 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushMRSOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.034s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":50,"dirs.run_cpu_time_us":245,"dirs.run_wall_time_us":1203,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1986,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:18.981838 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling LogGCOp(8f85bff13f6940da92e87e492deda721): free 121006425 bytes of WAL
I20260812 06:17:18.982064 15261 log_reader.cc:385] T 8f85bff13f6940da92e87e492deda721: removed 12 log segments from log reader
I20260812 06:17:18.982112 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000003 (ops 12-16)
I20260812 06:17:18.982172 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000004 (ops 17-21)
I20260812 06:17:18.982201 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000005 (ops 22-26)
I20260812 06:17:18.982232 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000006 (ops 27-31)
I20260812 06:17:18.982263 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000007 (ops 32-36)
I20260812 06:17:18.982295 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000008 (ops 37-40)
I20260812 06:17:18.982323 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000009 (ops 41-45)
I20260812 06:17:18.982353 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000010 (ops 46-50)
I20260812 06:17:18.982383 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000011 (ops 51-55)
I20260812 06:17:18.982414 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000012 (ops 56-60)
I20260812 06:17:18.982442 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000013 (ops 61-65)
I20260812 06:17:18.982471 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000014 (ops 66-70)
I20260812 06:17:19.002408 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: LogGCOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.020s	user 0.003s	sys 0.014s Metrics: {}
I20260812 06:17:19.002837 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling UndoDeltaBlockGCOp(8f85bff13f6940da92e87e492deda721): 472 bytes on disk
I20260812 06:17:19.003278 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: UndoDeltaBlockGCOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:17:19.003839 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=3.181125
I20260812 06:17:19.028893 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.025s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4512904,"delete_count":0,"lbm_write_time_us":4267,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:19.029371 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling LogGCOp(8f85bff13f6940da92e87e492deda721): free 11564875 bytes of WAL
I20260812 06:17:19.029603 15261 log_reader.cc:385] T 8f85bff13f6940da92e87e492deda721: removed 1 log segments from log reader
I20260812 06:17:19.029673 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000015 (ops 71-74)
I20260812 06:17:19.031409 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: LogGCOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:19.031723 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=2.188937
I20260812 06:17:19.041354 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.009s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3234,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:19.041944 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721): perf score=1.000000
I20260812 06:17:19.268749 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.227s	user 0.147s	sys 0.070s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020737,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":565,"lbm_read_time_us":15205,"lbm_reads_lt_1ms":774,"lbm_write_time_us":34324,"lbm_writes_lt_1ms":743,"mutex_wait_us":47,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":22144,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:17:19.269248 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=18.063937
I20260812 06:17:19.332922 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.064s	user 0.043s	sys 0.004s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":21519,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:19.333401 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=2.188937
I20260812 06:17:19.344738 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.011s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3954,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.345193 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721): perf score=1.000000
I20260812 06:17:19.532976 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.188s	user 0.126s	sys 0.061s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":938,"lbm_read_time_us":13218,"lbm_reads_lt_1ms":672,"lbm_write_time_us":29135,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16128,"update_count":3000}
I20260812 06:17:19.534368 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=14.095187
I20260812 06:17:19.587029 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.051s	user 0.014s	sys 0.033s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19567,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:19.587651 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=2.188937
I20260812 06:17:19.606855 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.019s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5330,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.607470 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721): perf score=1.000000
I20260812 06:17:19.765170 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.157s	user 0.121s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":410,"lbm_read_time_us":10893,"lbm_reads_lt_1ms":564,"lbm_write_time_us":23723,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:17:19.765884 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=14.095187
I20260812 06:17:19.813539 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.047s	user 0.023s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17230,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:19.814103 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=2.188937
I20260812 06:17:19.826401 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4757,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.826926 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721): perf score=1.000000
I20260812 06:17:19.992074 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.165s	user 0.119s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":188,"lbm_read_time_us":11153,"lbm_reads_lt_1ms":568,"lbm_write_time_us":28267,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:19.995884 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=14.095187
I20260812 06:17:20.048345 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.052s	user 0.030s	sys 0.014s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":15246,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.048990 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=2.188937
I20260812 06:17:20.064219 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5845,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.064771 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721): perf score=1.000000
I20260812 06:17:20.240602 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.176s	user 0.120s	sys 0.044s 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":1025,"lbm_read_time_us":12504,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26017,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2500}
I20260812 06:17:20.241122 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=14.095187
I20260812 06:17:20.292783 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.052s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21517,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.293383 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=2.188937
I20260812 06:17:20.316517 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.023s	user 0.008s	sys 0.014s 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:17:20.317073 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushMRSOp(8f85bff13f6940da92e87e492deda721): perf score=1.000000
I20260812 06:17:20.352540 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushMRSOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.035s	user 0.025s	sys 0.002s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1455,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1312,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:20.353283 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling LogGCOp(8f85bff13f6940da92e87e492deda721): free 112239316 bytes of WAL
I20260812 06:17:20.353520 15261 log_reader.cc:385] T 8f85bff13f6940da92e87e492deda721: removed 11 log segments from log reader
I20260812 06:17:20.353595 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000016 (ops 75-79)
I20260812 06:17:20.353639 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000017 (ops 80-84)
I20260812 06:17:20.353672 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000018 (ops 85-89)
I20260812 06:17:20.353705 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000019 (ops 90-94)
I20260812 06:17:20.353734 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000020 (ops 95-99)
I20260812 06:17:20.353760 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000021 (ops 100-104)
I20260812 06:17:20.353785 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000022 (ops 105-108)
I20260812 06:17:20.353813 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000023 (ops 109-113)
I20260812 06:17:20.353845 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000024 (ops 114-118)
I20260812 06:17:20.353876 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000025 (ops 119-123)
I20260812 06:17:20.353900 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000026 (ops 124-128)
I20260812 06:17:20.378115 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: LogGCOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:17:20.378599 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling UndoDeltaBlockGCOp(8f85bff13f6940da92e87e492deda721): 448 bytes on disk
I20260812 06:17:20.379078 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: UndoDeltaBlockGCOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:17:20.379689 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=3.181125
I20260812 06:17:20.398228 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.018s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4240,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:20.398701 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=2.188937
I20260812 06:17:20.407769 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3224,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:20.408293 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721): perf score=1.000000
I20260812 06:17:20.646693 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.238s	user 0.180s	sys 0.046s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020734,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":792,"lbm_read_time_us":15313,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36197,"lbm_writes_lt_1ms":743,"mutex_wait_us":2,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":92,"threads_started":1,"update_count":3500}
I20260812 06:17:20.647321 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=18.063937
I20260812 06:17:20.700312 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.053s	user 0.039s	sys 0.008s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":21292,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:20.700953 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721): perf score=1.000000
I20260812 06:17:20.862709 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.162s	user 0.117s	sys 0.044s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24815568,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":187,"lbm_read_time_us":10776,"lbm_reads_lt_1ms":563,"lbm_write_time_us":27705,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2500}
I20260812 06:17:20.863261 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=14.095187
I20260812 06:17:20.918197 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.055s	user 0.029s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21283,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.918675 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=2.188937
I20260812 06:17:20.928526 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3805,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.928916 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721): perf score=1.000000
I20260812 06:17:21.089586 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.161s	user 0.105s	sys 0.054s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":197,"lbm_read_time_us":11333,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25547,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2500}
I20260812 06:17:21.090086 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=11.118625
I20260812 06:17:21.124639 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.034s	user 0.014s	sys 0.019s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14710,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:21.125308 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=2.188937
I20260812 06:17:21.160077 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.035s	user 0.016s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5935,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:21.160665 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=2.188937
I20260812 06:17:21.175674 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5660,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:21.176120 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721): perf score=1.000000
I20260812 06:17:21.352005 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.176s	user 0.103s	sys 0.062s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815795,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":221,"lbm_read_time_us":12242,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27230,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:17:21.352557 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=14.095187
I20260812 06:17:21.400174 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.047s	user 0.029s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19193,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:21.400676 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=2.188937
I20260812 06:17:21.410914 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.010s	user 0.004s	sys 0.004s 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:17:21.411484 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721): perf score=1.000000
I20260812 06:17:21.586491 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.175s	user 0.113s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":136,"lbm_read_time_us":11976,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27390,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2500}
I20260812 06:17:21.587105 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=14.095187
I20260812 06:17:21.636562 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.049s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19824,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:21.637127 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=2.188937
I20260812 06:17:21.652302 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5676,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:21.652872 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721): perf score=1.000000
I20260812 06:17:21.812664 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.160s	user 0.099s	sys 0.048s 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":1123,"lbm_read_time_us":10214,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30403,"lbm_writes_lt_1ms":543,"mutex_wait_us":333,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:17:21.813153 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=14.095187
I20260812 06:17:21.866793 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.053s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23158,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:21.867316 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=2.188937
I20260812 06:17:21.878386 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3976,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:21.878859 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushMRSOp(8f85bff13f6940da92e87e492deda721): perf score=1.000000
I20260812 06:17:21.910758 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushMRSOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":176,"dirs.run_wall_time_us":1175,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1675,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:21.911580 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling LogGCOp(8f85bff13f6940da92e87e492deda721): free 129773835 bytes of WAL
I20260812 06:17:21.911865 15261 log_reader.cc:385] T 8f85bff13f6940da92e87e492deda721: removed 13 log segments from log reader
I20260812 06:17:21.911917 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000027 (ops 129-133)
I20260812 06:17:21.911957 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000028 (ops 134-138)
I20260812 06:17:21.911989 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000029 (ops 139-143)
I20260812 06:17:21.912021 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000030 (ops 144-148)
I20260812 06:17:21.912052 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000031 (ops 149-153)
I20260812 06:17:21.912082 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000032 (ops 154-158)
I20260812 06:17:21.912112 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000033 (ops 159-163)
I20260812 06:17:21.912142 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000034 (ops 164-168)
I20260812 06:17:21.912171 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000035 (ops 169-172)
I20260812 06:17:21.912200 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000036 (ops 173-177)
I20260812 06:17:21.912230 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000037 (ops 178-182)
I20260812 06:17:21.912261 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000038 (ops 183-187)
I20260812 06:17:21.912289 15261 log.cc:1079] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: Deleting log segment in path: /tmp/dist-test-taskoACETR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515432042543-14778-0/minicluster-data/ts-0-root/wals/8f85bff13f6940da92e87e492deda721/wal-000000039 (ops 188-192)
I20260812 06:17:21.934677 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: LogGCOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.023s	user 0.002s	sys 0.018s Metrics: {}
I20260812 06:17:21.935096 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling UndoDeltaBlockGCOp(8f85bff13f6940da92e87e492deda721): 492 bytes on disk
I20260812 06:17:21.935742 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: UndoDeltaBlockGCOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:17:21.936408 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=3.181125
I20260812 06:17:21.962303 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.026s	user 0.015s	sys 0.008s Metrics: {"bytes_written":4677002,"delete_count":0,"lbm_write_time_us":6547,"lbm_writes_lt_1ms":117,"reinsert_count":0,"update_count":570}
I20260812 06:17:21.962790 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=2.188937
I20260812 06:17:21.971698 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3528305,"delete_count":0,"lbm_write_time_us":3189,"lbm_writes_lt_1ms":89,"reinsert_count":0,"update_count":430}
I20260812 06:17:21.972187 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721): perf score=1.000000
I20260812 06:17:22.108390 14778 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.718s	user 1.664s	sys 0.197s
I20260812 06:17:22.168212 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: MajorDeltaCompactionOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.196s	user 0.112s	sys 0.084s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020735,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":14972,"lbm_reads_lt_1ms":770,"lbm_write_time_us":32814,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"update_count":3500}
I20260812 06:17:22.168727 15364 maintenance_manager.cc:419] P 9f4390b6576a4033b2d20a65e7f260c0: Scheduling FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721): perf score=10.126437
I20260812 06:17:22.193136 14778 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.084s	user 0.001s	sys 0.000s
I20260812 06:17:22.193625 14778 tablet_server.cc:179] TabletServer@127.14.110.129:0 shutting down...
I20260812 06:17:22.230147 15261 maintenance_manager.cc:643] P 9f4390b6576a4033b2d20a65e7f260c0: FlushDeltaMemStoresOp(8f85bff13f6940da92e87e492deda721) complete. Timing: real 0.061s	user 0.013s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12109,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:22.230720 14778 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:22.230959 14778 tablet_replica.cc:333] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0: stopping tablet replica
I20260812 06:17:22.231107 14778 raft_consensus.cc:2243] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:22.239705 14778 raft_consensus.cc:2272] T 8f85bff13f6940da92e87e492deda721 P 9f4390b6576a4033b2d20a65e7f260c0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:22.242803 14778 tablet_server.cc:196] TabletServer@127.14.110.129:0 shutdown complete.
I20260812 06:17:22.245455 14778 master.cc:562] Master@127.14.110.190:37623 shutting down...
I20260812 06:17:22.248561 14778 raft_consensus.cc:2243] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:22.248700 14778 raft_consensus.cc:2272] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:22.248766 14778 tablet_replica.cc:333] T 00000000000000000000000000000000 P a7874b02d696473ea29edf7b4463ae81: stopping tablet replica
I20260812 06:17:22.260635 14778 master.cc:584] Master@127.14.110.190:37623 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5135 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10276 ms total)

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