[==========] 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:19:13.107606 13260 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.12.243.62:43863
I20260812 06:19:13.108599 13260 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:19:13.109175 13260 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:13.116055 13271 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:19:13.116107 13260 server_base.cc:1061] running on GCE node
W20260812 06:19:13.116385 13272 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:19:13.116544 13274 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:19:13.117163 13260 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:13.117290 13260 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:19:13.117336 13260 hybrid_clock.cc:648] HybridClock initialized: now 1786515553117333 us; error 0 us; skew 500 ppm
I20260812 06:19:13.119128 13260 webserver.cc:533] Webserver started at http://127.12.243.62:45071/ using document root <none> and password file <none>
I20260812 06:19:13.119690 13260 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:13.119771 13260 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:13.120010 13260 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:13.121642 13260 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/master-0-root/instance:
uuid: "d932ab88080646d19c4d083e99174940"
format_stamp: "Formatted at 2026-08-12 06:19:13 on dist-test-slave-6bbx"
I20260812 06:19:13.125231 13260 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:19:13.127357 13281 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:19:13.128358 13260 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:13.128470 13260 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/master-0-root
uuid: "d932ab88080646d19c4d083e99174940"
format_stamp: "Formatted at 2026-08-12 06:19:13 on dist-test-slave-6bbx"
I20260812 06:19:13.128561 13260 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-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:19:13.144712 13260 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:13.145401 13260 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:19:13.145569 13260 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:13.152910 13364 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.243.62:43863 every 8 connection(s)
I20260812 06:19:13.152907 13260 rpc_server.cc:307] RPC server started. Bound to: 127.12.243.62:43863
I20260812 06:19:13.155159 13366 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:19:13.160331 13366 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940: Bootstrap starting.
I20260812 06:19:13.162511 13366 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:13.163331 13366 log.cc:826] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:13.164875 13366 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940: No bootstrap required, opened a new log
I20260812 06:19:13.167464 13366 raft_consensus.cc:359] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d932ab88080646d19c4d083e99174940" member_type: VOTER }
I20260812 06:19:13.167618 13366 raft_consensus.cc:385] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:13.167656 13366 raft_consensus.cc:740] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d932ab88080646d19c4d083e99174940, State: Initialized, Role: FOLLOWER
I20260812 06:19:13.168210 13366 consensus_queue.cc:260] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940 [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: "d932ab88080646d19c4d083e99174940" member_type: VOTER }
I20260812 06:19:13.168344 13366 raft_consensus.cc:399] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:13.168388 13366 raft_consensus.cc:493] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:13.168473 13366 raft_consensus.cc:3060] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:13.169171 13366 raft_consensus.cc:515] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d932ab88080646d19c4d083e99174940" member_type: VOTER }
I20260812 06:19:13.169538 13366 leader_election.cc:304] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940 [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: d932ab88080646d19c4d083e99174940; no voters: 
I20260812 06:19:13.169795 13366 leader_election.cc:290] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:13.169919 13372 raft_consensus.cc:2804] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:13.170132 13372 raft_consensus.cc:697] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940 [term 1 LEADER]: Becoming Leader. State: Replica: d932ab88080646d19c4d083e99174940, State: Running, Role: LEADER
I20260812 06:19:13.170492 13372 consensus_queue.cc:237] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940 [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: "d932ab88080646d19c4d083e99174940" member_type: VOTER }
I20260812 06:19:13.170691 13366 sys_catalog.cc:565] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:13.172309 13375 sys_catalog.cc:455] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940 [sys.catalog]: SysCatalogTable state changed. Reason: New leader d932ab88080646d19c4d083e99174940. Latest consensus state: current_term: 1 leader_uuid: "d932ab88080646d19c4d083e99174940" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d932ab88080646d19c4d083e99174940" member_type: VOTER } }
I20260812 06:19:13.172362 13374 sys_catalog.cc:455] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "d932ab88080646d19c4d083e99174940" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d932ab88080646d19c4d083e99174940" member_type: VOTER } }
I20260812 06:19:13.172446 13375 sys_catalog.cc:458] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:13.172451 13374 sys_catalog.cc:458] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:13.172888 13393 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:13.173048 13260 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:13.175031 13393 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:13.179261 13393 catalog_manager.cc:1383] Generated new cluster ID: e297fc7e95744f009ae10669f3c3aba9
I20260812 06:19:13.179314 13393 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:13.188455 13393 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:13.189280 13393 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:13.206288 13393 catalog_manager.cc:6092] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940: Generated new TSK 0
I20260812 06:19:13.206964 13393 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:13.237778 13260 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:13.240408 13406 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:19:13.240449 13407 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:19:13.240609 13409 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:19:13.240676 13260 server_base.cc:1061] running on GCE node
I20260812 06:19:13.240866 13260 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:13.240906 13260 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:19:13.240926 13260 hybrid_clock.cc:648] HybridClock initialized: now 1786515553240926 us; error 0 us; skew 500 ppm
I20260812 06:19:13.241778 13260 webserver.cc:533] Webserver started at http://127.12.243.1:34403/ using document root <none> and password file <none>
I20260812 06:19:13.241928 13260 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:13.241981 13260 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:13.242059 13260 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:13.242431 13260 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/instance:
uuid: "11edca70f3b1417b9956c43ce36ec163"
format_stamp: "Formatted at 2026-08-12 06:19:13 on dist-test-slave-6bbx"
I20260812 06:19:13.243877 13260 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:13.244791 13415 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:19:13.245009 13260 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:13.245074 13260 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root
uuid: "11edca70f3b1417b9956c43ce36ec163"
format_stamp: "Formatted at 2026-08-12 06:19:13 on dist-test-slave-6bbx"
I20260812 06:19:13.245141 13260 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-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:19:13.265785 13260 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:13.266197 13260 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:13.266647 13260 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:13.267486 13260 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:13.267539 13260 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:13.267585 13260 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:13.267616 13260 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:13.273516 13260 rpc_server.cc:307] RPC server started. Bound to: 127.12.243.1:44909
I20260812 06:19:13.273695 13520 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.243.1:44909 every 8 connection(s)
I20260812 06:19:13.287091 13522 heartbeater.cc:344] Connected to a master server at 127.12.243.62:43863
I20260812 06:19:13.287350 13522 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:13.287865 13522 heartbeater.cc:507] Master 127.12.243.62:43863 requested a full tablet report, sending...
I20260812 06:19:13.289436 13313 ts_manager.cc:194] Registered new tserver with Master: 11edca70f3b1417b9956c43ce36ec163 (127.12.243.1:44909)
I20260812 06:19:13.289650 13260 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015486704s
I20260812 06:19:13.291011 13313 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:43684
I20260812 06:19:13.298892 13313 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:43698:
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:19:13.312331 13459 tablet_service.cc:1511] Processing CreateTablet for tablet 32d6be943ae64adeae18b82dfb92f846 (DEFAULT_TABLE table=heavy-update-compaction-test [id=48bdf45317b04b018de2a252c143d088]), partition=
I20260812 06:19:13.312772 13459 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 32d6be943ae64adeae18b82dfb92f846. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:13.314808 13542 tablet_bootstrap.cc:492] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Bootstrap starting.
I20260812 06:19:13.315961 13542 tablet_bootstrap.cc:654] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:13.317058 13542 tablet_bootstrap.cc:492] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: No bootstrap required, opened a new log
I20260812 06:19:13.317162 13542 ts_tablet_manager.cc:1403] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:13.317627 13542 raft_consensus.cc:359] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "11edca70f3b1417b9956c43ce36ec163" member_type: VOTER last_known_addr { host: "127.12.243.1" port: 44909 } }
I20260812 06:19:13.317744 13542 raft_consensus.cc:385] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:13.317773 13542 raft_consensus.cc:740] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 11edca70f3b1417b9956c43ce36ec163, State: Initialized, Role: FOLLOWER
I20260812 06:19:13.317898 13542 consensus_queue.cc:260] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163 [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: "11edca70f3b1417b9956c43ce36ec163" member_type: VOTER last_known_addr { host: "127.12.243.1" port: 44909 } }
I20260812 06:19:13.317972 13542 raft_consensus.cc:399] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:13.318009 13542 raft_consensus.cc:493] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:13.318053 13542 raft_consensus.cc:3060] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:13.318938 13542 raft_consensus.cc:515] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "11edca70f3b1417b9956c43ce36ec163" member_type: VOTER last_known_addr { host: "127.12.243.1" port: 44909 } }
I20260812 06:19:13.319075 13542 leader_election.cc:304] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163 [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: 11edca70f3b1417b9956c43ce36ec163; no voters: 
I20260812 06:19:13.319273 13542 leader_election.cc:290] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:13.319453 13544 raft_consensus.cc:2804] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:13.319558 13542 ts_tablet_manager.cc:1434] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:13.319684 13544 raft_consensus.cc:697] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163 [term 1 LEADER]: Becoming Leader. State: Replica: 11edca70f3b1417b9956c43ce36ec163, State: Running, Role: LEADER
I20260812 06:19:13.319968 13522 heartbeater.cc:499] Master 127.12.243.62:43863 was elected leader, sending a full tablet report...
I20260812 06:19:13.319834 13544 consensus_queue.cc:237] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163 [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: "11edca70f3b1417b9956c43ce36ec163" member_type: VOTER last_known_addr { host: "127.12.243.1" port: 44909 } }
I20260812 06:19:13.322475 13313 catalog_manager.cc:5719] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163 reported cstate change: term changed from 0 to 1, leader changed from <none> to 11edca70f3b1417b9956c43ce36ec163 (127.12.243.1). New cstate: current_term: 1 leader_uuid: "11edca70f3b1417b9956c43ce36ec163" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "11edca70f3b1417b9956c43ce36ec163" member_type: VOTER last_known_addr { host: "127.12.243.1" port: 44909 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:13.378254 13260 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.018s	sys 0.005s
I20260812 06:19:13.524613 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushMRSOp(32d6be943ae64adeae18b82dfb92f846): perf score=19.054940
I20260812 06:19:13.684598 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushMRSOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.160s	user 0.138s	sys 0.020s Metrics: {"bytes_written":12717735,"cfile_init":1,"compiler_manager_pool.queue_time_us":234,"delete_count":0,"dirs.queue_time_us":40,"dirs.run_cpu_time_us":220,"dirs.run_wall_time_us":963,"drs_written":1,"lbm_read_time_us":91,"lbm_reads_lt_1ms":4,"lbm_write_time_us":35692,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":376576,"thread_start_us":135,"threads_started":1,"update_count":1550}
I20260812 06:19:13.685535 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling LogGCOp(32d6be943ae64adeae18b82dfb92f846): free 20743880 bytes of WAL
I20260812 06:19:13.685801 13423 log_reader.cc:385] T 32d6be943ae64adeae18b82dfb92f846: removed 2 log segments from log reader
I20260812 06:19:13.685858 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000001 (ops 1-6)
I20260812 06:19:13.685915 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000002 (ops 7-11)
I20260812 06:19:13.690230 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: LogGCOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:13.690788 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:13.706712 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.016s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5362,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:13.707166 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:13.846529 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.139s	user 0.111s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":799,"lbm_read_time_us":7828,"lbm_reads_lt_1ms":464,"lbm_write_time_us":20904,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":288,"threads_started":5,"update_count":2000}
I20260812 06:19:13.847010 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling UndoDeltaBlockGCOp(32d6be943ae64adeae18b82dfb92f846): 16411397 bytes on disk
I20260812 06:19:13.847458 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: UndoDeltaBlockGCOp(32d6be943ae64adeae18b82dfb92f846) 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:19:13.847920 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=10.126437
I20260812 06:19:13.889986 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.042s	user 0.030s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17456,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:13.890516 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:13.901050 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3626,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.901690 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:14.016665 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.115s	user 0.096s	sys 0.018s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":962,"lbm_read_time_us":9155,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20088,"lbm_writes_lt_1ms":443,"mutex_wait_us":278,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":2000}
I20260812 06:19:14.017138 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=10.126437
I20260812 06:19:14.053716 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.036s	user 0.014s	sys 0.017s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14097,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.054203 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:14.065739 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3838,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.066174 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:14.180143 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.114s	user 0.093s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1117,"lbm_read_time_us":7573,"lbm_reads_lt_1ms":468,"lbm_write_time_us":20833,"lbm_writes_lt_1ms":443,"mutex_wait_us":421,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:14.180610 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=10.126437
I20260812 06:19:14.216790 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.036s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":11630,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.217389 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:14.232085 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5479,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.232569 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:14.366118 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.133s	user 0.097s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":220,"lbm_read_time_us":10688,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20410,"lbm_writes_lt_1ms":443,"mutex_wait_us":18,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2000}
I20260812 06:19:14.366566 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=10.126437
I20260812 06:19:14.399554 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.033s	user 0.016s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13459,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.400058 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:14.409884 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3595,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.410405 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:14.527318 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.117s	user 0.084s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":902,"lbm_read_time_us":8088,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22311,"lbm_writes_lt_1ms":443,"mutex_wait_us":273,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":2000}
I20260812 06:19:14.527925 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=10.126437
I20260812 06:19:14.565014 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.037s	user 0.015s	sys 0.017s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13993,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.565516 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:14.575790 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3678,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.576365 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:14.690471 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.114s	user 0.078s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":249,"lbm_read_time_us":7778,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22234,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2000}
I20260812 06:19:14.690928 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=10.126437
I20260812 06:19:14.738523 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.047s	user 0.026s	sys 0.010s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13498,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.739125 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:14.749208 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3757,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.749714 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushMRSOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:14.779749 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushMRSOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":265,"dirs.run_wall_time_us":1427,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1306,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:14.780694 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:14.926555 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.146s	user 0.082s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":205,"lbm_read_time_us":7516,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24191,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:14.927139 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling LogGCOp(32d6be943ae64adeae18b82dfb92f846): free 115943176 bytes of WAL
I20260812 06:19:14.927369 13423 log_reader.cc:385] T 32d6be943ae64adeae18b82dfb92f846: removed 11 log segments from log reader
I20260812 06:19:14.927423 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000003 (ops 12-16)
I20260812 06:19:14.927469 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000004 (ops 17-21)
I20260812 06:19:14.927505 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000005 (ops 22-26)
I20260812 06:19:14.927533 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000006 (ops 27-31)
I20260812 06:19:14.927560 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000007 (ops 32-36)
I20260812 06:19:14.927585 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000008 (ops 37-41)
I20260812 06:19:14.927611 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000009 (ops 42-46)
I20260812 06:19:14.927642 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000010 (ops 47-51)
I20260812 06:19:14.927697 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000011 (ops 52-56)
I20260812 06:19:14.927728 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000012 (ops 57-61)
I20260812 06:19:14.927753 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000013 (ops 62-66)
I20260812 06:19:14.952461 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: LogGCOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.025s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:19:14.952857 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=15.087375
I20260812 06:19:15.000232 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.047s	user 0.037s	sys 0.010s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":20318,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:15.000692 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling UndoDeltaBlockGCOp(32d6be943ae64adeae18b82dfb92f846): 447 bytes on disk
I20260812 06:19:15.001142 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: UndoDeltaBlockGCOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:19:15.001796 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:15.026588 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.025s	user 0.004s	sys 0.014s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5280,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:15.027122 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:15.037132 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3713,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.037619 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:15.230114 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.192s	user 0.101s	sys 0.082s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877206,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":468,"lbm_read_time_us":12860,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31701,"lbm_writes_lt_1ms":643,"mutex_wait_us":262,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":3000}
I20260812 06:19:15.230563 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=14.095187
I20260812 06:19:15.286695 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.056s	user 0.022s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18710,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.287348 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:15.302527 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5618,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.303059 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:15.460837 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.158s	user 0.098s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":195,"lbm_read_time_us":11352,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26578,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:15.461690 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=10.126437
I20260812 06:19:15.492508 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.031s	user 0.022s	sys 0.007s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14089,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:15.493037 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:15.510702 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.017s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7304,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.511215 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:15.639045 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.128s	user 0.100s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1280,"lbm_read_time_us":6961,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24020,"lbm_writes_lt_1ms":443,"mutex_wait_us":261,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.639619 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=11.118625
I20260812 06:19:15.668138 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.028s	user 0.024s	sys 0.004s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":11906,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:15.668582 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:15.682363 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5594,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:15.682834 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:15.812201 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.129s	user 0.101s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672267,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":578,"lbm_read_time_us":7620,"lbm_reads_lt_1ms":468,"lbm_write_time_us":25073,"lbm_writes_lt_1ms":443,"mutex_wait_us":275,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2000}
I20260812 06:19:15.812791 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=10.126437
I20260812 06:19:15.854288 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.041s	user 0.018s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18131,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:15.854797 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:15.866518 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4211,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.867074 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:15.984719 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.117s	user 0.096s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":656,"lbm_read_time_us":7132,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21788,"lbm_writes_lt_1ms":443,"mutex_wait_us":352,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:19:15.985332 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=11.118625
I20260812 06:19:16.023984 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.038s	user 0.019s	sys 0.019s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14637,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:16.024588 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:16.036185 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3815,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:16.036623 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:16.187752 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.151s	user 0.096s	sys 0.054s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1078,"lbm_read_time_us":10327,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25425,"lbm_writes_lt_1ms":443,"mutex_wait_us":272,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2000}
I20260812 06:19:16.188376 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=10.126437
I20260812 06:19:16.221424 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.033s	user 0.013s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13519,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:16.221921 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:16.235098 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5140,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.235759 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushMRSOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:16.263782 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushMRSOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.028s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":1452,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1449,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:16.264518 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling LogGCOp(32d6be943ae64adeae18b82dfb92f846): free 121459489 bytes of WAL
I20260812 06:19:16.264743 13423 log_reader.cc:385] T 32d6be943ae64adeae18b82dfb92f846: removed 12 log segments from log reader
I20260812 06:19:16.264803 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000014 (ops 67-71)
I20260812 06:19:16.264850 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000015 (ops 72-76)
I20260812 06:19:16.264890 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000016 (ops 77-81)
I20260812 06:19:16.264918 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000017 (ops 82-86)
I20260812 06:19:16.264948 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000018 (ops 87-91)
I20260812 06:19:16.264979 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000019 (ops 92-96)
I20260812 06:19:16.265010 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000020 (ops 97-101)
I20260812 06:19:16.265038 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000021 (ops 102-106)
I20260812 06:19:16.265065 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000022 (ops 107-111)
I20260812 06:19:16.265093 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000023 (ops 112-116)
I20260812 06:19:16.265125 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000024 (ops 117-121)
I20260812 06:19:16.265154 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000025 (ops 122-126)
I20260812 06:19:16.290654 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: LogGCOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:16.291374 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:16.310920 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.019s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6200,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.311458 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling LogGCOp(32d6be943ae64adeae18b82dfb92f846): free 11564883 bytes of WAL
I20260812 06:19:16.311717 13423 log_reader.cc:385] T 32d6be943ae64adeae18b82dfb92f846: removed 1 log segments from log reader
I20260812 06:19:16.311774 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000026 (ops 127-130)
I20260812 06:19:16.314265 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: LogGCOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:16.314625 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling UndoDeltaBlockGCOp(32d6be943ae64adeae18b82dfb92f846): 482 bytes on disk
I20260812 06:19:16.315116 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: UndoDeltaBlockGCOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:19:16.315632 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:16.336061 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.020s	user 0.007s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5979,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.336506 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:16.519619 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.183s	user 0.118s	sys 0.065s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877338,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":941,"lbm_read_time_us":13206,"lbm_reads_lt_1ms":666,"lbm_write_time_us":28309,"lbm_writes_lt_1ms":643,"mutex_wait_us":25,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8832,"thread_start_us":74,"threads_started":1,"update_count":3000}
I20260812 06:19:16.520215 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=14.095187
I20260812 06:19:16.568197 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.048s	user 0.034s	sys 0.011s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":16000,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.568748 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:16.578881 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3867,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.579311 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:16.737790 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.158s	user 0.138s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1055,"lbm_read_time_us":12120,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26290,"lbm_writes_lt_1ms":543,"mutex_wait_us":383,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":23936,"update_count":2500}
I20260812 06:19:16.738504 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=10.126437
I20260812 06:19:16.774780 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.036s	user 0.020s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12921,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:16.775318 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:16.786523 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3573,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.787089 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:16.899741 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.112s	user 0.095s	sys 0.018s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":786,"lbm_read_time_us":7734,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20543,"lbm_writes_lt_1ms":443,"mutex_wait_us":282,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2000}
I20260812 06:19:16.900199 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=10.126437
I20260812 06:19:16.944233 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.044s	user 0.023s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15785,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:16.944742 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:16.954852 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3600,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.955519 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:17.083104 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.127s	user 0.098s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":142,"lbm_read_time_us":8700,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23235,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:17.083576 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=10.126437
I20260812 06:19:17.117178 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.033s	user 0.013s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12541,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:17.117736 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:17.220443 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.102s	user 0.082s	sys 0.020s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":605,"lbm_read_time_us":7077,"lbm_reads_lt_1ms":363,"lbm_write_time_us":17508,"lbm_writes_lt_1ms":343,"mutex_wait_us":319,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":1500}
I20260812 06:19:17.221035 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=10.126437
I20260812 06:19:17.255479 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.034s	user 0.024s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12891,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:17.255996 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:17.271142 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5387,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.271941 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:17.399930 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.128s	user 0.122s	sys 0.005s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":259,"lbm_read_time_us":9481,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23318,"lbm_writes_lt_1ms":443,"mutex_wait_us":76,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2000}
I20260812 06:19:17.400481 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=10.126437
I20260812 06:19:17.445314 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.045s	user 0.027s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16041,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:17.446040 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:17.460927 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.015s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5504,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.462055 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:17.573589 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.111s	user 0.085s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":194,"lbm_read_time_us":7528,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20230,"lbm_writes_lt_1ms":443,"mutex_wait_us":60,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:17.574327 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=10.126437
I20260812 06:19:17.610143 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.036s	user 0.019s	sys 0.009s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13306,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:17.610693 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:17.620512 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3687,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.621044 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushMRSOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:17.649977 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushMRSOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.029s	user 0.021s	sys 0.005s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":178,"dirs.run_wall_time_us":1409,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1968,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:17.650708 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling LogGCOp(32d6be943ae64adeae18b82dfb92f846): free 121006692 bytes of WAL
I20260812 06:19:17.650951 13423 log_reader.cc:385] T 32d6be943ae64adeae18b82dfb92f846: removed 12 log segments from log reader
I20260812 06:19:17.651000 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000027 (ops 131-135)
I20260812 06:19:17.651028 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000028 (ops 136-140)
I20260812 06:19:17.651059 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000029 (ops 141-145)
I20260812 06:19:17.651091 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000030 (ops 146-150)
I20260812 06:19:17.651124 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000031 (ops 151-155)
I20260812 06:19:17.651155 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000032 (ops 156-160)
I20260812 06:19:17.651196 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000033 (ops 161-165)
I20260812 06:19:17.651228 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000034 (ops 166-170)
I20260812 06:19:17.651259 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000035 (ops 171-174)
I20260812 06:19:17.651290 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000036 (ops 175-179)
I20260812 06:19:17.651321 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000037 (ops 180-184)
I20260812 06:19:17.651352 13423 log.cc:1079] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/32d6be943ae64adeae18b82dfb92f846/wal-000000038 (ops 185-189)
I20260812 06:19:17.672804 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: LogGCOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.022s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:19:17.673166 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling UndoDeltaBlockGCOp(32d6be943ae64adeae18b82dfb92f846): 473 bytes on disk
I20260812 06:19:17.673574 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: UndoDeltaBlockGCOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:19:17.674093 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=3.181125
I20260812 06:19:17.686184 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4575,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:17.686626 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:17.695881 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.009s	user 0.001s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3342,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:17.696295 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:17.862107 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.166s	user 0.128s	sys 0.032s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2046,"lbm_read_time_us":9887,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34188,"lbm_writes_lt_1ms":643,"mutex_wait_us":1390,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2176,"thread_start_us":97,"threads_started":1,"update_count":3000}
I20260812 06:19:17.862653 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=14.095187
I20260812 06:19:17.907835 13260 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.529s	user 1.706s	sys 0.099s
I20260812 06:19:17.913105 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.050s	user 0.013s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24612,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:17.913614 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846): perf score=2.188937
I20260812 06:19:17.922952 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: FlushDeltaMemStoresOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3740,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":500}
I20260812 06:19:17.923448 13523 maintenance_manager.cc:419] P 11edca70f3b1417b9956c43ce36ec163: Scheduling MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846): perf score=1.000000
I20260812 06:19:17.951125 13260 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.043s	user 0.001s	sys 0.000s
I20260812 06:19:17.951790 13260 tablet_server.cc:179] TabletServer@127.12.243.1:0 shutting down...
I20260812 06:19:18.026387 13423 maintenance_manager.cc:643] P 11edca70f3b1417b9956c43ce36ec163: MajorDeltaCompactionOp(32d6be943ae64adeae18b82dfb92f846) complete. Timing: real 0.103s	user 0.091s	sys 0.012s Metrics: {"cfile_cache_hit":401,"cfile_cache_hit_bytes":16409767,"cfile_cache_miss":131,"cfile_cache_miss_bytes":8364921,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":368,"lbm_read_time_us":3037,"lbm_reads_lt_1ms":163,"lbm_write_time_us":21978,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:19:18.027100 13260 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:18.027477 13260 tablet_replica.cc:333] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163: stopping tablet replica
I20260812 06:19:18.027750 13260 raft_consensus.cc:2243] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:18.027971 13260 raft_consensus.cc:2272] T 32d6be943ae64adeae18b82dfb92f846 P 11edca70f3b1417b9956c43ce36ec163 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:18.043167 13260 tablet_server.cc:196] TabletServer@127.12.243.1:0 shutdown complete.
I20260812 06:19:18.072068 13260 master.cc:562] Master@127.12.243.62:43863 shutting down...
I20260812 06:19:18.075804 13260 raft_consensus.cc:2243] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:18.075973 13260 raft_consensus.cc:2272] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:18.076045 13260 tablet_replica.cc:333] T 00000000000000000000000000000000 P d932ab88080646d19c4d083e99174940: stopping tablet replica
I20260812 06:19:18.088207 13260 master.cc:584] Master@127.12.243.62:43863 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5053 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:18.169320 13260 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.12.243.62:40341
I20260812 06:19:18.169728 13260 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:18.171555 13571 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:19:18.171701 13260 server_base.cc:1061] running on GCE node
W20260812 06:19:18.171712 13570 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:19:18.171629 13573 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:19:18.171983 13260 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:18.172025 13260 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:19:18.172040 13260 hybrid_clock.cc:648] HybridClock initialized: now 1786515558172040 us; error 0 us; skew 500 ppm
I20260812 06:19:18.172808 13260 webserver.cc:533] Webserver started at http://127.12.243.62:41175/ using document root <none> and password file <none>
I20260812 06:19:18.172931 13260 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:18.172968 13260 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:18.173022 13260 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:18.173367 13260 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/master-0-root/instance:
uuid: "4f87416f15ca47e9bcf687ee9e70dfd1"
format_stamp: "Formatted at 2026-08-12 06:19:18 on dist-test-slave-6bbx"
I20260812 06:19:18.174718 13260 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:18.175554 13582 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:19:18.175815 13260 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:18.175882 13260 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/master-0-root
uuid: "4f87416f15ca47e9bcf687ee9e70dfd1"
format_stamp: "Formatted at 2026-08-12 06:19:18 on dist-test-slave-6bbx"
I20260812 06:19:18.175933 13260 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-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:19:18.182559 13260 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:18.182864 13260 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:18.186676 13260 rpc_server.cc:307] RPC server started. Bound to: 127.12.243.62:40341
I20260812 06:19:18.192505 13666 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.243.62:40341 every 8 connection(s)
I20260812 06:19:18.192960 13667 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:19:18.194674 13667 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1: Bootstrap starting.
I20260812 06:19:18.195431 13667 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:18.196400 13667 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1: No bootstrap required, opened a new log
I20260812 06:19:18.196769 13667 raft_consensus.cc:359] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4f87416f15ca47e9bcf687ee9e70dfd1" member_type: VOTER }
I20260812 06:19:18.196851 13667 raft_consensus.cc:385] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:18.196884 13667 raft_consensus.cc:740] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4f87416f15ca47e9bcf687ee9e70dfd1, State: Initialized, Role: FOLLOWER
I20260812 06:19:18.197016 13667 consensus_queue.cc:260] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1 [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: "4f87416f15ca47e9bcf687ee9e70dfd1" member_type: VOTER }
I20260812 06:19:18.197084 13667 raft_consensus.cc:399] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:18.197121 13667 raft_consensus.cc:493] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:18.197170 13667 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:18.197808 13667 raft_consensus.cc:515] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4f87416f15ca47e9bcf687ee9e70dfd1" member_type: VOTER }
I20260812 06:19:18.197926 13667 leader_election.cc:304] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1 [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: 4f87416f15ca47e9bcf687ee9e70dfd1; no voters: 
I20260812 06:19:18.198100 13667 leader_election.cc:290] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:18.198172 13670 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:18.198371 13670 raft_consensus.cc:697] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1 [term 1 LEADER]: Becoming Leader. State: Replica: 4f87416f15ca47e9bcf687ee9e70dfd1, State: Running, Role: LEADER
I20260812 06:19:18.198515 13667 sys_catalog.cc:565] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:18.198513 13670 consensus_queue.cc:237] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1 [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: "4f87416f15ca47e9bcf687ee9e70dfd1" member_type: VOTER }
I20260812 06:19:18.198982 13672 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 4f87416f15ca47e9bcf687ee9e70dfd1. Latest consensus state: current_term: 1 leader_uuid: "4f87416f15ca47e9bcf687ee9e70dfd1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4f87416f15ca47e9bcf687ee9e70dfd1" member_type: VOTER } }
I20260812 06:19:18.199072 13672 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:18.198968 13671 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "4f87416f15ca47e9bcf687ee9e70dfd1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4f87416f15ca47e9bcf687ee9e70dfd1" member_type: VOTER } }
I20260812 06:19:18.199214 13671 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:18.199756 13676 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:18.200397 13676 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:18.200598 13260 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:18.202150 13676 catalog_manager.cc:1383] Generated new cluster ID: 34c40360e5fd443abd073c8aba236802
I20260812 06:19:18.202205 13676 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:18.209297 13676 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:18.209828 13676 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:18.221082 13676 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1: Generated new TSK 0
I20260812 06:19:18.221249 13676 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:18.232950 13260 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:19:18.234906 13260 server_base.cc:1061] running on GCE node
W20260812 06:19:18.234907 13699 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:19:18.235035 13697 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:19:18.235024 13701 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:19:18.235327 13260 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:18.235371 13260 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:19:18.235385 13260 hybrid_clock.cc:648] HybridClock initialized: now 1786515558235386 us; error 0 us; skew 500 ppm
I20260812 06:19:18.236241 13260 webserver.cc:533] Webserver started at http://127.12.243.1:42919/ using document root <none> and password file <none>
I20260812 06:19:18.236377 13260 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:18.236418 13260 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:18.236474 13260 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:18.236812 13260 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/instance:
uuid: "3a1dcdf6ab7f44de900dea638cc4183d"
format_stamp: "Formatted at 2026-08-12 06:19:18 on dist-test-slave-6bbx"
I20260812 06:19:18.238224 13260 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:18.239144 13706 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:19:18.239354 13260 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:18.239418 13260 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root
uuid: "3a1dcdf6ab7f44de900dea638cc4183d"
format_stamp: "Formatted at 2026-08-12 06:19:18 on dist-test-slave-6bbx"
I20260812 06:19:18.239485 13260 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-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:19:18.257695 13260 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:18.258100 13260 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:18.258412 13260 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:18.258898 13260 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:18.258937 13260 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:18.258981 13260 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:18.259011 13260 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:18.263037 13260 rpc_server.cc:307] RPC server started. Bound to: 127.12.243.1:42171
I20260812 06:19:18.263608 13810 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.243.1:42171 every 8 connection(s)
I20260812 06:19:18.268093 13813 heartbeater.cc:344] Connected to a master server at 127.12.243.62:40341
I20260812 06:19:18.268189 13813 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:18.268429 13813 heartbeater.cc:507] Master 127.12.243.62:40341 requested a full tablet report, sending...
I20260812 06:19:18.269027 13611 ts_manager.cc:194] Registered new tserver with Master: 3a1dcdf6ab7f44de900dea638cc4183d (127.12.243.1:42171)
I20260812 06:19:18.269243 13260 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.005562957s
I20260812 06:19:18.269796 13611 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:47048
I20260812 06:19:18.276476 13611 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:47058:
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:19:18.284786 13755 tablet_service.cc:1511] Processing CreateTablet for tablet 2fdca61c9e084759b7fafdda0c1d8b5f (DEFAULT_TABLE table=heavy-update-compaction-test [id=7a5a49cc7a1e4034bf2e3999bcd46efb]), partition=
I20260812 06:19:18.285063 13755 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 2fdca61c9e084759b7fafdda0c1d8b5f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:18.286914 13835 tablet_bootstrap.cc:492] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Bootstrap starting.
I20260812 06:19:18.287776 13835 tablet_bootstrap.cc:654] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:18.288810 13835 tablet_bootstrap.cc:492] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: No bootstrap required, opened a new log
I20260812 06:19:18.288892 13835 ts_tablet_manager.cc:1403] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:19:18.289311 13835 raft_consensus.cc:359] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3a1dcdf6ab7f44de900dea638cc4183d" member_type: VOTER last_known_addr { host: "127.12.243.1" port: 42171 } }
I20260812 06:19:18.289402 13835 raft_consensus.cc:385] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:18.289431 13835 raft_consensus.cc:740] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3a1dcdf6ab7f44de900dea638cc4183d, State: Initialized, Role: FOLLOWER
I20260812 06:19:18.289568 13835 consensus_queue.cc:260] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d [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: "3a1dcdf6ab7f44de900dea638cc4183d" member_type: VOTER last_known_addr { host: "127.12.243.1" port: 42171 } }
I20260812 06:19:18.289646 13835 raft_consensus.cc:399] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:18.289685 13835 raft_consensus.cc:493] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:18.289732 13835 raft_consensus.cc:3060] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:18.290439 13835 raft_consensus.cc:515] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3a1dcdf6ab7f44de900dea638cc4183d" member_type: VOTER last_known_addr { host: "127.12.243.1" port: 42171 } }
I20260812 06:19:18.290566 13835 leader_election.cc:304] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d [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: 3a1dcdf6ab7f44de900dea638cc4183d; no voters: 
I20260812 06:19:18.290762 13835 leader_election.cc:290] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:18.290866 13838 raft_consensus.cc:2804] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:18.291054 13813 heartbeater.cc:499] Master 127.12.243.62:40341 was elected leader, sending a full tablet report...
I20260812 06:19:18.291077 13838 raft_consensus.cc:697] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d [term 1 LEADER]: Becoming Leader. State: Replica: 3a1dcdf6ab7f44de900dea638cc4183d, State: Running, Role: LEADER
I20260812 06:19:18.291244 13835 ts_tablet_manager.cc:1434] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:18.291234 13838 consensus_queue.cc:237] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d [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: "3a1dcdf6ab7f44de900dea638cc4183d" member_type: VOTER last_known_addr { host: "127.12.243.1" port: 42171 } }
I20260812 06:19:18.292522 13611 catalog_manager.cc:5719] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d reported cstate change: term changed from 0 to 1, leader changed from <none> to 3a1dcdf6ab7f44de900dea638cc4183d (127.12.243.1). New cstate: current_term: 1 leader_uuid: "3a1dcdf6ab7f44de900dea638cc4183d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3a1dcdf6ab7f44de900dea638cc4183d" member_type: VOTER last_known_addr { host: "127.12.243.1" port: 42171 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:18.345506 13260 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.013s	sys 0.008s
I20260812 06:19:18.514165 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushMRSOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=23.023690
I20260812 06:19:18.675397 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushMRSOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.161s	user 0.109s	sys 0.048s Metrics: {"bytes_written":12881835,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":140,"dirs.run_cpu_time_us":204,"dirs.run_wall_time_us":740,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39234,"lbm_writes_lt_1ms":871,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":2944,"update_count":1570}
I20260812 06:19:18.676004 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling LogGCOp(2fdca61c9e084759b7fafdda0c1d8b5f): free 20743880 bytes of WAL
I20260812 06:19:18.676195 13717 log_reader.cc:385] T 2fdca61c9e084759b7fafdda0c1d8b5f: removed 2 log segments from log reader
I20260812 06:19:18.676239 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000001 (ops 1-6)
I20260812 06:19:18.676285 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000002 (ops 7-11)
I20260812 06:19:18.681557 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: LogGCOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:18.681929 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling UndoDeltaBlockGCOp(2fdca61c9e084759b7fafdda0c1d8b5f): 20513813 bytes on disk
I20260812 06:19:18.682438 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: UndoDeltaBlockGCOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:19:18.682862 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:18.702808 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.020s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3938559,"delete_count":0,"lbm_write_time_us":3731,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:19:18.703214 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:18.712215 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3165,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:18.712607 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=1.000000
I20260812 06:19:18.884436 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.172s	user 0.120s	sys 0.043s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":955,"lbm_read_time_us":11469,"lbm_reads_lt_1ms":569,"lbm_write_time_us":28164,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6784,"thread_start_us":358,"threads_started":5,"update_count":2500}
I20260812 06:19:18.884964 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=14.095187
I20260812 06:19:18.935099 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.050s	user 0.034s	sys 0.008s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19612,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:18.935511 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:18.945586 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3580,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.946300 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=1.000000
I20260812 06:19:19.103075 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.157s	user 0.120s	sys 0.036s 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":849,"lbm_read_time_us":11969,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26279,"lbm_writes_lt_1ms":543,"mutex_wait_us":314,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2500}
I20260812 06:19:19.103696 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=11.118625
I20260812 06:19:19.145429 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.042s	user 0.025s	sys 0.015s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16840,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:19.145987 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:19.170081 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.024s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4354,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:19.170542 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:19.179785 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3487,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.180141 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=1.000000
I20260812 06:19:19.352880 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.173s	user 0.114s	sys 0.050s 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":234,"lbm_read_time_us":11992,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27440,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2500}
I20260812 06:19:19.353444 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=14.095187
I20260812 06:19:19.406700 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.053s	user 0.040s	sys 0.001s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19422,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.407215 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:19.417553 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3752,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.418206 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=1.000000
I20260812 06:19:19.584367 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.166s	user 0.090s	sys 0.076s 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":847,"lbm_read_time_us":12428,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27772,"lbm_writes_lt_1ms":543,"mutex_wait_us":241,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:19:19.584889 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=14.095187
I20260812 06:19:19.634284 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.049s	user 0.011s	sys 0.035s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":17163,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.634853 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:19.645259 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3913,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.645807 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=1.000000
I20260812 06:19:19.817854 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.172s	user 0.111s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815680,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":287,"dirs.run_cpu_time_us":482,"dirs.run_wall_time_us":2688,"lbm_read_time_us":12787,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26539,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2500}
I20260812 06:19:19.818423 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=11.118625
I20260812 06:19:19.854507 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.036s	user 0.024s	sys 0.009s Metrics: {"bytes_written":12799772,"delete_count":0,"lbm_write_time_us":15117,"lbm_writes_lt_1ms":315,"reinsert_count":0,"update_count":1560}
I20260812 06:19:19.855104 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:19.885529 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.030s	user 0.009s	sys 0.005s Metrics: {"bytes_written":3610355,"delete_count":0,"lbm_write_time_us":5057,"lbm_writes_lt_1ms":91,"reinsert_count":0,"update_count":440}
I20260812 06:19:19.886081 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:19.896203 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3817,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.896642 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushMRSOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=1.000000
I20260812 06:19:19.930902 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushMRSOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.034s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":175,"dirs.run_wall_time_us":1258,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2107,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:19.931545 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling LogGCOp(2fdca61c9e084759b7fafdda0c1d8b5f): free 124710244 bytes of WAL
I20260812 06:19:19.931788 13717 log_reader.cc:385] T 2fdca61c9e084759b7fafdda0c1d8b5f: removed 12 log segments from log reader
I20260812 06:19:19.931843 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000003 (ops 12-16)
I20260812 06:19:19.931874 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000004 (ops 17-21)
I20260812 06:19:19.931903 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000005 (ops 22-26)
I20260812 06:19:19.931936 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000006 (ops 27-31)
I20260812 06:19:19.931970 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000007 (ops 32-36)
I20260812 06:19:19.932003 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000008 (ops 37-41)
I20260812 06:19:19.932034 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000009 (ops 42-46)
I20260812 06:19:19.932063 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000010 (ops 47-51)
I20260812 06:19:19.932093 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000011 (ops 52-56)
I20260812 06:19:19.932125 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000012 (ops 57-61)
I20260812 06:19:19.932157 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000013 (ops 62-66)
I20260812 06:19:19.932188 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000014 (ops 67-71)
I20260812 06:19:19.953142 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: LogGCOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.021s	user 0.005s	sys 0.015s Metrics: {}
I20260812 06:19:19.953560 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling UndoDeltaBlockGCOp(2fdca61c9e084759b7fafdda0c1d8b5f): 472 bytes on disk
I20260812 06:19:19.953941 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: UndoDeltaBlockGCOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:19:19.954393 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:19.976377 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.022s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5105,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.977003 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:19.990983 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5251,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.991617 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=1.000000
I20260812 06:19:20.226504 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.235s	user 0.162s	sys 0.057s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020842,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1014,"lbm_read_time_us":14268,"lbm_reads_lt_1ms":775,"lbm_write_time_us":39599,"lbm_writes_lt_1ms":743,"mutex_wait_us":324,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:19:20.228209 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=18.063937
I20260812 06:19:20.280462 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.052s	user 0.027s	sys 0.024s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":22368,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:20.280962 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:20.291867 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3811,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.292773 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=1.000000
I20260812 06:19:20.468541 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.176s	user 0.136s	sys 0.039s 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":221,"lbm_read_time_us":12769,"lbm_reads_lt_1ms":672,"lbm_write_time_us":29396,"lbm_writes_lt_1ms":643,"mutex_wait_us":29,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:20.469063 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=14.095187
I20260812 06:19:20.512768 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.043s	user 0.031s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18496,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.513342 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:20.527567 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5657,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.528079 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=1.000000
I20260812 06:19:20.680215 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.152s	user 0.104s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2038,"lbm_read_time_us":8887,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26871,"lbm_writes_lt_1ms":543,"mutex_wait_us":586,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14976,"update_count":2500}
I20260812 06:19:20.680917 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=14.095187
I20260812 06:19:20.742686 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.062s	user 0.020s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20538,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.743208 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:20.753710 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3575,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.754374 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=1.000000
I20260812 06:19:20.911836 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.157s	user 0.106s	sys 0.049s 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":1226,"lbm_read_time_us":10716,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24146,"lbm_writes_lt_1ms":543,"mutex_wait_us":436,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:19:20.912330 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=14.095187
I20260812 06:19:20.963536 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.051s	user 0.026s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17752,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.964133 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:20.975577 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4066,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.976083 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=1.000000
I20260812 06:19:21.166329 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.190s	user 0.120s	sys 0.068s 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":1625,"lbm_read_time_us":13005,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33517,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":547,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18816,"update_count":2500}
I20260812 06:19:21.166910 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=14.095187
I20260812 06:19:21.230234 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.063s	user 0.032s	sys 0.027s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":28111,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.230826 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:21.246623 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.016s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5341,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.247318 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:21.262018 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5411,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.262555 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushMRSOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=1.000000
I20260812 06:19:21.298857 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushMRSOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.036s	user 0.033s	sys 0.001s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":1331,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2066,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:21.299752 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling LogGCOp(2fdca61c9e084759b7fafdda0c1d8b5f): free 120553390 bytes of WAL
I20260812 06:19:21.300033 13717 log_reader.cc:385] T 2fdca61c9e084759b7fafdda0c1d8b5f: removed 12 log segments from log reader
I20260812 06:19:21.300122 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000015 (ops 72-76)
I20260812 06:19:21.300211 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000016 (ops 77-81)
I20260812 06:19:21.300247 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000017 (ops 82-86)
I20260812 06:19:21.300271 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000018 (ops 87-91)
I20260812 06:19:21.300318 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000019 (ops 92-96)
I20260812 06:19:21.300349 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000020 (ops 97-100)
I20260812 06:19:21.300397 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000021 (ops 101-105)
I20260812 06:19:21.300432 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000022 (ops 106-110)
I20260812 06:19:21.300479 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000023 (ops 111-115)
I20260812 06:19:21.300518 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000024 (ops 116-120)
I20260812 06:19:21.300573 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000025 (ops 121-124)
I20260812 06:19:21.300608 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000026 (ops 125-129)
I20260812 06:19:21.322631 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: LogGCOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.023s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:19:21.323073 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling UndoDeltaBlockGCOp(2fdca61c9e084759b7fafdda0c1d8b5f): 462 bytes on disk
I20260812 06:19:21.324673 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: UndoDeltaBlockGCOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:19:21.325320 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=3.181125
I20260812 06:19:21.354507 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.029s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4311,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:21.355043 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:21.364794 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3366,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:21.365240 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=1.000000
I20260812 06:19:21.586594 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.221s	user 0.157s	sys 0.063s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37123262,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":258,"lbm_read_time_us":16082,"lbm_reads_lt_1ms":875,"lbm_write_time_us":37380,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":72,"threads_started":1,"update_count":4000}
I20260812 06:19:21.587157 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=14.095187
I20260812 06:19:21.626967 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.040s	user 0.012s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17484,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.627521 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:21.653820 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.026s	user 0.011s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5180,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.654322 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=1.196750
I20260812 06:19:21.662850 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.008s	user 0.002s	sys 0.004s Metrics: {"bytes_written":3036009,"delete_count":0,"lbm_write_time_us":3136,"lbm_writes_lt_1ms":77,"reinsert_count":0,"update_count":370}
I20260812 06:19:21.663281 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=1.000000
I20260812 06:19:21.830869 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.167s	user 0.140s	sys 0.027s Metrics: {"cfile_cache_miss":607,"cfile_cache_miss_bytes":27851564,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":195,"lbm_read_time_us":11124,"lbm_reads_lt_1ms":643,"lbm_write_time_us":33990,"lbm_writes_lt_1ms":617,"mutex_wait_us":72,"peak_mem_usage":72394794,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2870}
I20260812 06:19:21.831475 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=12.110812
I20260812 06:19:21.870172 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.039s	user 0.020s	sys 0.016s Metrics: {"bytes_written":13784366,"delete_count":0,"lbm_write_time_us":16636,"lbm_writes_lt_1ms":339,"reinsert_count":0,"update_count":1680}
I20260812 06:19:21.870828 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:21.886188 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5586,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:21.886831 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=1.000000
I20260812 06:19:22.016774 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.130s	user 0.094s	sys 0.035s Metrics: {"cfile_cache_miss":458,"cfile_cache_miss_bytes":21779894,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":545,"lbm_read_time_us":9633,"lbm_reads_lt_1ms":494,"lbm_write_time_us":23561,"lbm_writes_lt_1ms":469,"mutex_wait_us":345,"peak_mem_usage":53837006,"reinsert_count":0,"update_count":2130}
I20260812 06:19:22.017371 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=10.126437
I20260812 06:19:22.048123 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.031s	user 0.023s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13380,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:22.048617 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:22.062021 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.013s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4787,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.062515 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=1.000000
I20260812 06:19:22.208098 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.145s	user 0.113s	sys 0.031s 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":123,"lbm_read_time_us":11681,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22615,"lbm_writes_lt_1ms":443,"mutex_wait_us":58,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2000}
I20260812 06:19:22.208722 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=10.126437
I20260812 06:19:22.240142 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.031s	user 0.019s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12875,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:22.240756 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:22.255918 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5174,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.256448 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=1.000000
I20260812 06:19:22.378648 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.122s	user 0.086s	sys 0.036s 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":598,"lbm_read_time_us":9430,"lbm_reads_lt_1ms":468,"lbm_write_time_us":22871,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":35584,"update_count":2000}
I20260812 06:19:22.379132 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=10.126437
I20260812 06:19:22.419071 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.040s	user 0.015s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14644,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:22.419569 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:22.429324 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3564,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.429867 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=1.000000
I20260812 06:19:22.556722 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.127s	user 0.102s	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":1014,"lbm_read_time_us":9887,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22400,"lbm_writes_lt_1ms":443,"mutex_wait_us":344,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2000}
I20260812 06:19:22.557221 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=10.126437
I20260812 06:19:22.598661 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.041s	user 0.018s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12354,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:22.599272 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:22.614504 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5391,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.615042 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushMRSOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=1.000000
I20260812 06:19:22.646708 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushMRSOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":1217,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1594,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:22.647372 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling LogGCOp(2fdca61c9e084759b7fafdda0c1d8b5f): free 120553645 bytes of WAL
I20260812 06:19:22.647594 13717 log_reader.cc:385] T 2fdca61c9e084759b7fafdda0c1d8b5f: removed 12 log segments from log reader
I20260812 06:19:22.647641 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000027 (ops 130-134)
I20260812 06:19:22.647703 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000028 (ops 135-139)
I20260812 06:19:22.647739 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000029 (ops 140-144)
I20260812 06:19:22.647759 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000030 (ops 145-149)
I20260812 06:19:22.647790 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000031 (ops 150-154)
I20260812 06:19:22.647822 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000032 (ops 155-158)
I20260812 06:19:22.647853 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000033 (ops 159-163)
I20260812 06:19:22.647886 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000034 (ops 164-168)
I20260812 06:19:22.647919 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000035 (ops 169-173)
I20260812 06:19:22.647951 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000036 (ops 174-178)
I20260812 06:19:22.647984 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000037 (ops 179-182)
I20260812 06:19:22.648015 13717 log.cc:1079] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: Deleting log segment in path: /tmp/dist-test-tasksGIARw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553097156-13260-0/minicluster-data/ts-0-root/wals/2fdca61c9e084759b7fafdda0c1d8b5f/wal-000000038 (ops 183-187)
I20260812 06:19:22.668334 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: LogGCOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.021s	user 0.002s	sys 0.019s Metrics: {}
I20260812 06:19:22.668792 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling UndoDeltaBlockGCOp(2fdca61c9e084759b7fafdda0c1d8b5f): 447 bytes on disk
I20260812 06:19:22.669457 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: UndoDeltaBlockGCOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:19:22.669991 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=3.181125
I20260812 06:19:22.684269 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.014s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4269,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:22.684724 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:22.694365 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3425,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:22.694995 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=1.000000
I20260812 06:19:22.865897 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.171s	user 0.104s	sys 0.059s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918322,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1027,"lbm_read_time_us":11206,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33132,"lbm_writes_lt_1ms":643,"mutex_wait_us":487,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":99,"threads_started":1,"update_count":3000}
I20260812 06:19:22.866446 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=14.095187
I20260812 06:19:22.914460 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.048s	user 0.023s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18330,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:22.914999 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=2.188937
I20260812 06:19:22.929557 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: FlushDeltaMemStoresOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.014s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5884,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.930024 13815 maintenance_manager.cc:419] P 3a1dcdf6ab7f44de900dea638cc4183d: Scheduling MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f): perf score=1.000000
I20260812 06:19:22.960857 13260 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.615s	user 1.732s	sys 0.125s
I20260812 06:19:23.012024 13260 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.051s	user 0.002s	sys 0.000s
I20260812 06:19:23.012529 13260 tablet_server.cc:179] TabletServer@127.12.243.1:0 shutting down...
I20260812 06:19:23.050908 13717 maintenance_manager.cc:643] P 3a1dcdf6ab7f44de900dea638cc4183d: MajorDeltaCompactionOp(2fdca61c9e084759b7fafdda0c1d8b5f) complete. Timing: real 0.121s	user 0.092s	sys 0.028s 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":220,"lbm_read_time_us":10010,"lbm_reads_lt_1ms":568,"lbm_write_time_us":21925,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":28544,"update_count":2500}
I20260812 06:19:23.052002 13260 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:23.052222 13260 tablet_replica.cc:333] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d: stopping tablet replica
I20260812 06:19:23.052345 13260 raft_consensus.cc:2243] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:23.061655 13260 raft_consensus.cc:2272] T 2fdca61c9e084759b7fafdda0c1d8b5f P 3a1dcdf6ab7f44de900dea638cc4183d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:23.076380 13260 tablet_server.cc:196] TabletServer@127.12.243.1:0 shutdown complete.
I20260812 06:19:23.096167 13260 master.cc:562] Master@127.12.243.62:40341 shutting down...
I20260812 06:19:23.099937 13260 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:23.100123 13260 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:23.100174 13260 tablet_replica.cc:333] T 00000000000000000000000000000000 P 4f87416f15ca47e9bcf687ee9e70dfd1: stopping tablet replica
I20260812 06:19:23.113760 13260 master.cc:584] Master@127.12.243.62:40341 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5026 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10081 ms total)

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