[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:17:55.246634  1695 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.1.167.254:38597
I20260812 06:17:55.247613  1695 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:17:55.248205  1695 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:55.254951  1701 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:55.255043  1695 server_base.cc:1061] running on GCE node
W20260812 06:17:55.254935  1700 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:55.255290  1704 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:55.255811  1695 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:55.255916  1695 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:55.255949  1695 hybrid_clock.cc:648] HybridClock initialized: now 1786515475255948 us; error 0 us; skew 500 ppm
I20260812 06:17:55.257802  1695 webserver.cc:533] Webserver started at http://127.1.167.254:33199/ using document root <none> and password file <none>
I20260812 06:17:55.258317  1695 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:55.258373  1695 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:55.258560  1695 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:55.260191  1695 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/master-0-root/instance:
uuid: "748065348f8741cebf3c723899c299d6"
format_stamp: "Formatted at 2026-08-12 06:17:55 on dist-test-slave-s11t"
I20260812 06:17:55.263720  1695 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:17:55.265904  1717 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:55.266916  1695 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:55.267043  1695 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/master-0-root
uuid: "748065348f8741cebf3c723899c299d6"
format_stamp: "Formatted at 2026-08-12 06:17:55 on dist-test-slave-s11t"
I20260812 06:17:55.267146  1695 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:55.286760  1695 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:55.287465  1695 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:17:55.287658  1695 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:55.295903  1695 rpc_server.cc:307] RPC server started. Bound to: 127.1.167.254:38597
I20260812 06:17:55.296005  1807 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.1.167.254:38597 every 8 connection(s)
I20260812 06:17:55.298265  1809 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:55.303674  1809 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6: Bootstrap starting.
I20260812 06:17:55.306093  1809 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:55.307101  1809 log.cc:826] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:55.308846  1809 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6: No bootstrap required, opened a new log
I20260812 06:17:55.311569  1809 raft_consensus.cc:359] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "748065348f8741cebf3c723899c299d6" member_type: VOTER }
I20260812 06:17:55.311733  1809 raft_consensus.cc:385] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:55.311802  1809 raft_consensus.cc:740] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 748065348f8741cebf3c723899c299d6, State: Initialized, Role: FOLLOWER
I20260812 06:17:55.312395  1809 consensus_queue.cc:260] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6 [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: "748065348f8741cebf3c723899c299d6" member_type: VOTER }
I20260812 06:17:55.312552  1809 raft_consensus.cc:399] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:55.312624  1809 raft_consensus.cc:493] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:55.312803  1809 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:55.313601  1809 raft_consensus.cc:515] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "748065348f8741cebf3c723899c299d6" member_type: VOTER }
I20260812 06:17:55.314038  1809 leader_election.cc:304] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6 [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: 748065348f8741cebf3c723899c299d6; no voters: 
I20260812 06:17:55.314347  1809 leader_election.cc:290] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:55.314513  1817 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:55.314810  1817 raft_consensus.cc:697] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6 [term 1 LEADER]: Becoming Leader. State: Replica: 748065348f8741cebf3c723899c299d6, State: Running, Role: LEADER
I20260812 06:17:55.315162  1817 consensus_queue.cc:237] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6 [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: "748065348f8741cebf3c723899c299d6" member_type: VOTER }
I20260812 06:17:55.315402  1809 sys_catalog.cc:565] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:55.317186  1819 sys_catalog.cc:455] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 748065348f8741cebf3c723899c299d6. Latest consensus state: current_term: 1 leader_uuid: "748065348f8741cebf3c723899c299d6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "748065348f8741cebf3c723899c299d6" member_type: VOTER } }
I20260812 06:17:55.317239  1818 sys_catalog.cc:455] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "748065348f8741cebf3c723899c299d6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "748065348f8741cebf3c723899c299d6" member_type: VOTER } }
I20260812 06:17:55.317317  1819 sys_catalog.cc:458] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:55.317346  1818 sys_catalog.cc:458] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:55.317723  1835 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:55.317768  1695 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:55.320147  1835 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:55.324949  1835 catalog_manager.cc:1383] Generated new cluster ID: ef9a0f218edc421aaee91c9558d386a4
I20260812 06:17:55.325038  1835 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:55.348948  1835 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:55.349992  1835 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:55.358476  1835 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6: Generated new TSK 0
I20260812 06:17:55.359109  1835 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:55.382622  1695 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:55.385591  1850 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:55.385659  1845 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:55.385603  1842 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:55.386102  1695 server_base.cc:1061] running on GCE node
I20260812 06:17:55.386270  1695 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:55.386319  1695 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:55.386343  1695 hybrid_clock.cc:648] HybridClock initialized: now 1786515475386342 us; error 0 us; skew 500 ppm
I20260812 06:17:55.387317  1695 webserver.cc:533] Webserver started at http://127.1.167.193:39807/ using document root <none> and password file <none>
I20260812 06:17:55.387495  1695 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:55.387555  1695 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:55.387637  1695 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:55.388082  1695 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/instance:
uuid: "32fdbf2661df43309910b334f78256fe"
format_stamp: "Formatted at 2026-08-12 06:17:55 on dist-test-slave-s11t"
I20260812 06:17:55.390065  1695 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:55.391225  1855 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:55.391535  1695 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:55.391609  1695 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root
uuid: "32fdbf2661df43309910b334f78256fe"
format_stamp: "Formatted at 2026-08-12 06:17:55 on dist-test-slave-s11t"
I20260812 06:17:55.391700  1695 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:55.407800  1695 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:55.408483  1695 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:55.409072  1695 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:55.409894  1695 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:55.409945  1695 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:55.410020  1695 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:55.410060  1695 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:55.416785  1695 rpc_server.cc:307] RPC server started. Bound to: 127.1.167.193:41943
I20260812 06:17:55.417018  1952 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.1.167.193:41943 every 8 connection(s)
I20260812 06:17:55.432730  1953 heartbeater.cc:344] Connected to a master server at 127.1.167.254:38597
I20260812 06:17:55.433002  1953 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:55.433553  1953 heartbeater.cc:507] Master 127.1.167.254:38597 requested a full tablet report, sending...
I20260812 06:17:55.434984  1746 ts_manager.cc:194] Registered new tserver with Master: 32fdbf2661df43309910b334f78256fe (127.1.167.193:41943)
I20260812 06:17:55.435617  1695 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.017900625s
I20260812 06:17:55.436484  1746 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:46520
I20260812 06:17:55.446255  1746 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:46522:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:55.462261  1898 tablet_service.cc:1511] Processing CreateTablet for tablet 11ec5812e3a043cbba834c9525b7a888 (DEFAULT_TABLE table=heavy-update-compaction-test [id=72f0d0f6fe0b43ba80d0830dd2e5e6bd]), partition=
I20260812 06:17:55.462770  1898 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 11ec5812e3a043cbba834c9525b7a888. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:55.465139  1983 tablet_bootstrap.cc:492] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Bootstrap starting.
I20260812 06:17:55.466635  1983 tablet_bootstrap.cc:654] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:55.468101  1983 tablet_bootstrap.cc:492] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: No bootstrap required, opened a new log
I20260812 06:17:55.468225  1983 ts_tablet_manager.cc:1403] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:55.468828  1983 raft_consensus.cc:359] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "32fdbf2661df43309910b334f78256fe" member_type: VOTER last_known_addr { host: "127.1.167.193" port: 41943 } }
I20260812 06:17:55.468963  1983 raft_consensus.cc:385] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:55.469000  1983 raft_consensus.cc:740] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 32fdbf2661df43309910b334f78256fe, State: Initialized, Role: FOLLOWER
I20260812 06:17:55.469185  1983 consensus_queue.cc:260] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe [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: "32fdbf2661df43309910b334f78256fe" member_type: VOTER last_known_addr { host: "127.1.167.193" port: 41943 } }
I20260812 06:17:55.469285  1983 raft_consensus.cc:399] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:55.469386  1983 raft_consensus.cc:493] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:55.469450  1983 raft_consensus.cc:3060] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:55.470451  1983 raft_consensus.cc:515] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "32fdbf2661df43309910b334f78256fe" member_type: VOTER last_known_addr { host: "127.1.167.193" port: 41943 } }
I20260812 06:17:55.470604  1983 leader_election.cc:304] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe [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: 32fdbf2661df43309910b334f78256fe; no voters: 
I20260812 06:17:55.470822  1983 leader_election.cc:290] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:55.471158  1990 raft_consensus.cc:2804] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:55.471192  1983 ts_tablet_manager.cc:1434] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:55.471589  1990 raft_consensus.cc:697] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe [term 1 LEADER]: Becoming Leader. State: Replica: 32fdbf2661df43309910b334f78256fe, State: Running, Role: LEADER
I20260812 06:17:55.471671  1953 heartbeater.cc:499] Master 127.1.167.254:38597 was elected leader, sending a full tablet report...
I20260812 06:17:55.471791  1990 consensus_queue.cc:237] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe [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: "32fdbf2661df43309910b334f78256fe" member_type: VOTER last_known_addr { host: "127.1.167.193" port: 41943 } }
I20260812 06:17:55.474900  1746 catalog_manager.cc:5719] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe reported cstate change: term changed from 0 to 1, leader changed from <none> to 32fdbf2661df43309910b334f78256fe (127.1.167.193). New cstate: current_term: 1 leader_uuid: "32fdbf2661df43309910b334f78256fe" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "32fdbf2661df43309910b334f78256fe" member_type: VOTER last_known_addr { host: "127.1.167.193" port: 41943 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:55.538264  1695 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.016s	sys 0.008s
I20260812 06:17:55.668143  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushMRSOp(11ec5812e3a043cbba834c9525b7a888): perf score=15.086190
I20260812 06:17:55.828016  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushMRSOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.159s	user 0.117s	sys 0.028s Metrics: {"bytes_written":11897249,"cfile_init":1,"compiler_manager_pool.queue_time_us":194,"delete_count":0,"dirs.queue_time_us":43,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":902,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37813,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":123,"threads_started":1,"update_count":1450}
I20260812 06:17:55.829259  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling LogGCOp(11ec5812e3a043cbba834c9525b7a888): free 20743880 bytes of WAL
I20260812 06:17:55.829595  1864 log_reader.cc:385] T 11ec5812e3a043cbba834c9525b7a888: removed 2 log segments from log reader
I20260812 06:17:55.829681  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000001 (ops 1-6)
I20260812 06:17:55.829766  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000002 (ops 7-11)
I20260812 06:17:55.834132  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: LogGCOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:55.834470  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling UndoDeltaBlockGCOp(11ec5812e3a043cbba834c9525b7a888): 12719216 bytes on disk
I20260812 06:17:55.835023  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: UndoDeltaBlockGCOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:17:55.835412  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=2.188937
I20260812 06:17:55.855935  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.020s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6669,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.856393  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.000000
I20260812 06:17:55.985908  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.129s	user 0.105s	sys 0.023s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262036,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":539,"lbm_read_time_us":7491,"lbm_reads_lt_1ms":450,"lbm_write_time_us":26388,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":282,"threads_started":5,"update_count":1950}
I20260812 06:17:55.986461  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=10.126437
I20260812 06:17:56.036778  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.050s	user 0.028s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17412,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.037300  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=2.188937
I20260812 06:17:56.047700  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4041,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.048372  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.000000
I20260812 06:17:56.179950  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.131s	user 0.106s	sys 0.023s 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":343,"lbm_read_time_us":8943,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26976,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2000}
I20260812 06:17:56.180544  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=10.126437
I20260812 06:17:56.223062  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.042s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16332,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.223487  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=2.188937
I20260812 06:17:56.234375  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3948,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.234977  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.000000
I20260812 06:17:56.360486  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.125s	user 0.093s	sys 0.032s 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":730,"lbm_read_time_us":10133,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23301,"lbm_writes_lt_1ms":443,"mutex_wait_us":303,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:17:56.360998  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=10.126437
I20260812 06:17:56.415318  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.054s	user 0.026s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15804,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.415808  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=2.188937
I20260812 06:17:56.427244  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4459,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.427739  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.000000
I20260812 06:17:56.593590  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.166s	user 0.098s	sys 0.056s 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":233,"lbm_read_time_us":11051,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26662,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:56.594324  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=10.126437
I20260812 06:17:56.629635  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.035s	user 0.022s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13056,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.630246  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.000000
I20260812 06:17:56.743014  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.113s	user 0.083s	sys 0.029s 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":394,"lbm_read_time_us":5996,"lbm_reads_lt_1ms":363,"lbm_write_time_us":21260,"lbm_writes_lt_1ms":343,"mutex_wait_us":85,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":1500}
I20260812 06:17:56.743640  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=10.126437
I20260812 06:17:56.782130  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.038s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16283,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.782621  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=2.188937
I20260812 06:17:56.793201  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3970,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.793731  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.000000
I20260812 06:17:56.928627  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.135s	user 0.102s	sys 0.032s 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":622,"lbm_read_time_us":10172,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25969,"lbm_writes_lt_1ms":443,"mutex_wait_us":326,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":23680,"update_count":2000}
I20260812 06:17:56.929251  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=10.126437
I20260812 06:17:56.984771  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.055s	user 0.029s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16467,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.985280  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=2.188937
I20260812 06:17:56.995918  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4250,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.996376  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.000000
I20260812 06:17:57.143630  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.147s	user 0.091s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":419,"lbm_read_time_us":11310,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23147,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.144287  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=10.126437
I20260812 06:17:57.195255  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.051s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16596,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:57.195791  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=2.188937
I20260812 06:17:57.209828  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.014s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5081,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.210474  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushMRSOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.000000
I20260812 06:17:57.239627  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushMRSOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.029s	user 0.026s	sys 0.001s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":230,"dirs.run_wall_time_us":1338,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1868,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:57.240511  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling LogGCOp(11ec5812e3a043cbba834c9525b7a888): free 124710298 bytes of WAL
I20260812 06:17:57.240856  1864 log_reader.cc:385] T 11ec5812e3a043cbba834c9525b7a888: removed 12 log segments from log reader
I20260812 06:17:57.240923  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000003 (ops 12-16)
I20260812 06:17:57.240979  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000004 (ops 17-21)
I20260812 06:17:57.241016  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000005 (ops 22-26)
I20260812 06:17:57.241055  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000006 (ops 27-31)
I20260812 06:17:57.241092  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000007 (ops 32-36)
I20260812 06:17:57.241129  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000008 (ops 37-41)
I20260812 06:17:57.241166  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000009 (ops 42-46)
I20260812 06:17:57.241204  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000010 (ops 47-51)
I20260812 06:17:57.241240  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000011 (ops 52-56)
I20260812 06:17:57.241276  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000012 (ops 57-61)
I20260812 06:17:57.241312  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000013 (ops 62-66)
I20260812 06:17:57.241349  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000014 (ops 67-71)
I20260812 06:17:57.271354  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: LogGCOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.031s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:17:57.271808  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling UndoDeltaBlockGCOp(11ec5812e3a043cbba834c9525b7a888): 472 bytes on disk
I20260812 06:17:57.272403  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: UndoDeltaBlockGCOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4}
I20260812 06:17:57.273089  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=3.181125
I20260812 06:17:57.287849  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":5046218,"delete_count":0,"lbm_write_time_us":5902,"lbm_writes_lt_1ms":126,"reinsert_count":0,"update_count":615}
I20260812 06:17:57.288352  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.196750
I20260812 06:17:57.309953  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.021s	user 0.009s	sys 0.011s Metrics: {"bytes_written":3159080,"delete_count":0,"lbm_write_time_us":4482,"lbm_writes_lt_1ms":80,"reinsert_count":0,"update_count":385}
I20260812 06:17:57.310701  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.000000
I20260812 06:17:57.530637  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.220s	user 0.140s	sys 0.079s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877320,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":258,"lbm_read_time_us":15573,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36394,"lbm_writes_lt_1ms":643,"mutex_wait_us":51,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12928,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:17:57.531392  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=14.095187
I20260812 06:17:57.603587  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.072s	user 0.038s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26362,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.604249  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=2.188937
I20260812 06:17:57.623111  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.019s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7074,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.623828  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.000000
I20260812 06:17:57.806903  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.183s	user 0.141s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":261,"lbm_read_time_us":14061,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31162,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:17:57.807718  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=11.118625
I20260812 06:17:57.845038  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.037s	user 0.018s	sys 0.019s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16548,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:57.845707  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=2.188937
I20260812 06:17:57.869661  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.024s	user 0.012s	sys 0.002s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5200,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:57.870179  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=2.188937
I20260812 06:17:57.882162  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4466,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.882890  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.000000
I20260812 06:17:58.076726  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.194s	user 0.134s	sys 0.053s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":147,"lbm_read_time_us":11990,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31130,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19456,"update_count":2500}
I20260812 06:17:58.077314  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=14.095187
I20260812 06:17:58.127611  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.050s	user 0.025s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17833,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:58.128114  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=2.188937
I20260812 06:17:58.144055  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5881,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.144629  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.000000
I20260812 06:17:58.313450  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.169s	user 0.144s	sys 0.025s 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":343,"lbm_read_time_us":10391,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35503,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:58.314040  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=10.126437
I20260812 06:17:58.361907  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.048s	user 0.015s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15940,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:58.362756  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=2.188937
I20260812 06:17:58.381250  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.018s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6908,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.381907  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.000000
I20260812 06:17:58.532950  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.151s	user 0.101s	sys 0.048s 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":544,"lbm_read_time_us":10672,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28543,"lbm_writes_lt_1ms":443,"mutex_wait_us":281,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:17:58.533921  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=10.126437
I20260812 06:17:58.576978  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.043s	user 0.012s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15826,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:58.577495  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=2.188937
I20260812 06:17:58.588189  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4169,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.588654  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.000000
I20260812 06:17:58.722862  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.134s	user 0.093s	sys 0.041s 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":257,"lbm_read_time_us":10685,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25313,"lbm_writes_lt_1ms":443,"mutex_wait_us":32,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19072,"update_count":2000}
I20260812 06:17:58.723398  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=10.126437
I20260812 06:17:58.776584  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.053s	user 0.021s	sys 0.018s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":14970,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:58.777154  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=2.188937
I20260812 06:17:58.790089  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5161,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.790575  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushMRSOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.000000
I20260812 06:17:58.829321  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushMRSOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.039s	user 0.025s	sys 0.003s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":202,"dirs.run_wall_time_us":1806,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1469,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:58.830065  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling LogGCOp(11ec5812e3a043cbba834c9525b7a888): free 112692379 bytes of WAL
I20260812 06:17:58.830317  1864 log_reader.cc:385] T 11ec5812e3a043cbba834c9525b7a888: removed 11 log segments from log reader
I20260812 06:17:58.830368  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000015 (ops 72-76)
I20260812 06:17:58.830401  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000016 (ops 77-81)
I20260812 06:17:58.830472  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000017 (ops 82-86)
I20260812 06:17:58.830524  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000018 (ops 87-91)
I20260812 06:17:58.830590  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000019 (ops 92-96)
I20260812 06:17:58.830636  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000020 (ops 97-101)
I20260812 06:17:58.830700  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000021 (ops 102-106)
I20260812 06:17:58.830742  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000022 (ops 107-111)
I20260812 06:17:58.830785  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000023 (ops 112-116)
I20260812 06:17:58.830828  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000024 (ops 117-121)
I20260812 06:17:58.830871  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000025 (ops 122-126)
I20260812 06:17:58.858882  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: LogGCOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:58.859288  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling UndoDeltaBlockGCOp(11ec5812e3a043cbba834c9525b7a888): 462 bytes on disk
I20260812 06:17:58.859731  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: UndoDeltaBlockGCOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:17:58.860256  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=3.181125
I20260812 06:17:58.873579  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.013s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4512901,"delete_count":0,"lbm_write_time_us":5259,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:58.874020  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling LogGCOp(11ec5812e3a043cbba834c9525b7a888): free 11564883 bytes of WAL
I20260812 06:17:58.874253  1864 log_reader.cc:385] T 11ec5812e3a043cbba834c9525b7a888: removed 1 log segments from log reader
I20260812 06:17:58.874300  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000026 (ops 127-130)
I20260812 06:17:58.877010  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: LogGCOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.003s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:58.877308  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=2.188937
I20260812 06:17:58.889272  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3908,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:58.889912  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.000000
I20260812 06:17:59.078857  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.189s	user 0.109s	sys 0.080s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877330,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":239,"lbm_read_time_us":14243,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32470,"lbm_writes_lt_1ms":643,"mutex_wait_us":18,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8960,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:17:59.080725  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=14.095187
I20260812 06:17:59.142905  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.062s	user 0.032s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22538,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.143440  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=2.188937
I20260812 06:17:59.154863  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3907,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.155552  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.000000
I20260812 06:17:59.337872  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.182s	user 0.110s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":565,"lbm_read_time_us":12062,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30028,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2500}
I20260812 06:17:59.338469  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=14.095187
I20260812 06:17:59.410466  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.072s	user 0.020s	sys 0.040s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":23940,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.411005  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=2.188937
I20260812 06:17:59.422166  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4372,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.422695  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.000000
I20260812 06:17:59.600998  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.178s	user 0.107s	sys 0.068s 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":549,"lbm_read_time_us":13529,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29628,"lbm_writes_lt_1ms":543,"mutex_wait_us":202,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:59.601611  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=11.118625
I20260812 06:17:59.637027  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.035s	user 0.031s	sys 0.004s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15296,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:59.637617  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=2.188937
I20260812 06:17:59.658713  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.021s	user 0.015s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5673,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:59.659454  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.000000
I20260812 06:17:59.827931  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.168s	user 0.095s	sys 0.067s 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":745,"dirs.run_cpu_time_us":2725,"dirs.run_wall_time_us":20720,"lbm_read_time_us":11285,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27449,"lbm_writes_lt_1ms":443,"mutex_wait_us":4919,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:59.828670  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=11.118625
I20260812 06:17:59.869071  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.040s	user 0.027s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17485,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:59.869727  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=2.188937
I20260812 06:17:59.894915  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.025s	user 0.009s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5042,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:59.895593  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=2.188937
I20260812 06:17:59.911032  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5716,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.911829  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.000000
I20260812 06:18:00.091315  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.179s	user 0.134s	sys 0.035s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":414,"lbm_read_time_us":12366,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33822,"lbm_writes_lt_1ms":543,"mutex_wait_us":59,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17408,"update_count":2500}
I20260812 06:18:00.091866  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=14.095187
I20260812 06:18:00.146553  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.054s	user 0.022s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21072,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:00.147195  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=2.188937
I20260812 06:18:00.158900  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3986,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.159431  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.000000
I20260812 06:18:00.324131  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.164s	user 0.109s	sys 0.052s 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":1268,"lbm_read_time_us":11648,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32994,"lbm_writes_lt_1ms":543,"mutex_wait_us":286,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:18:00.325091  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=11.118625
I20260812 06:18:00.366648  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.041s	user 0.031s	sys 0.009s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18264,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:00.367221  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=2.188937
I20260812 06:18:00.378674  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4032,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:00.379209  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushMRSOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.000000
I20260812 06:18:00.414227  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushMRSOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.035s	user 0.032s	sys 0.001s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":1110,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1999,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:00.415063  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling LogGCOp(11ec5812e3a043cbba834c9525b7a888): free 116849716 bytes of WAL
I20260812 06:18:00.415390  1864 log_reader.cc:385] T 11ec5812e3a043cbba834c9525b7a888: removed 12 log segments from log reader
I20260812 06:18:00.415470  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000027 (ops 131-135)
I20260812 06:18:00.415517  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000028 (ops 136-140)
I20260812 06:18:00.415558  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000029 (ops 141-144)
I20260812 06:18:00.415588  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000030 (ops 145-149)
I20260812 06:18:00.415625  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000031 (ops 150-154)
I20260812 06:18:00.415660  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000032 (ops 155-158)
I20260812 06:18:00.415701  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000033 (ops 159-163)
I20260812 06:18:00.415731  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000034 (ops 164-168)
I20260812 06:18:00.415761  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000035 (ops 169-172)
I20260812 06:18:00.415791  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000036 (ops 173-177)
I20260812 06:18:00.415822  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000037 (ops 178-182)
I20260812 06:18:00.415854  1864 log.cc:1079] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/11ec5812e3a043cbba834c9525b7a888/wal-000000038 (ops 183-187)
I20260812 06:18:00.443225  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: LogGCOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:00.443789  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling UndoDeltaBlockGCOp(11ec5812e3a043cbba834c9525b7a888): 472 bytes on disk
I20260812 06:18:00.444249  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: UndoDeltaBlockGCOp(11ec5812e3a043cbba834c9525b7a888) 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:18:00.445016  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=6.157687
I20260812 06:18:00.476109  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.031s	user 0.013s	sys 0.013s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":13489,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":202,"reinsert_count":0,"update_count":1000}
I20260812 06:18:00.476725  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.000000
I20260812 06:18:00.642238  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.165s	user 0.116s	sys 0.049s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877213,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":608,"lbm_read_time_us":12497,"lbm_reads_lt_1ms":665,"lbm_write_time_us":32490,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":173,"threads_started":1,"update_count":3000}
I20260812 06:18:00.643040  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=14.095187
I20260812 06:18:00.693821  1695 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.155s	user 1.925s	sys 0.161s
I20260812 06:18:00.698707  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.055s	user 0.038s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24850,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:00.699195  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888): perf score=2.188937
I20260812 06:18:00.709245  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: FlushDeltaMemStoresOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4085,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.709720  1958 maintenance_manager.cc:419] P 32fdbf2661df43309910b334f78256fe: Scheduling MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888): perf score=1.000000
I20260812 06:18:00.739539  1695 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.045s	user 0.001s	sys 0.000s
I20260812 06:18:00.740242  1695 tablet_server.cc:179] TabletServer@127.1.167.193:0 shutting down...
I20260812 06:18:00.819306  1864 maintenance_manager.cc:643] P 32fdbf2661df43309910b334f78256fe: MajorDeltaCompactionOp(11ec5812e3a043cbba834c9525b7a888) complete. Timing: real 0.109s	user 0.094s	sys 0.016s 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":313,"lbm_read_time_us":3112,"lbm_reads_lt_1ms":163,"lbm_write_time_us":25109,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2500}
I20260812 06:18:00.820231  1695 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:00.820664  1695 tablet_replica.cc:333] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe: stopping tablet replica
I20260812 06:18:00.820938  1695 raft_consensus.cc:2243] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:00.821187  1695 raft_consensus.cc:2272] T 11ec5812e3a043cbba834c9525b7a888 P 32fdbf2661df43309910b334f78256fe [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:00.837018  1695 tablet_server.cc:196] TabletServer@127.1.167.193:0 shutdown complete.
I20260812 06:18:00.865751  1695 master.cc:562] Master@127.1.167.254:38597 shutting down...
I20260812 06:18:00.869928  1695 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:00.870143  1695 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:00.870240  1695 tablet_replica.cc:333] T 00000000000000000000000000000000 P 748065348f8741cebf3c723899c299d6: stopping tablet replica
I20260812 06:18:00.882959  1695 master.cc:584] Master@127.1.167.254:38597 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5732 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:00.990435  1695 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.1.167.254:39919
I20260812 06:18:00.990914  1695 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:18:00.993605  1695 server_base.cc:1061] running on GCE node
W20260812 06:18:00.993643  2012 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:00.993644  2013 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:00.993796  2017 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:00.994065  1695 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:00.994107  1695 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:00.994122  1695 hybrid_clock.cc:648] HybridClock initialized: now 1786515480994122 us; error 0 us; skew 500 ppm
I20260812 06:18:00.994989  1695 webserver.cc:533] Webserver started at http://127.1.167.254:40237/ using document root <none> and password file <none>
I20260812 06:18:00.995128  1695 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:00.995172  1695 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:00.995229  1695 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:00.995708  1695 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/master-0-root/instance:
uuid: "48442ddb6a1541dfb3c1e258e3a32312"
format_stamp: "Formatted at 2026-08-12 06:18:00 on dist-test-slave-s11t"
I20260812 06:18:00.997361  1695 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:00.998265  2031 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:00.998543  1695 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:00.998613  1695 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/master-0-root
uuid: "48442ddb6a1541dfb3c1e258e3a32312"
format_stamp: "Formatted at 2026-08-12 06:18:00 on dist-test-slave-s11t"
I20260812 06:18:00.998714  1695 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:01.009379  1695 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:01.009840  1695 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:01.014560  1695 rpc_server.cc:307] RPC server started. Bound to: 127.1.167.254:39919
I20260812 06:18:01.017027  2121 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:01.021772  2120 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.1.167.254:39919 every 8 connection(s)
I20260812 06:18:01.022490  2121 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312: Bootstrap starting.
I20260812 06:18:01.023435  2121 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:01.024524  2121 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312: No bootstrap required, opened a new log
I20260812 06:18:01.025009  2121 raft_consensus.cc:359] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "48442ddb6a1541dfb3c1e258e3a32312" member_type: VOTER }
I20260812 06:18:01.025102  2121 raft_consensus.cc:385] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:01.025125  2121 raft_consensus.cc:740] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 48442ddb6a1541dfb3c1e258e3a32312, State: Initialized, Role: FOLLOWER
I20260812 06:18:01.025265  2121 consensus_queue.cc:260] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312 [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: "48442ddb6a1541dfb3c1e258e3a32312" member_type: VOTER }
I20260812 06:18:01.025358  2121 raft_consensus.cc:399] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:01.025384  2121 raft_consensus.cc:493] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:01.025415  2121 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:01.026080  2121 raft_consensus.cc:515] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "48442ddb6a1541dfb3c1e258e3a32312" member_type: VOTER }
I20260812 06:18:01.026192  2121 leader_election.cc:304] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312 [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: 48442ddb6a1541dfb3c1e258e3a32312; no voters: 
I20260812 06:18:01.026360  2121 leader_election.cc:290] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:01.026530  2129 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:01.026747  2129 raft_consensus.cc:697] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312 [term 1 LEADER]: Becoming Leader. State: Replica: 48442ddb6a1541dfb3c1e258e3a32312, State: Running, Role: LEADER
I20260812 06:18:01.026904  2129 consensus_queue.cc:237] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312 [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: "48442ddb6a1541dfb3c1e258e3a32312" member_type: VOTER }
I20260812 06:18:01.026883  2121 sys_catalog.cc:565] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:01.027391  2131 sys_catalog.cc:455] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 48442ddb6a1541dfb3c1e258e3a32312. Latest consensus state: current_term: 1 leader_uuid: "48442ddb6a1541dfb3c1e258e3a32312" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "48442ddb6a1541dfb3c1e258e3a32312" member_type: VOTER } }
I20260812 06:18:01.027361  2130 sys_catalog.cc:455] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "48442ddb6a1541dfb3c1e258e3a32312" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "48442ddb6a1541dfb3c1e258e3a32312" member_type: VOTER } }
I20260812 06:18:01.027474  2131 sys_catalog.cc:458] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:01.027484  2130 sys_catalog.cc:458] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:01.027763  2133 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:01.028599  2133 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:01.029103  1695 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:01.030501  2133 catalog_manager.cc:1383] Generated new cluster ID: 3bff360ad07049e58148256051ed958b
I20260812 06:18:01.030560  2133 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:01.038705  2133 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:01.039268  2133 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:01.047091  2133 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312: Generated new TSK 0
I20260812 06:18:01.047310  2133 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:01.061550  1695 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:01.063649  2159 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:01.063722  2153 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:01.063737  1695 server_base.cc:1061] running on GCE node
W20260812 06:18:01.063808  2154 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:01.064127  1695 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:01.064173  1695 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:01.064189  1695 hybrid_clock.cc:648] HybridClock initialized: now 1786515481064190 us; error 0 us; skew 500 ppm
I20260812 06:18:01.065151  1695 webserver.cc:533] Webserver started at http://127.1.167.193:43167/ using document root <none> and password file <none>
I20260812 06:18:01.065371  1695 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:01.065425  1695 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:01.065505  1695 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:01.065937  1695 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/instance:
uuid: "73fe78cceba841b0ad20e88205e564de"
format_stamp: "Formatted at 2026-08-12 06:18:01 on dist-test-slave-s11t"
I20260812 06:18:01.067567  1695 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:01.068881  2168 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:01.069306  1695 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:01.069437  1695 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root
uuid: "73fe78cceba841b0ad20e88205e564de"
format_stamp: "Formatted at 2026-08-12 06:18:01 on dist-test-slave-s11t"
I20260812 06:18:01.069536  1695 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:01.088580  1695 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:01.089088  1695 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:01.089478  1695 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:01.090024  1695 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:01.090094  1695 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:01.090160  1695 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:01.090216  1695 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:01.095055  1695 rpc_server.cc:307] RPC server started. Bound to: 127.1.167.193:35819
I20260812 06:18:01.095762  2283 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.1.167.193:35819 every 8 connection(s)
I20260812 06:18:01.104442  2285 heartbeater.cc:344] Connected to a master server at 127.1.167.254:39919
I20260812 06:18:01.104578  2285 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:01.104895  2285 heartbeater.cc:507] Master 127.1.167.254:39919 requested a full tablet report, sending...
I20260812 06:18:01.105618  2058 ts_manager.cc:194] Registered new tserver with Master: 73fe78cceba841b0ad20e88205e564de (127.1.167.193:35819)
I20260812 06:18:01.105939  1695 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010019191s
I20260812 06:18:01.106410  2058 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:47966
I20260812 06:18:01.113415  2058 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:47972:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:01.122237  2224 tablet_service.cc:1511] Processing CreateTablet for tablet 53a3996b96f64a76b9d77a0cf4ddd4de (DEFAULT_TABLE table=heavy-update-compaction-test [id=630515b2d8aa42c08d199a2b2f909d1b]), partition=
I20260812 06:18:01.122557  2224 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 53a3996b96f64a76b9d77a0cf4ddd4de. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:01.124956  2309 tablet_bootstrap.cc:492] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Bootstrap starting.
I20260812 06:18:01.125892  2309 tablet_bootstrap.cc:654] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:01.127110  2309 tablet_bootstrap.cc:492] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: No bootstrap required, opened a new log
I20260812 06:18:01.127234  2309 ts_tablet_manager.cc:1403] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:01.127859  2309 raft_consensus.cc:359] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "73fe78cceba841b0ad20e88205e564de" member_type: VOTER last_known_addr { host: "127.1.167.193" port: 35819 } }
I20260812 06:18:01.127986  2309 raft_consensus.cc:385] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:01.128068  2309 raft_consensus.cc:740] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 73fe78cceba841b0ad20e88205e564de, State: Initialized, Role: FOLLOWER
I20260812 06:18:01.128228  2309 consensus_queue.cc:260] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de [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: "73fe78cceba841b0ad20e88205e564de" member_type: VOTER last_known_addr { host: "127.1.167.193" port: 35819 } }
I20260812 06:18:01.128350  2309 raft_consensus.cc:399] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:01.128396  2309 raft_consensus.cc:493] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:01.128451  2309 raft_consensus.cc:3060] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:01.129328  2309 raft_consensus.cc:515] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "73fe78cceba841b0ad20e88205e564de" member_type: VOTER last_known_addr { host: "127.1.167.193" port: 35819 } }
I20260812 06:18:01.129499  2309 leader_election.cc:304] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de [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: 73fe78cceba841b0ad20e88205e564de; no voters: 
I20260812 06:18:01.129735  2309 leader_election.cc:290] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:01.129933  2312 raft_consensus.cc:2804] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:01.130158  2312 raft_consensus.cc:697] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de [term 1 LEADER]: Becoming Leader. State: Replica: 73fe78cceba841b0ad20e88205e564de, State: Running, Role: LEADER
I20260812 06:18:01.130132  2285 heartbeater.cc:499] Master 127.1.167.254:39919 was elected leader, sending a full tablet report...
I20260812 06:18:01.130110  2309 ts_tablet_manager.cc:1434] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:01.130335  2312 consensus_queue.cc:237] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de [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: "73fe78cceba841b0ad20e88205e564de" member_type: VOTER last_known_addr { host: "127.1.167.193" port: 35819 } }
I20260812 06:18:01.131970  2058 catalog_manager.cc:5719] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de reported cstate change: term changed from 0 to 1, leader changed from <none> to 73fe78cceba841b0ad20e88205e564de (127.1.167.193). New cstate: current_term: 1 leader_uuid: "73fe78cceba841b0ad20e88205e564de" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "73fe78cceba841b0ad20e88205e564de" member_type: VOTER last_known_addr { host: "127.1.167.193" port: 35819 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:01.194478  1695 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.016s	sys 0.008s
I20260812 06:18:01.346580  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushMRSOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=19.054940
I20260812 06:18:01.517346  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushMRSOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.170s	user 0.121s	sys 0.048s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":102,"dirs.run_cpu_time_us":354,"dirs.run_wall_time_us":1426,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41169,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:18:01.518354  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling LogGCOp(53a3996b96f64a76b9d77a0cf4ddd4de): free 20743880 bytes of WAL
I20260812 06:18:01.518682  2179 log_reader.cc:385] T 53a3996b96f64a76b9d77a0cf4ddd4de: removed 2 log segments from log reader
I20260812 06:18:01.518760  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000001 (ops 1-6)
I20260812 06:18:01.518807  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000002 (ops 7-11)
I20260812 06:18:01.525028  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: LogGCOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.006s	user 0.000s	sys 0.006s Metrics: {}
I20260812 06:18:01.525594  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling UndoDeltaBlockGCOp(53a3996b96f64a76b9d77a0cf4ddd4de): 16411393 bytes on disk
I20260812 06:18:01.526333  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: UndoDeltaBlockGCOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":105,"lbm_reads_lt_1ms":4}
I20260812 06:18:01.526911  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=2.188937
I20260812 06:18:01.547135  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.020s	user 0.013s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7706,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.547735  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=1.000000
I20260812 06:18:01.712481  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.165s	user 0.111s	sys 0.053s 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":536,"lbm_read_time_us":11462,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27594,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":368,"threads_started":5,"update_count":2000}
I20260812 06:18:01.713207  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=10.126437
I20260812 06:18:01.757898  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.044s	user 0.040s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19343,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:01.758541  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=2.188937
I20260812 06:18:01.771648  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4929,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.772150  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=1.000000
I20260812 06:18:01.934649  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.162s	user 0.107s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":457,"lbm_read_time_us":10960,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24558,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":63616,"update_count":2000}
I20260812 06:18:01.935405  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=10.126437
I20260812 06:18:01.978006  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.042s	user 0.025s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18818,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:01.978509  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=2.188937
I20260812 06:18:01.991195  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4854,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.991648  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=1.000000
I20260812 06:18:02.129449  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.138s	user 0.118s	sys 0.020s 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":230,"lbm_read_time_us":8628,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28172,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":27520,"update_count":2000}
I20260812 06:18:02.130221  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=10.126437
I20260812 06:18:02.178503  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.048s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18458,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:02.179014  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=2.188937
I20260812 06:18:02.189272  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3984,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.190086  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=1.000000
I20260812 06:18:02.336225  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.146s	user 0.109s	sys 0.036s 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":2220,"lbm_read_time_us":9969,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28848,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2000}
I20260812 06:18:02.337098  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=10.126437
I20260812 06:18:02.391718  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.054s	user 0.031s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17973,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:02.392408  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=2.188937
I20260812 06:18:02.409832  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.017s	user 0.014s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6601,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.410410  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=1.000000
I20260812 06:18:02.572929  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.162s	user 0.121s	sys 0.041s 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":2232,"lbm_read_time_us":12916,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23309,"lbm_writes_lt_1ms":443,"mutex_wait_us":502,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21376,"update_count":2000}
I20260812 06:18:02.573675  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=10.126437
I20260812 06:18:02.623641  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.050s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16805,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:02.624306  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=2.188937
I20260812 06:18:02.637502  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.013s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4716,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.638079  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=1.000000
I20260812 06:18:02.771720  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.133s	user 0.113s	sys 0.020s 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":275,"lbm_read_time_us":10724,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24074,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2000}
I20260812 06:18:02.772617  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=10.126437
I20260812 06:18:02.819984  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.047s	user 0.023s	sys 0.009s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15483,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:02.820535  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=2.188937
I20260812 06:18:02.836789  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.016s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6091,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.837514  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushMRSOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=1.000000
I20260812 06:18:02.869925  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushMRSOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":109,"dirs.run_cpu_time_us":511,"dirs.run_wall_time_us":1656,"drs_written":1,"lbm_read_time_us":107,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2272,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:02.870604  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling LogGCOp(53a3996b96f64a76b9d77a0cf4ddd4de): free 112692367 bytes of WAL
I20260812 06:18:02.870843  2179 log_reader.cc:385] T 53a3996b96f64a76b9d77a0cf4ddd4de: removed 11 log segments from log reader
I20260812 06:18:02.870890  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000003 (ops 12-16)
I20260812 06:18:02.870946  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000004 (ops 17-21)
I20260812 06:18:02.870983  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000005 (ops 22-26)
I20260812 06:18:02.871027  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000006 (ops 27-31)
I20260812 06:18:02.871064  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000007 (ops 32-36)
I20260812 06:18:02.871126  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000008 (ops 37-41)
I20260812 06:18:02.871162  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000009 (ops 42-46)
I20260812 06:18:02.871201  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000010 (ops 47-51)
I20260812 06:18:02.871240  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000011 (ops 52-56)
I20260812 06:18:02.871281  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000012 (ops 57-61)
I20260812 06:18:02.871325  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000013 (ops 62-66)
I20260812 06:18:02.897423  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: LogGCOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:02.897891  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=2.188937
I20260812 06:18:02.919552  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.021s	user 0.001s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6062,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.920015  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling UndoDeltaBlockGCOp(53a3996b96f64a76b9d77a0cf4ddd4de): 447 bytes on disk
I20260812 06:18:02.920423  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: UndoDeltaBlockGCOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:18:02.921020  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=2.188937
I20260812 06:18:02.931743  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4195,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.932475  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=1.000000
I20260812 06:18:03.126801  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.194s	user 0.136s	sys 0.052s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":578,"lbm_read_time_us":12638,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37623,"lbm_writes_lt_1ms":643,"mutex_wait_us":309,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12544,"thread_start_us":74,"threads_started":1,"update_count":3000}
I20260812 06:18:03.127492  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=14.095187
I20260812 06:18:03.190042  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.062s	user 0.036s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23031,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:03.190711  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=2.188937
I20260812 06:18:03.209585  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.019s	user 0.010s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7230,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:03.210233  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=1.000000
I20260812 06:18:03.447834  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.237s	user 0.217s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":934,"lbm_read_time_us":17109,"lbm_reads_lt_1ms":572,"lbm_write_time_us":40972,"lbm_writes_lt_1ms":543,"mutex_wait_us":331,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:03.448551  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=22.032687
I20260812 06:18:03.544047  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.095s	user 0.060s	sys 0.032s Metrics: {"bytes_written":24614722,"delete_count":0,"lbm_write_time_us":41547,"lbm_writes_lt_1ms":603,"reinsert_count":0,"update_count":3000}
I20260812 06:18:03.544736  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=6.157687
I20260812 06:18:03.584517  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.040s	user 0.022s	sys 0.009s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":14175,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:03.585260  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=2.188937
I20260812 06:18:03.602415  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.017s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6674,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:03.602902  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=1.000000
I20260812 06:18:03.836760  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.234s	user 0.170s	sys 0.064s Metrics: {"cfile_cache_miss":933,"cfile_cache_miss_bytes":41184451,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":750,"lbm_read_time_us":18140,"lbm_reads_lt_1ms":973,"lbm_write_time_us":49197,"lbm_writes_lt_1ms":943,"mutex_wait_us":25,"peak_mem_usage":112822188,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":4500}
I20260812 06:18:03.837550  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=18.063937
I20260812 06:18:03.896075  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.058s	user 0.035s	sys 0.020s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":26158,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:03.896660  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=2.188937
I20260812 06:18:03.919872  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.023s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6174,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:03.920343  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=1.000000
I20260812 06:18:04.084390  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.164s	user 0.124s	sys 0.040s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":202,"lbm_read_time_us":10928,"lbm_reads_lt_1ms":664,"lbm_write_time_us":34003,"lbm_writes_lt_1ms":643,"mutex_wait_us":24,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":3000}
I20260812 06:18:04.085203  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=14.095187
I20260812 06:18:04.138916  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.053s	user 0.035s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23745,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:04.139619  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=2.188937
I20260812 06:18:04.152665  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4616,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.153422  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=1.000000
I20260812 06:18:04.312917  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.159s	user 0.112s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":751,"lbm_read_time_us":9617,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31685,"lbm_writes_lt_1ms":543,"mutex_wait_us":317,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":40832,"update_count":2500}
I20260812 06:18:04.313643  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=10.126437
I20260812 06:18:04.349846  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.036s	user 0.031s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16138,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:04.350685  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=2.188937
I20260812 06:18:04.371258  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.020s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5939,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.371871  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushMRSOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=1.000000
I20260812 06:18:04.426050  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushMRSOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.054s	user 0.026s	sys 0.004s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":84,"dirs.run_cpu_time_us":343,"dirs.run_wall_time_us":1443,"drs_written":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2354,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:04.426719  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling LogGCOp(53a3996b96f64a76b9d77a0cf4ddd4de): free 132118257 bytes of WAL
I20260812 06:18:04.427019  2179 log_reader.cc:385] T 53a3996b96f64a76b9d77a0cf4ddd4de: removed 13 log segments from log reader
I20260812 06:18:04.427073  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000014 (ops 67-70)
I20260812 06:18:04.427102  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000015 (ops 71-75)
I20260812 06:18:04.427174  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000016 (ops 76-80)
I20260812 06:18:04.427222  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000017 (ops 81-84)
I20260812 06:18:04.427263  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000018 (ops 85-89)
I20260812 06:18:04.427306  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000019 (ops 90-94)
I20260812 06:18:04.427348  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000020 (ops 95-99)
I20260812 06:18:04.427372  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000021 (ops 100-104)
I20260812 06:18:04.427414  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000022 (ops 105-109)
I20260812 06:18:04.427510  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000023 (ops 110-114)
I20260812 06:18:04.427556  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000024 (ops 115-119)
I20260812 06:18:04.427575  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000025 (ops 120-124)
I20260812 06:18:04.427627  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000026 (ops 125-128)
I20260812 06:18:04.457582  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: LogGCOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:18:04.458137  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=7.149875
I20260812 06:18:04.482358  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.024s	user 0.014s	sys 0.009s Metrics: {"bytes_written":9230684,"delete_count":0,"lbm_write_time_us":10406,"lbm_writes_lt_1ms":228,"reinsert_count":0,"update_count":1125}
I20260812 06:18:04.483070  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling UndoDeltaBlockGCOp(53a3996b96f64a76b9d77a0cf4ddd4de): 493 bytes on disk
I20260812 06:18:04.483625  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: UndoDeltaBlockGCOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":87,"lbm_reads_lt_1ms":4}
I20260812 06:18:04.484325  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=1.196750
I20260812 06:18:04.496747  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.012s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3077030,"delete_count":0,"lbm_write_time_us":3211,"lbm_writes_lt_1ms":78,"reinsert_count":0,"update_count":375}
I20260812 06:18:04.497236  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=1.000000
I20260812 06:18:04.709545  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.212s	user 0.161s	sys 0.049s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979728,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":4571,"lbm_read_time_us":15160,"lbm_reads_lt_1ms":766,"lbm_write_time_us":39058,"lbm_writes_lt_1ms":743,"mutex_wait_us":2259,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2304,"thread_start_us":83,"threads_started":1,"update_count":3500}
I20260812 06:18:04.710273  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=18.063937
I20260812 06:18:04.774156  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.064s	user 0.042s	sys 0.020s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":28623,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:04.774650  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=2.188937
I20260812 06:18:04.790206  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5855,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.790688  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=1.000000
I20260812 06:18:04.958961  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.168s	user 0.131s	sys 0.037s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":222,"lbm_read_time_us":12894,"lbm_reads_lt_1ms":664,"lbm_write_time_us":36004,"lbm_writes_lt_1ms":643,"mutex_wait_us":51,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17024,"update_count":3000}
I20260812 06:18:04.959491  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=14.095187
I20260812 06:18:05.011660  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.052s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22423,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:05.012357  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=2.188937
I20260812 06:18:05.026399  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4942,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.026937  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=1.000000
I20260812 06:18:05.201125  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.174s	user 0.125s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":11571,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32402,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:05.201818  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=14.095187
I20260812 06:18:05.279019  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.077s	user 0.027s	sys 0.037s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":28651,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:05.279567  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=2.188937
I20260812 06:18:05.291992  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4496,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.292477  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=1.000000
I20260812 06:18:05.488554  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.196s	user 0.139s	sys 0.056s 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":1159,"lbm_read_time_us":12964,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32843,"lbm_writes_lt_1ms":543,"mutex_wait_us":332,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":2500}
I20260812 06:18:05.489197  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=14.095187
I20260812 06:18:05.553961  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.065s	user 0.039s	sys 0.022s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":23577,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:05.554574  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=2.188937
I20260812 06:18:05.566185  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4670,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.566650  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=1.000000
I20260812 06:18:05.754110  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.187s	user 0.106s	sys 0.075s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":780,"lbm_read_time_us":13065,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31912,"lbm_writes_lt_1ms":543,"mutex_wait_us":261,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2500}
I20260812 06:18:05.754863  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=14.095187
I20260812 06:18:05.810508  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.055s	user 0.043s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18908,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:05.811041  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=2.188937
I20260812 06:18:05.821622  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4248,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.822046  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushMRSOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=1.000000
I20260812 06:18:05.863759  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushMRSOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.042s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":256,"dirs.run_wall_time_us":1232,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1372,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:05.864475  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling LogGCOp(53a3996b96f64a76b9d77a0cf4ddd4de): free 112692616 bytes of WAL
I20260812 06:18:05.864763  2179 log_reader.cc:385] T 53a3996b96f64a76b9d77a0cf4ddd4de: removed 11 log segments from log reader
I20260812 06:18:05.864812  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000027 (ops 129-133)
I20260812 06:18:05.864858  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000028 (ops 134-138)
I20260812 06:18:05.864905  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000029 (ops 139-143)
I20260812 06:18:05.864946  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000030 (ops 144-148)
I20260812 06:18:05.864993  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000031 (ops 149-153)
I20260812 06:18:05.865037  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000032 (ops 154-158)
I20260812 06:18:05.865077  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000033 (ops 159-163)
I20260812 06:18:05.865118  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000034 (ops 164-168)
I20260812 06:18:05.865157  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000035 (ops 169-173)
I20260812 06:18:05.865199  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000036 (ops 174-178)
I20260812 06:18:05.865240  2179 log.cc:1079] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: Deleting log segment in path: /tmp/dist-test-taskk6cmaw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475236110-1695-0/minicluster-data/ts-0-root/wals/53a3996b96f64a76b9d77a0cf4ddd4de/wal-000000037 (ops 179-183)
I20260812 06:18:05.890246  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: LogGCOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.026s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:18:05.890796  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=2.188937
I20260812 06:18:05.914245  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.023s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6309,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.914763  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=2.188937
I20260812 06:18:05.925180  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.010s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3976,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.925634  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling UndoDeltaBlockGCOp(53a3996b96f64a76b9d77a0cf4ddd4de): 447 bytes on disk
I20260812 06:18:05.926230  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: UndoDeltaBlockGCOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":89,"lbm_reads_lt_1ms":4}
I20260812 06:18:05.927266  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=1.000000
I20260812 06:18:06.174436  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.247s	user 0.153s	sys 0.079s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979748,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":527,"lbm_read_time_us":15302,"lbm_reads_lt_1ms":774,"lbm_write_time_us":43030,"lbm_writes_lt_1ms":743,"mutex_wait_us":45,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":21248,"thread_start_us":87,"threads_started":1,"update_count":3500}
I20260812 06:18:06.175136  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=18.063937
I20260812 06:18:06.230973  1695 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.036s	user 1.841s	sys 0.176s
I20260812 06:18:06.235023  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.060s	user 0.042s	sys 0.013s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":25238,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:06.235635  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=2.188937
I20260812 06:18:06.252514  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: FlushDeltaMemStoresOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6703,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":500}
I20260812 06:18:06.253239  2286 maintenance_manager.cc:419] P 73fe78cceba841b0ad20e88205e564de: Scheduling MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de): perf score=1.000000
I20260812 06:18:06.314916  1695 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.083s	user 0.002s	sys 0.000s
I20260812 06:18:06.315537  1695 tablet_server.cc:179] TabletServer@127.1.167.193:0 shutting down...
I20260812 06:18:06.417501  2179 maintenance_manager.cc:643] P 73fe78cceba841b0ad20e88205e564de: MajorDeltaCompactionOp(53a3996b96f64a76b9d77a0cf4ddd4de) complete. Timing: real 0.164s	user 0.114s	sys 0.050s Metrics: {"cfile_cache_hit":432,"cfile_cache_hit_bytes":17682424,"cfile_cache_miss":200,"cfile_cache_miss_bytes":11194680,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":336,"lbm_read_time_us":5998,"lbm_reads_lt_1ms":232,"lbm_write_time_us":31093,"lbm_writes_lt_1ms":643,"mutex_wait_us":72,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":65792,"update_count":3000}
I20260812 06:18:06.418443  1695 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:06.418711  1695 tablet_replica.cc:333] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de: stopping tablet replica
I20260812 06:18:06.418866  1695 raft_consensus.cc:2243] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:06.419047  1695 raft_consensus.cc:2272] T 53a3996b96f64a76b9d77a0cf4ddd4de P 73fe78cceba841b0ad20e88205e564de [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:06.423553  1695 tablet_server.cc:196] TabletServer@127.1.167.193:0 shutdown complete.
I20260812 06:18:06.470614  1695 master.cc:562] Master@127.1.167.254:39919 shutting down...
I20260812 06:18:06.475196  1695 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:06.475409  1695 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:06.475533  1695 tablet_replica.cc:333] T 00000000000000000000000000000000 P 48442ddb6a1541dfb3c1e258e3a32312: stopping tablet replica
I20260812 06:18:06.489188  1695 master.cc:584] Master@127.1.167.254:39919 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5603 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11337 ms total)

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