[==========] 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:20:03.062903 27883 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.27.58.254:36973
I20260812 06:20:03.063814 27883 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:20:03.064339 27883 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:03.070356 27893 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:20:03.070441 27883 server_base.cc:1061] running on GCE node
W20260812 06:20:03.070359 27900 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:20:03.070611 27898 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:20:03.071156 27883 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:03.071260 27883 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:20:03.071303 27883 hybrid_clock.cc:648] HybridClock initialized: now 1786515603071300 us; error 0 us; skew 500 ppm
I20260812 06:20:03.072958 27883 webserver.cc:533] Webserver started at http://127.27.58.254:42877/ using document root <none> and password file <none>
I20260812 06:20:03.073510 27883 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:03.073578 27883 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:03.073802 27883 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:03.075376 27883 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/master-0-root/instance:
uuid: "2bf0e6bcf2e94c80a57cce03fb69135e"
format_stamp: "Formatted at 2026-08-12 06:20:03 on dist-test-slave-gjw7"
I20260812 06:20:03.078629 27883 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:20:03.080507 27907 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:20:03.081440 27883 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:03.081537 27883 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/master-0-root
uuid: "2bf0e6bcf2e94c80a57cce03fb69135e"
format_stamp: "Formatted at 2026-08-12 06:20:03 on dist-test-slave-gjw7"
I20260812 06:20:03.081614 27883 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-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:20:03.091091 27883 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:03.091598 27883 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:20:03.091734 27883 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:03.098824 27883 rpc_server.cc:307] RPC server started. Bound to: 127.27.58.254:36973
I20260812 06:20:03.098843 28024 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.58.254:36973 every 8 connection(s)
I20260812 06:20:03.100937 28025 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:20:03.106181 28025 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e: Bootstrap starting.
I20260812 06:20:03.108439 28025 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:03.109311 28025 log.cc:826] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:03.110908 28025 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e: No bootstrap required, opened a new log
I20260812 06:20:03.113651 28025 raft_consensus.cc:359] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2bf0e6bcf2e94c80a57cce03fb69135e" member_type: VOTER }
I20260812 06:20:03.113824 28025 raft_consensus.cc:385] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:03.113878 28025 raft_consensus.cc:740] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2bf0e6bcf2e94c80a57cce03fb69135e, State: Initialized, Role: FOLLOWER
I20260812 06:20:03.114470 28025 consensus_queue.cc:260] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e [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: "2bf0e6bcf2e94c80a57cce03fb69135e" member_type: VOTER }
I20260812 06:20:03.114615 28025 raft_consensus.cc:399] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:03.114661 28025 raft_consensus.cc:493] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:03.114755 28025 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:03.115502 28025 raft_consensus.cc:515] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2bf0e6bcf2e94c80a57cce03fb69135e" member_type: VOTER }
I20260812 06:20:03.115922 28025 leader_election.cc:304] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e [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: 2bf0e6bcf2e94c80a57cce03fb69135e; no voters: 
I20260812 06:20:03.116232 28025 leader_election.cc:290] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:03.116364 28030 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:03.116600 28030 raft_consensus.cc:697] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e [term 1 LEADER]: Becoming Leader. State: Replica: 2bf0e6bcf2e94c80a57cce03fb69135e, State: Running, Role: LEADER
I20260812 06:20:03.116972 28030 consensus_queue.cc:237] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e [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: "2bf0e6bcf2e94c80a57cce03fb69135e" member_type: VOTER }
I20260812 06:20:03.117224 28025 sys_catalog.cc:565] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:03.118774 28033 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "2bf0e6bcf2e94c80a57cce03fb69135e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2bf0e6bcf2e94c80a57cce03fb69135e" member_type: VOTER } }
I20260812 06:20:03.118834 28034 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e [sys.catalog]: SysCatalogTable state changed. Reason: New leader 2bf0e6bcf2e94c80a57cce03fb69135e. Latest consensus state: current_term: 1 leader_uuid: "2bf0e6bcf2e94c80a57cce03fb69135e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2bf0e6bcf2e94c80a57cce03fb69135e" member_type: VOTER } }
I20260812 06:20:03.118942 28034 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:03.118889 28033 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:03.119417 27883 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:03.119362 28051 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:03.121958 28051 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:03.126704 28051 catalog_manager.cc:1383] Generated new cluster ID: 41e640ef2d19443da83b0a71d70572f7
I20260812 06:20:03.126760 28051 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:03.140060 28051 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:03.140911 28051 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:03.155417 28051 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e: Generated new TSK 0
I20260812 06:20:03.156078 28051 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:03.184223 27883 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:03.187222 28065 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:20:03.187237 28067 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:20:03.187511 28072 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:20:03.187701 27883 server_base.cc:1061] running on GCE node
I20260812 06:20:03.187896 27883 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:03.187942 27883 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:20:03.187958 27883 hybrid_clock.cc:648] HybridClock initialized: now 1786515603187957 us; error 0 us; skew 500 ppm
I20260812 06:20:03.188833 27883 webserver.cc:533] Webserver started at http://127.27.58.193:37221/ using document root <none> and password file <none>
I20260812 06:20:03.189002 27883 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:03.189059 27883 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:03.189137 27883 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:03.189560 27883 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/instance:
uuid: "fa63166b3a6d4b009fe10f19effbdee5"
format_stamp: "Formatted at 2026-08-12 06:20:03 on dist-test-slave-gjw7"
I20260812 06:20:03.191023 27883 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:03.191927 28083 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:20:03.192169 27883 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:03.192240 27883 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root
uuid: "fa63166b3a6d4b009fe10f19effbdee5"
format_stamp: "Formatted at 2026-08-12 06:20:03 on dist-test-slave-gjw7"
I20260812 06:20:03.192312 27883 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-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:20:03.209261 27883 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:03.210106 27883 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:03.210577 27883 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:03.211452 27883 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:03.211513 27883 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:03.211561 27883 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:03.211591 27883 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:03.217521 27883 rpc_server.cc:307] RPC server started. Bound to: 127.27.58.193:46467
I20260812 06:20:03.217578 28208 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.58.193:46467 every 8 connection(s)
I20260812 06:20:03.230997 28209 heartbeater.cc:344] Connected to a master server at 127.27.58.254:36973
I20260812 06:20:03.231242 28209 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:03.231673 28209 heartbeater.cc:507] Master 127.27.58.254:36973 requested a full tablet report, sending...
I20260812 06:20:03.232951 27936 ts_manager.cc:194] Registered new tserver with Master: fa63166b3a6d4b009fe10f19effbdee5 (127.27.58.193:46467)
I20260812 06:20:03.233850 27883 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015712238s
I20260812 06:20:03.234126 27936 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:42044
I20260812 06:20:03.244565 27936 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:42060:
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:20:03.258423 28145 tablet_service.cc:1511] Processing CreateTablet for tablet 3559ae9bd66e4d7f9481160daf5f9543 (DEFAULT_TABLE table=heavy-update-compaction-test [id=e25d316b1e3a4704b4aa4a5de7cd228a]), partition=
I20260812 06:20:03.258837 28145 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 3559ae9bd66e4d7f9481160daf5f9543. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:03.261145 28237 tablet_bootstrap.cc:492] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Bootstrap starting.
I20260812 06:20:03.262410 28237 tablet_bootstrap.cc:654] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:03.263468 28237 tablet_bootstrap.cc:492] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: No bootstrap required, opened a new log
I20260812 06:20:03.263551 28237 ts_tablet_manager.cc:1403] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:03.264002 28237 raft_consensus.cc:359] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fa63166b3a6d4b009fe10f19effbdee5" member_type: VOTER last_known_addr { host: "127.27.58.193" port: 46467 } }
I20260812 06:20:03.264103 28237 raft_consensus.cc:385] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:03.264137 28237 raft_consensus.cc:740] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: fa63166b3a6d4b009fe10f19effbdee5, State: Initialized, Role: FOLLOWER
I20260812 06:20:03.264259 28237 consensus_queue.cc:260] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5 [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: "fa63166b3a6d4b009fe10f19effbdee5" member_type: VOTER last_known_addr { host: "127.27.58.193" port: 46467 } }
I20260812 06:20:03.264328 28237 raft_consensus.cc:399] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:03.264370 28237 raft_consensus.cc:493] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:03.264420 28237 raft_consensus.cc:3060] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:03.265081 28237 raft_consensus.cc:515] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fa63166b3a6d4b009fe10f19effbdee5" member_type: VOTER last_known_addr { host: "127.27.58.193" port: 46467 } }
I20260812 06:20:03.265221 28237 leader_election.cc:304] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5 [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: fa63166b3a6d4b009fe10f19effbdee5; no voters: 
I20260812 06:20:03.265431 28237 leader_election.cc:290] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:03.265538 28239 raft_consensus.cc:2804] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:03.265766 28237 ts_tablet_manager.cc:1434] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:03.265996 28209 heartbeater.cc:499] Master 127.27.58.254:36973 was elected leader, sending a full tablet report...
I20260812 06:20:03.265789 28239 raft_consensus.cc:697] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5 [term 1 LEADER]: Becoming Leader. State: Replica: fa63166b3a6d4b009fe10f19effbdee5, State: Running, Role: LEADER
I20260812 06:20:03.266608 28239 consensus_queue.cc:237] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5 [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: "fa63166b3a6d4b009fe10f19effbdee5" member_type: VOTER last_known_addr { host: "127.27.58.193" port: 46467 } }
I20260812 06:20:03.269415 27936 catalog_manager.cc:5719] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5 reported cstate change: term changed from 0 to 1, leader changed from <none> to fa63166b3a6d4b009fe10f19effbdee5 (127.27.58.193). New cstate: current_term: 1 leader_uuid: "fa63166b3a6d4b009fe10f19effbdee5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fa63166b3a6d4b009fe10f19effbdee5" member_type: VOTER last_known_addr { host: "127.27.58.193" port: 46467 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:03.328953 27883 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.049s	user 0.024s	sys 0.000s
I20260812 06:20:03.468679 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushMRSOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=19.054940
I20260812 06:20:03.659817 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushMRSOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.191s	user 0.137s	sys 0.051s Metrics: {"bytes_written":16491951,"cfile_init":1,"compiler_manager_pool.queue_time_us":214,"delete_count":0,"dirs.queue_time_us":42,"dirs.run_cpu_time_us":202,"dirs.run_wall_time_us":829,"drs_written":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4,"lbm_write_time_us":46593,"lbm_writes_lt_1ms":859,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":294144,"thread_start_us":121,"threads_started":1,"update_count":2010}
I20260812 06:20:03.661070 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling LogGCOp(3559ae9bd66e4d7f9481160daf5f9543): free 20743880 bytes of WAL
I20260812 06:20:03.661419 28094 log_reader.cc:385] T 3559ae9bd66e4d7f9481160daf5f9543: removed 2 log segments from log reader
I20260812 06:20:03.661500 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000001 (ops 1-6)
I20260812 06:20:03.661557 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000002 (ops 7-11)
I20260812 06:20:03.666211 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: LogGCOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.005s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:20:03.666592 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling UndoDeltaBlockGCOp(3559ae9bd66e4d7f9481160daf5f9543): 16411394 bytes on disk
I20260812 06:20:03.667290 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: UndoDeltaBlockGCOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:20:03.667794 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=4.173312
I20260812 06:20:03.684337 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":6030802,"delete_count":0,"lbm_write_time_us":6675,"lbm_writes_lt_1ms":150,"reinsert_count":0,"update_count":735}
I20260812 06:20:03.684759 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:03.690719 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.006s	user 0.002s	sys 0.003s Metrics: {"bytes_written":2092427,"delete_count":0,"lbm_write_time_us":1971,"lbm_writes_lt_1ms":54,"reinsert_count":0,"update_count":255}
I20260812 06:20:03.691083 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:03.887408 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.196s	user 0.135s	sys 0.052s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877175,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":490,"lbm_read_time_us":13879,"lbm_reads_lt_1ms":669,"lbm_write_time_us":32739,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":292,"threads_started":5,"update_count":3000}
I20260812 06:20:03.887936 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=14.095187
I20260812 06:20:03.943949 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.056s	user 0.024s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18575,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.944446 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=2.188937
I20260812 06:20:03.954417 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3676,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.954849 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:04.107007 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.152s	user 0.104s	sys 0.048s 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":149,"lbm_read_time_us":11806,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26134,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19968,"update_count":2500}
I20260812 06:20:04.107689 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=10.126437
I20260812 06:20:04.139536 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.032s	user 0.028s	sys 0.001s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13346,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:04.140020 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=2.188937
I20260812 06:20:04.161545 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.021s	user 0.009s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5829,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.162087 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:04.296190 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.134s	user 0.093s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":337,"lbm_read_time_us":9969,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21711,"lbm_writes_lt_1ms":443,"mutex_wait_us":67,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:04.296788 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=10.126437
I20260812 06:20:04.343638 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.047s	user 0.023s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15892,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:04.344156 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=2.188937
I20260812 06:20:04.359704 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5390,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.360352 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:04.479410 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.119s	user 0.094s	sys 0.024s 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":1083,"lbm_read_time_us":8440,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23096,"lbm_writes_lt_1ms":443,"mutex_wait_us":502,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2000}
I20260812 06:20:04.479947 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=10.126437
I20260812 06:20:04.511687 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.032s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13600,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:04.512220 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=2.188937
I20260812 06:20:04.522042 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3541,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.522640 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:04.634644 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.112s	user 0.093s	sys 0.018s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":871,"lbm_read_time_us":9144,"lbm_reads_lt_1ms":472,"lbm_write_time_us":19696,"lbm_writes_lt_1ms":443,"mutex_wait_us":307,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2000}
I20260812 06:20:04.635332 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=10.126437
I20260812 06:20:04.686561 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.051s	user 0.018s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14665,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:04.687186 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=2.188937
I20260812 06:20:04.701959 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5547,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.702478 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:04.842557 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.140s	user 0.100s	sys 0.040s 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":644,"lbm_read_time_us":10396,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23377,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:20:04.843009 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=10.126437
I20260812 06:20:04.874251 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.031s	user 0.025s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12602,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:04.874722 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushMRSOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:04.923106 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushMRSOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.048s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1344,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1481,"lbm_writes_lt_1ms":39,"mutex_wait_us":1,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:04.924443 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling LogGCOp(3559ae9bd66e4d7f9481160daf5f9543): free 124710304 bytes of WAL
I20260812 06:20:04.924728 28094 log_reader.cc:385] T 3559ae9bd66e4d7f9481160daf5f9543: removed 12 log segments from log reader
I20260812 06:20:04.924790 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000003 (ops 12-16)
I20260812 06:20:04.924831 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000004 (ops 17-21)
I20260812 06:20:04.924868 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000005 (ops 22-26)
I20260812 06:20:04.924898 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000006 (ops 27-31)
I20260812 06:20:04.924924 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000007 (ops 32-36)
I20260812 06:20:04.924957 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000008 (ops 37-41)
I20260812 06:20:04.924988 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000009 (ops 42-46)
I20260812 06:20:04.925014 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000010 (ops 47-51)
I20260812 06:20:04.925041 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000011 (ops 52-56)
I20260812 06:20:04.925066 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000012 (ops 57-61)
I20260812 06:20:04.925098 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000013 (ops 62-66)
I20260812 06:20:04.925130 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000014 (ops 67-71)
I20260812 06:20:04.957332 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: LogGCOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.033s	user 0.002s	sys 0.025s Metrics: {}
I20260812 06:20:04.957847 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=7.149875
I20260812 06:20:04.988150 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.030s	user 0.015s	sys 0.012s Metrics: {"bytes_written":8615324,"delete_count":0,"lbm_write_time_us":10206,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:20:04.988588 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling UndoDeltaBlockGCOp(3559ae9bd66e4d7f9481160daf5f9543): 483 bytes on disk
I20260812 06:20:04.988986 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: UndoDeltaBlockGCOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:20:04.989470 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=2.188937
I20260812 06:20:04.998505 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3330,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:04.998898 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:05.185436 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.186s	user 0.103s	sys 0.072s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877213,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":994,"lbm_read_time_us":14006,"lbm_reads_lt_1ms":673,"lbm_write_time_us":30259,"lbm_writes_lt_1ms":643,"mutex_wait_us":272,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":93,"threads_started":1,"update_count":3000}
I20260812 06:20:05.185875 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=14.095187
I20260812 06:20:05.243255 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.057s	user 0.031s	sys 0.014s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17126,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.243772 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=2.188937
I20260812 06:20:05.253697 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3714,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.254094 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:05.414461 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.160s	user 0.114s	sys 0.043s 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":302,"lbm_read_time_us":10439,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26212,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:20:05.414950 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=11.118625
I20260812 06:20:05.446060 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.031s	user 0.018s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12440,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:05.446494 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=2.188937
I20260812 06:20:05.468469 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.022s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3425,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:05.468986 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=2.188937
I20260812 06:20:05.490703 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.022s	user 0.013s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5265,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.491236 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:05.662590 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.171s	user 0.129s	sys 0.040s 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":726,"lbm_read_time_us":11979,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26901,"lbm_writes_lt_1ms":543,"mutex_wait_us":251,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:05.663043 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=11.118625
I20260812 06:20:05.699011 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.036s	user 0.030s	sys 0.004s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14868,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:05.699615 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=2.188937
I20260812 06:20:05.710615 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4007,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:05.711180 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:05.827648 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.116s	user 0.076s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":526,"lbm_read_time_us":8028,"lbm_reads_lt_1ms":464,"lbm_write_time_us":20822,"lbm_writes_lt_1ms":443,"mutex_wait_us":272,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2000}
I20260812 06:20:05.828584 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=10.126437
I20260812 06:20:05.871238 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.042s	user 0.020s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20871,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:20:05.872958 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=2.188937
I20260812 06:20:05.899778 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.027s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5550,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.900246 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=2.188937
I20260812 06:20:05.909883 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3502,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.910475 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:06.050750 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.140s	user 0.119s	sys 0.020s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774808,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":445,"lbm_read_time_us":10550,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26121,"lbm_writes_lt_1ms":543,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:06.051370 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=11.118625
I20260812 06:20:06.080837 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.029s	user 0.015s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12312,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:06.081403 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=2.188937
I20260812 06:20:06.093076 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3978,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:06.093612 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:06.216130 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.122s	user 0.100s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1007,"lbm_read_time_us":8134,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24804,"lbm_writes_lt_1ms":443,"mutex_wait_us":329,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:06.216590 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=10.126437
I20260812 06:20:06.261036 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.044s	user 0.020s	sys 0.014s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":12868,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:06.261574 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=2.188937
I20260812 06:20:06.271657 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3619,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.272218 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushMRSOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:06.305972 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushMRSOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.034s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":198,"dirs.run_wall_time_us":1234,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1278,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:06.306700 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling LogGCOp(3559ae9bd66e4d7f9481160daf5f9543): free 121006445 bytes of WAL
I20260812 06:20:06.306938 28094 log_reader.cc:385] T 3559ae9bd66e4d7f9481160daf5f9543: removed 12 log segments from log reader
I20260812 06:20:06.306996 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000015 (ops 72-76)
I20260812 06:20:06.307039 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000016 (ops 77-80)
I20260812 06:20:06.307072 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000017 (ops 81-85)
I20260812 06:20:06.307093 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000018 (ops 86-90)
I20260812 06:20:06.307121 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000019 (ops 91-95)
I20260812 06:20:06.307148 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000020 (ops 96-100)
I20260812 06:20:06.307176 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000021 (ops 101-105)
I20260812 06:20:06.307207 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000022 (ops 106-110)
I20260812 06:20:06.307235 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000023 (ops 111-115)
I20260812 06:20:06.307260 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000024 (ops 116-120)
I20260812 06:20:06.307284 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000025 (ops 121-125)
I20260812 06:20:06.307313 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000026 (ops 126-130)
I20260812 06:20:06.330756 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: LogGCOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.024s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:20:06.331195 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling UndoDeltaBlockGCOp(3559ae9bd66e4d7f9481160daf5f9543): 462 bytes on disk
I20260812 06:20:06.331704 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: UndoDeltaBlockGCOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:20:06.332250 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=3.181125
I20260812 06:20:06.351140 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.019s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4370,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:06.351527 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=2.188937
I20260812 06:20:06.360186 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3169,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:06.360563 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:06.547443 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.187s	user 0.135s	sys 0.052s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877325,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":311,"lbm_read_time_us":12629,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30791,"lbm_writes_lt_1ms":643,"mutex_wait_us":28,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:20:06.547907 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=14.095187
I20260812 06:20:06.595854 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.048s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21475,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:06.596398 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:06.732455 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.136s	user 0.117s	sys 0.017s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672156,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":90,"lbm_read_time_us":8771,"lbm_reads_lt_1ms":467,"lbm_write_time_us":20214,"lbm_writes_lt_1ms":443,"mutex_wait_us":18,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2000}
I20260812 06:20:06.733103 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=11.118625
I20260812 06:20:06.766054 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.033s	user 0.017s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13900,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:06.766538 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=2.188937
I20260812 06:20:06.779245 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4404,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:06.779816 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:06.901419 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.121s	user 0.088s	sys 0.032s 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":875,"lbm_read_time_us":9426,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21532,"lbm_writes_lt_1ms":443,"mutex_wait_us":238,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:20:06.902004 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=10.126437
I20260812 06:20:06.937927 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.036s	user 0.020s	sys 0.009s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":12303,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:06.938428 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=2.188937
I20260812 06:20:06.948992 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3847,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.949615 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:07.070461 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.121s	user 0.080s	sys 0.040s 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":268,"lbm_read_time_us":8182,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20931,"lbm_writes_lt_1ms":443,"mutex_wait_us":51,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2000}
I20260812 06:20:07.071012 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=10.126437
I20260812 06:20:07.106262 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.035s	user 0.010s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14987,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:07.106830 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:07.204273 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.097s	user 0.089s	sys 0.008s 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":1072,"lbm_read_time_us":6401,"lbm_reads_lt_1ms":363,"lbm_write_time_us":16929,"lbm_writes_lt_1ms":343,"mutex_wait_us":346,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":31872,"update_count":1500}
I20260812 06:20:07.204807 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=10.126437
I20260812 06:20:07.244920 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.040s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16343,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:07.245533 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=2.188937
I20260812 06:20:07.255980 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3680,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.256896 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:07.375855 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.118s	user 0.071s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":517,"lbm_read_time_us":7064,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24780,"lbm_writes_lt_1ms":443,"mutex_wait_us":276,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":2000}
I20260812 06:20:07.376384 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=10.126437
I20260812 06:20:07.419524 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.043s	user 0.023s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14565,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:07.420035 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=2.188937
I20260812 06:20:07.429749 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3614,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.430204 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:07.551848 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.121s	user 0.105s	sys 0.016s 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":760,"lbm_read_time_us":9778,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22117,"lbm_writes_lt_1ms":443,"mutex_wait_us":34,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2000}
I20260812 06:20:07.552362 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=10.126437
I20260812 06:20:07.583604 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.031s	user 0.020s	sys 0.009s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12891,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:07.584481 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=2.188937
I20260812 06:20:07.596107 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4072,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.596707 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushMRSOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:07.627673 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushMRSOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":184,"dirs.run_wall_time_us":1287,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1327,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:07.628312 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling LogGCOp(3559ae9bd66e4d7f9481160daf5f9543): free 115943419 bytes of WAL
I20260812 06:20:07.628526 28094 log_reader.cc:385] T 3559ae9bd66e4d7f9481160daf5f9543: removed 11 log segments from log reader
I20260812 06:20:07.628573 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000027 (ops 131-135)
I20260812 06:20:07.628604 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000028 (ops 136-140)
I20260812 06:20:07.628638 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000029 (ops 141-145)
I20260812 06:20:07.628662 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000030 (ops 146-150)
I20260812 06:20:07.628695 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000031 (ops 151-155)
I20260812 06:20:07.628728 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000032 (ops 156-160)
I20260812 06:20:07.628760 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000033 (ops 161-165)
I20260812 06:20:07.628793 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000034 (ops 166-170)
I20260812 06:20:07.628825 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000035 (ops 171-175)
I20260812 06:20:07.628857 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000036 (ops 176-180)
I20260812 06:20:07.628890 28094 log.cc:1079] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/3559ae9bd66e4d7f9481160daf5f9543/wal-000000037 (ops 181-185)
I20260812 06:20:07.649755 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: LogGCOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.021s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:20:07.650164 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling UndoDeltaBlockGCOp(3559ae9bd66e4d7f9481160daf5f9543): 462 bytes on disk
I20260812 06:20:07.650657 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: UndoDeltaBlockGCOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:20:07.651212 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=3.181125
I20260812 06:20:07.667903 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.017s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":6726,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:07.668324 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=2.188937
I20260812 06:20:07.677214 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.009s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3320,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:07.677704 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:07.852886 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.175s	user 0.129s	sys 0.037s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877325,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":195,"lbm_read_time_us":13154,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32619,"lbm_writes_lt_1ms":643,"mutex_wait_us":30,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":65536,"thread_start_us":72,"threads_started":1,"update_count":3000}
I20260812 06:20:07.853449 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=14.095187
I20260812 06:20:07.897708 27883 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.569s	user 1.672s	sys 0.149s
I20260812 06:20:07.900692 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.047s	user 0.029s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17831,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:07.901273 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=2.188937
I20260812 06:20:07.910367 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: FlushDeltaMemStoresOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3634,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.910764 28214 maintenance_manager.cc:419] P fa63166b3a6d4b009fe10f19effbdee5: Scheduling MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543): perf score=1.000000
I20260812 06:20:07.940114 27883 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.042s	user 0.001s	sys 0.000s
I20260812 06:20:07.940672 27883 tablet_server.cc:179] TabletServer@127.27.58.193:0 shutting down...
I20260812 06:20:08.012791 28094 maintenance_manager.cc:643] P fa63166b3a6d4b009fe10f19effbdee5: MajorDeltaCompactionOp(3559ae9bd66e4d7f9481160daf5f9543) complete. Timing: real 0.102s	user 0.081s	sys 0.020s Metrics: {"cfile_cache_hit":357,"cfile_cache_hit_bytes":14605285,"cfile_cache_miss":175,"cfile_cache_miss_bytes":10169405,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":695,"lbm_read_time_us":3718,"lbm_reads_lt_1ms":207,"lbm_write_time_us":21717,"lbm_writes_lt_1ms":543,"mutex_wait_us":244,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2500}
I20260812 06:20:08.013375 27883 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:08.013758 27883 tablet_replica.cc:333] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5: stopping tablet replica
I20260812 06:20:08.013981 27883 raft_consensus.cc:2243] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:08.014190 27883 raft_consensus.cc:2272] T 3559ae9bd66e4d7f9481160daf5f9543 P fa63166b3a6d4b009fe10f19effbdee5 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:08.029719 27883 tablet_server.cc:196] TabletServer@127.27.58.193:0 shutdown complete.
I20260812 06:20:08.057689 27883 master.cc:562] Master@127.27.58.254:36973 shutting down...
I20260812 06:20:08.061142 27883 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:08.061335 27883 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:08.061403 27883 tablet_replica.cc:333] T 00000000000000000000000000000000 P 2bf0e6bcf2e94c80a57cce03fb69135e: stopping tablet replica
I20260812 06:20:08.073688 27883 master.cc:584] Master@127.27.58.254:36973 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5083 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:08.154512 27883 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.27.58.254:42891
I20260812 06:20:08.154874 27883 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:08.156759 28272 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:20:08.156751 28279 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:20:08.156889 27883 server_base.cc:1061] running on GCE node
W20260812 06:20:08.156751 28274 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:20:08.157094 27883 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:08.157141 27883 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:20:08.157160 27883 hybrid_clock.cc:648] HybridClock initialized: now 1786515608157161 us; error 0 us; skew 500 ppm
I20260812 06:20:08.158048 27883 webserver.cc:533] Webserver started at http://127.27.58.254:43967/ using document root <none> and password file <none>
I20260812 06:20:08.158205 27883 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:08.158254 27883 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:08.158329 27883 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:08.158708 27883 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/master-0-root/instance:
uuid: "c42175d3e75449898d18f19765b58d7f"
format_stamp: "Formatted at 2026-08-12 06:20:08 on dist-test-slave-gjw7"
I20260812 06:20:08.160082 27883 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:08.160877 28292 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:20:08.161093 27883 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:08.161160 27883 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/master-0-root
uuid: "c42175d3e75449898d18f19765b58d7f"
format_stamp: "Formatted at 2026-08-12 06:20:08 on dist-test-slave-gjw7"
I20260812 06:20:08.161227 27883 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-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:20:08.170595 27883 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:08.170893 27883 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:08.174821 27883 rpc_server.cc:307] RPC server started. Bound to: 127.27.58.254:42891
I20260812 06:20:08.179327 28408 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.58.254:42891 every 8 connection(s)
I20260812 06:20:08.179718 28409 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:20:08.181484 28409 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f: Bootstrap starting.
I20260812 06:20:08.182235 28409 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:08.183109 28409 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f: No bootstrap required, opened a new log
I20260812 06:20:08.183460 28409 raft_consensus.cc:359] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c42175d3e75449898d18f19765b58d7f" member_type: VOTER }
I20260812 06:20:08.183542 28409 raft_consensus.cc:385] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:08.183574 28409 raft_consensus.cc:740] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c42175d3e75449898d18f19765b58d7f, State: Initialized, Role: FOLLOWER
I20260812 06:20:08.183737 28409 consensus_queue.cc:260] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f [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: "c42175d3e75449898d18f19765b58d7f" member_type: VOTER }
I20260812 06:20:08.183822 28409 raft_consensus.cc:399] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:08.183864 28409 raft_consensus.cc:493] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:08.183912 28409 raft_consensus.cc:3060] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:08.184531 28409 raft_consensus.cc:515] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c42175d3e75449898d18f19765b58d7f" member_type: VOTER }
I20260812 06:20:08.184651 28409 leader_election.cc:304] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f [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: c42175d3e75449898d18f19765b58d7f; no voters: 
I20260812 06:20:08.184824 28409 leader_election.cc:290] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:08.184898 28414 raft_consensus.cc:2804] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:08.185091 28414 raft_consensus.cc:697] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f [term 1 LEADER]: Becoming Leader. State: Replica: c42175d3e75449898d18f19765b58d7f, State: Running, Role: LEADER
I20260812 06:20:08.185238 28409 sys_catalog.cc:565] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:08.185220 28414 consensus_queue.cc:237] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f [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: "c42175d3e75449898d18f19765b58d7f" member_type: VOTER }
I20260812 06:20:08.185624 28416 sys_catalog.cc:455] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f [sys.catalog]: SysCatalogTable state changed. Reason: New leader c42175d3e75449898d18f19765b58d7f. Latest consensus state: current_term: 1 leader_uuid: "c42175d3e75449898d18f19765b58d7f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c42175d3e75449898d18f19765b58d7f" member_type: VOTER } }
I20260812 06:20:08.185611 28415 sys_catalog.cc:455] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "c42175d3e75449898d18f19765b58d7f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c42175d3e75449898d18f19765b58d7f" member_type: VOTER } }
I20260812 06:20:08.185745 28416 sys_catalog.cc:458] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:08.185817 28415 sys_catalog.cc:458] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:08.186340 28426 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:08.186960 28426 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:08.187151 27883 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:08.188618 28426 catalog_manager.cc:1383] Generated new cluster ID: 248050758435462d9713201358f47d96
I20260812 06:20:08.188664 28426 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:08.195685 28426 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:08.196184 28426 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:08.203701 28426 catalog_manager.cc:6092] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f: Generated new TSK 0
I20260812 06:20:08.203838 28426 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:08.219267 27883 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:08.220924 28454 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:20:08.221001 27883 server_base.cc:1061] running on GCE node
W20260812 06:20:08.221063 28458 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:20:08.221081 28460 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:20:08.221393 27883 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:08.221446 27883 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:20:08.221478 27883 hybrid_clock.cc:648] HybridClock initialized: now 1786515608221477 us; error 0 us; skew 500 ppm
I20260812 06:20:08.222239 27883 webserver.cc:533] Webserver started at http://127.27.58.193:38217/ using document root <none> and password file <none>
I20260812 06:20:08.222394 27883 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:08.222446 27883 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:08.222519 27883 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:08.222908 27883 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/instance:
uuid: "3ffff40066e94109b9c4819cb379828f"
format_stamp: "Formatted at 2026-08-12 06:20:08 on dist-test-slave-gjw7"
I20260812 06:20:08.224375 27883 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:08.225217 28477 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:20:08.225457 27883 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:08.225525 27883 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root
uuid: "3ffff40066e94109b9c4819cb379828f"
format_stamp: "Formatted at 2026-08-12 06:20:08 on dist-test-slave-gjw7"
I20260812 06:20:08.225593 27883 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-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:20:08.235248 27883 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:08.235560 27883 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:08.235838 27883 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:08.236287 27883 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:08.236325 27883 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:08.236367 27883 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:08.236394 27883 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:08.240530 27883 rpc_server.cc:307] RPC server started. Bound to: 127.27.58.193:35755
I20260812 06:20:08.241511 28608 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.58.193:35755 every 8 connection(s)
I20260812 06:20:08.248847 28614 heartbeater.cc:344] Connected to a master server at 127.27.58.254:42891
I20260812 06:20:08.248943 28614 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:08.249152 28614 heartbeater.cc:507] Master 127.27.58.254:42891 requested a full tablet report, sending...
I20260812 06:20:08.249773 28325 ts_manager.cc:194] Registered new tserver with Master: 3ffff40066e94109b9c4819cb379828f (127.27.58.193:35755)
I20260812 06:20:08.250123 27883 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008775618s
I20260812 06:20:08.250507 28325 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:35308
I20260812 06:20:08.256855 28325 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:35318:
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:20:08.265130 28541 tablet_service.cc:1511] Processing CreateTablet for tablet 95977988579d4e7c946cc6b43d6a1bc3 (DEFAULT_TABLE table=heavy-update-compaction-test [id=0602f45839384cecb468a7f221b6fd50]), partition=
I20260812 06:20:08.265451 28541 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 95977988579d4e7c946cc6b43d6a1bc3. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:08.267505 28631 tablet_bootstrap.cc:492] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Bootstrap starting.
I20260812 06:20:08.268308 28631 tablet_bootstrap.cc:654] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:08.269263 28631 tablet_bootstrap.cc:492] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: No bootstrap required, opened a new log
I20260812 06:20:08.269364 28631 ts_tablet_manager.cc:1403] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:08.269747 28631 raft_consensus.cc:359] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3ffff40066e94109b9c4819cb379828f" member_type: VOTER last_known_addr { host: "127.27.58.193" port: 35755 } }
I20260812 06:20:08.269848 28631 raft_consensus.cc:385] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:08.269902 28631 raft_consensus.cc:740] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3ffff40066e94109b9c4819cb379828f, State: Initialized, Role: FOLLOWER
I20260812 06:20:08.270032 28631 consensus_queue.cc:260] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f [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: "3ffff40066e94109b9c4819cb379828f" member_type: VOTER last_known_addr { host: "127.27.58.193" port: 35755 } }
I20260812 06:20:08.270125 28631 raft_consensus.cc:399] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:08.270206 28631 raft_consensus.cc:493] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:08.270260 28631 raft_consensus.cc:3060] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:08.271003 28631 raft_consensus.cc:515] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3ffff40066e94109b9c4819cb379828f" member_type: VOTER last_known_addr { host: "127.27.58.193" port: 35755 } }
I20260812 06:20:08.271127 28631 leader_election.cc:304] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f [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: 3ffff40066e94109b9c4819cb379828f; no voters: 
I20260812 06:20:08.271294 28631 leader_election.cc:290] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:08.271406 28641 raft_consensus.cc:2804] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:08.271567 28631 ts_tablet_manager.cc:1434] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:08.271607 28614 heartbeater.cc:499] Master 127.27.58.254:42891 was elected leader, sending a full tablet report...
I20260812 06:20:08.271616 28641 raft_consensus.cc:697] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f [term 1 LEADER]: Becoming Leader. State: Replica: 3ffff40066e94109b9c4819cb379828f, State: Running, Role: LEADER
I20260812 06:20:08.271778 28641 consensus_queue.cc:237] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f [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: "3ffff40066e94109b9c4819cb379828f" member_type: VOTER last_known_addr { host: "127.27.58.193" port: 35755 } }
I20260812 06:20:08.273053 28325 catalog_manager.cc:5719] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f reported cstate change: term changed from 0 to 1, leader changed from <none> to 3ffff40066e94109b9c4819cb379828f (127.27.58.193). New cstate: current_term: 1 leader_uuid: "3ffff40066e94109b9c4819cb379828f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3ffff40066e94109b9c4819cb379828f" member_type: VOTER last_known_addr { host: "127.27.58.193" port: 35755 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:08.330883 27883 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.012s	sys 0.011s
I20260812 06:20:08.491912 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushMRSOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=23.023690
I20260812 06:20:08.655494 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushMRSOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.163s	user 0.121s	sys 0.040s Metrics: {"bytes_written":12881834,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":229,"dirs.run_wall_time_us":909,"drs_written":1,"lbm_read_time_us":103,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44463,"lbm_writes_lt_1ms":871,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":4096,"update_count":1570}
I20260812 06:20:08.656248 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling LogGCOp(95977988579d4e7c946cc6b43d6a1bc3): free 20743880 bytes of WAL
I20260812 06:20:08.656484 28489 log_reader.cc:385] T 95977988579d4e7c946cc6b43d6a1bc3: removed 2 log segments from log reader
I20260812 06:20:08.656543 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000001 (ops 1-6)
I20260812 06:20:08.656649 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000002 (ops 7-11)
I20260812 06:20:08.660581 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: LogGCOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:08.660912 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=2.188937
I20260812 06:20:08.672183 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4225735,"delete_count":0,"lbm_write_time_us":4205,"lbm_writes_lt_1ms":106,"mutex_wait_us":83,"reinsert_count":0,"update_count":515}
I20260812 06:20:08.672559 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=2.188937
I20260812 06:20:08.682449 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3405230,"delete_count":0,"lbm_write_time_us":3565,"lbm_writes_lt_1ms":86,"reinsert_count":0,"update_count":415}
I20260812 06:20:08.683228 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=1.000000
I20260812 06:20:08.847671 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.164s	user 0.123s	sys 0.035s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":433,"lbm_read_time_us":12743,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27344,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7808,"thread_start_us":299,"threads_started":5,"update_count":2500}
I20260812 06:20:08.848143 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling UndoDeltaBlockGCOp(95977988579d4e7c946cc6b43d6a1bc3): 20513817 bytes on disk
I20260812 06:20:08.848539 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: UndoDeltaBlockGCOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:20:08.848976 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=14.095187
I20260812 06:20:08.892297 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.043s	user 0.023s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18834,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:08.892741 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=2.188937
I20260812 06:20:08.902141 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3477,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.902536 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=1.000000
I20260812 06:20:09.070847 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.168s	user 0.102s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":283,"lbm_read_time_us":9787,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27025,"lbm_writes_lt_1ms":543,"mutex_wait_us":84,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:09.071477 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=14.095187
I20260812 06:20:09.139406 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.068s	user 0.031s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25556,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:09.139930 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=2.188937
I20260812 06:20:09.150363 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3628,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.150910 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=1.000000
I20260812 06:20:09.314878 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.164s	user 0.108s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":325,"lbm_read_time_us":10497,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28940,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:09.315500 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=14.095187
I20260812 06:20:09.365631 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.050s	user 0.015s	sys 0.029s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":19037,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:09.366189 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=2.188937
I20260812 06:20:09.377338 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4058,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.377760 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=1.000000
I20260812 06:20:09.534760 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.157s	user 0.098s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":984,"lbm_read_time_us":11727,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24291,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:09.535413 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=14.095187
I20260812 06:20:09.586036 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.050s	user 0.026s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18327,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:09.586556 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=2.188937
I20260812 06:20:09.596397 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3795,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.596781 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=1.000000
I20260812 06:20:09.761094 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.164s	user 0.120s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1272,"lbm_read_time_us":11243,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25496,"lbm_writes_lt_1ms":543,"mutex_wait_us":285,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2500}
I20260812 06:20:09.761760 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=11.118625
I20260812 06:20:09.788451 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.026s	user 0.017s	sys 0.006s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":10949,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:09.789093 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=2.188937
I20260812 06:20:09.802531 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4288,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":450}
I20260812 06:20:09.803042 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushMRSOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=1.000000
I20260812 06:20:09.852021 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushMRSOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.049s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":203,"dirs.run_wall_time_us":1376,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1828,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:09.852910 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling LogGCOp(95977988579d4e7c946cc6b43d6a1bc3): free 120553384 bytes of WAL
I20260812 06:20:09.853170 28489 log_reader.cc:385] T 95977988579d4e7c946cc6b43d6a1bc3: removed 12 log segments from log reader
I20260812 06:20:09.853216 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000003 (ops 12-16)
I20260812 06:20:09.853245 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000004 (ops 17-21)
I20260812 06:20:09.853261 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000005 (ops 22-26)
I20260812 06:20:09.853282 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000006 (ops 27-31)
I20260812 06:20:09.853338 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000007 (ops 32-36)
I20260812 06:20:09.853358 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000008 (ops 37-40)
I20260812 06:20:09.853386 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000009 (ops 41-45)
I20260812 06:20:09.853417 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000010 (ops 46-50)
I20260812 06:20:09.853449 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000011 (ops 51-54)
I20260812 06:20:09.853480 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000012 (ops 55-59)
I20260812 06:20:09.853511 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000013 (ops 60-64)
I20260812 06:20:09.853542 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000014 (ops 65-69)
I20260812 06:20:09.876461 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: LogGCOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.023s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:20:09.876871 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=6.157687
I20260812 06:20:09.902979 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.026s	user 0.020s	sys 0.003s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":10189,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:09.903525 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling UndoDeltaBlockGCOp(95977988579d4e7c946cc6b43d6a1bc3): 472 bytes on disk
I20260812 06:20:09.903996 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: UndoDeltaBlockGCOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:20:09.904520 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=1.000000
I20260812 06:20:10.100620 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.196s	user 0.148s	sys 0.043s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918207,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":908,"lbm_read_time_us":13351,"lbm_reads_lt_1ms":665,"lbm_write_time_us":31820,"lbm_writes_lt_1ms":643,"mutex_wait_us":44,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16896,"thread_start_us":85,"threads_started":1,"update_count":3000}
I20260812 06:20:10.101186 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=15.087375
I20260812 06:20:10.149061 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.048s	user 0.025s	sys 0.019s Metrics: {"bytes_written":16820140,"delete_count":0,"lbm_write_time_us":20730,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:10.149576 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=2.188937
I20260812 06:20:10.169246 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.018s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3602,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:10.169798 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=2.188937
I20260812 06:20:10.183938 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.014s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5159,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.184397 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=1.000000
I20260812 06:20:10.391254 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.207s	user 0.120s	sys 0.080s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918199,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":538,"lbm_read_time_us":13631,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33405,"lbm_writes_lt_1ms":643,"mutex_wait_us":248,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:20:10.391795 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=18.063937
I20260812 06:20:10.454849 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.063s	user 0.030s	sys 0.028s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":28330,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:20:10.455323 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=2.188937
I20260812 06:20:10.465756 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3631,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.466256 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=1.000000
I20260812 06:20:10.652892 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.186s	user 0.138s	sys 0.048s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":294,"lbm_read_time_us":13202,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31404,"lbm_writes_lt_1ms":643,"mutex_wait_us":34,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":3000}
I20260812 06:20:10.653481 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=14.095187
I20260812 06:20:10.709264 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.056s	user 0.017s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19715,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:10.709766 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=2.188937
I20260812 06:20:10.720439 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3895,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.721043 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=1.000000
I20260812 06:20:10.891500 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.170s	user 0.117s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":242,"lbm_read_time_us":12560,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25966,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:20:10.891963 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=14.095187
I20260812 06:20:10.944324 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.052s	user 0.024s	sys 0.019s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17004,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:10.944847 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=2.188937
I20260812 06:20:10.954766 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3717,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.955265 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=1.000000
I20260812 06:20:11.117552 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.162s	user 0.100s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":309,"lbm_read_time_us":11575,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25511,"lbm_writes_lt_1ms":543,"mutex_wait_us":64,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:20:11.118186 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=14.095187
I20260812 06:20:11.178263 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.060s	user 0.036s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21842,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:11.178694 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=2.188937
I20260812 06:20:11.188520 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3719,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.188915 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushMRSOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=1.000000
I20260812 06:20:11.217793 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushMRSOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.029s	user 0.022s	sys 0.004s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":36,"dirs.run_cpu_time_us":176,"dirs.run_wall_time_us":1255,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1703,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:11.218467 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=1.000000
I20260812 06:20:11.386778 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.168s	user 0.105s	sys 0.062s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":458,"lbm_read_time_us":12117,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26325,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:11.387377 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling LogGCOp(95977988579d4e7c946cc6b43d6a1bc3): free 120553329 bytes of WAL
I20260812 06:20:11.387657 28489 log_reader.cc:385] T 95977988579d4e7c946cc6b43d6a1bc3: removed 12 log segments from log reader
I20260812 06:20:11.387715 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000015 (ops 70-74)
I20260812 06:20:11.387751 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000016 (ops 75-78)
I20260812 06:20:11.387773 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000017 (ops 79-83)
I20260812 06:20:11.387826 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000018 (ops 84-88)
I20260812 06:20:11.387858 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000019 (ops 89-93)
I20260812 06:20:11.387879 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000020 (ops 94-98)
I20260812 06:20:11.387931 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000021 (ops 99-102)
I20260812 06:20:11.387965 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000022 (ops 103-107)
I20260812 06:20:11.388010 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000023 (ops 108-112)
I20260812 06:20:11.388038 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000024 (ops 113-117)
I20260812 06:20:11.388087 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000025 (ops 118-122)
I20260812 06:20:11.388128 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000026 (ops 123-127)
I20260812 06:20:11.408670 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: LogGCOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.021s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:20:11.409072 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=18.063937
I20260812 06:20:11.470148 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.061s	user 0.037s	sys 0.023s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":23909,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:11.470638 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=2.188937
I20260812 06:20:11.485201 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.014s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4808,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.485688 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=1.000000
I20260812 06:20:11.670333 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.184s	user 0.134s	sys 0.050s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":126,"lbm_read_time_us":12665,"lbm_reads_lt_1ms":668,"lbm_write_time_us":30497,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":3000}
I20260812 06:20:11.670992 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling UndoDeltaBlockGCOp(95977988579d4e7c946cc6b43d6a1bc3): 448 bytes on disk
I20260812 06:20:11.671556 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: UndoDeltaBlockGCOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:20:11.672201 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=15.087375
I20260812 06:20:11.720093 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.048s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":20000,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2050}
I20260812 06:20:11.720525 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=2.188937
I20260812 06:20:11.741163 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.020s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4904,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:11.741655 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=2.188937
I20260812 06:20:11.755754 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.014s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5107,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.756273 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=1.000000
I20260812 06:20:11.941424 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.185s	user 0.118s	sys 0.067s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918202,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":235,"lbm_read_time_us":12477,"lbm_reads_lt_1ms":673,"lbm_write_time_us":29708,"lbm_writes_lt_1ms":643,"mutex_wait_us":19,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":3000}
I20260812 06:20:11.942183 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=14.095187
I20260812 06:20:11.979482 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.037s	user 0.019s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":16009,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:11.980108 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=2.188937
I20260812 06:20:11.993583 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4273,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.994292 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=1.000000
I20260812 06:20:12.157119 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.163s	user 0.115s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":271,"lbm_read_time_us":11230,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28558,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2500}
I20260812 06:20:12.157670 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=14.095187
I20260812 06:20:12.201853 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.044s	user 0.030s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18039,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:12.202359 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=2.188937
I20260812 06:20:12.212096 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3703,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.212630 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=1.000000
I20260812 06:20:12.376884 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.164s	user 0.118s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":233,"lbm_read_time_us":11451,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27923,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:12.377437 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=14.095187
I20260812 06:20:12.434466 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.057s	user 0.028s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19850,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:12.434955 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=2.188937
I20260812 06:20:12.444998 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3698,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.445467 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=1.000000
I20260812 06:20:12.601562 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.156s	user 0.119s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":138,"lbm_read_time_us":10921,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25424,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":68096,"update_count":2500}
I20260812 06:20:12.602550 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=10.126437
I20260812 06:20:12.635469 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.033s	user 0.031s	sys 0.000s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13588,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:12.636098 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=2.188937
I20260812 06:20:12.652051 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5542,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.652545 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushMRSOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=1.000000
I20260812 06:20:12.696254 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushMRSOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.044s	user 0.024s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":49,"dirs.run_cpu_time_us":182,"dirs.run_wall_time_us":1299,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2336,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:12.697131 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=3.181125
I20260812 06:20:12.710901 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.014s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4348804,"delete_count":0,"lbm_write_time_us":4153,"lbm_writes_lt_1ms":109,"reinsert_count":0,"update_count":530}
I20260812 06:20:12.711478 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling LogGCOp(95977988579d4e7c946cc6b43d6a1bc3): free 133024640 bytes of WAL
I20260812 06:20:12.711742 28489 log_reader.cc:385] T 95977988579d4e7c946cc6b43d6a1bc3: removed 13 log segments from log reader
I20260812 06:20:12.711795 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000027 (ops 128-132)
I20260812 06:20:12.711834 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000028 (ops 133-137)
I20260812 06:20:12.711867 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000029 (ops 138-142)
I20260812 06:20:12.711894 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000030 (ops 143-146)
I20260812 06:20:12.711925 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000031 (ops 147-151)
I20260812 06:20:12.711954 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000032 (ops 152-156)
I20260812 06:20:12.711984 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000033 (ops 157-161)
I20260812 06:20:12.712014 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000034 (ops 162-166)
I20260812 06:20:12.712045 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000035 (ops 167-171)
I20260812 06:20:12.712074 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000036 (ops 172-176)
I20260812 06:20:12.712105 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000037 (ops 177-181)
I20260812 06:20:12.712134 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000038 (ops 182-186)
I20260812 06:20:12.712165 28489 log.cc:1079] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: Deleting log segment in path: /tmp/dist-test-tasktLhNea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603052787-27883-0/minicluster-data/ts-0-root/wals/95977988579d4e7c946cc6b43d6a1bc3/wal-000000039 (ops 187-191)
I20260812 06:20:12.735399 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: LogGCOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.024s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:20:12.735857 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=3.181125
I20260812 06:20:12.756155 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.020s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4266759,"delete_count":0,"lbm_write_time_us":5675,"lbm_writes_lt_1ms":107,"reinsert_count":0,"update_count":520}
I20260812 06:20:12.756615 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=2.188937
I20260812 06:20:12.765913 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3413,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:12.766535 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling UndoDeltaBlockGCOp(95977988579d4e7c946cc6b43d6a1bc3): 492 bytes on disk
I20260812 06:20:12.766985 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: UndoDeltaBlockGCOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:20:12.767726 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=1.000000
I20260812 06:20:12.896059 27883 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.565s	user 1.682s	sys 0.161s
I20260812 06:20:12.972952 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: MajorDeltaCompactionOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.205s	user 0.115s	sys 0.087s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020855,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":9047,"lbm_read_time_us":15398,"lbm_reads_lt_1ms":771,"lbm_write_time_us":31554,"lbm_writes_lt_1ms":743,"mutex_wait_us":2798,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4736,"thread_start_us":89,"threads_started":1,"update_count":3500}
I20260812 06:20:12.973654 28615 maintenance_manager.cc:419] P 3ffff40066e94109b9c4819cb379828f: Scheduling FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3): perf score=10.126437
I20260812 06:20:12.985267 27883 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.089s	user 0.001s	sys 0.000s
I20260812 06:20:12.985826 27883 tablet_server.cc:179] TabletServer@127.27.58.193:0 shutting down...
I20260812 06:20:13.002902 28489 maintenance_manager.cc:643] P 3ffff40066e94109b9c4819cb379828f: FlushDeltaMemStoresOp(95977988579d4e7c946cc6b43d6a1bc3) complete. Timing: real 0.029s	user 0.015s	sys 0.013s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":12495,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:13.003445 27883 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:13.003665 27883 tablet_replica.cc:333] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f: stopping tablet replica
I20260812 06:20:13.003813 27883 raft_consensus.cc:2243] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:13.003983 27883 raft_consensus.cc:2272] T 95977988579d4e7c946cc6b43d6a1bc3 P 3ffff40066e94109b9c4819cb379828f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:13.017459 27883 tablet_server.cc:196] TabletServer@127.27.58.193:0 shutdown complete.
I20260812 06:20:13.024586 27883 master.cc:562] Master@127.27.58.254:42891 shutting down...
I20260812 06:20:13.027297 27883 raft_consensus.cc:2243] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:13.027467 27883 raft_consensus.cc:2272] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:13.027530 27883 tablet_replica.cc:333] T 00000000000000000000000000000000 P c42175d3e75449898d18f19765b58d7f: stopping tablet replica
I20260812 06:20:13.039522 27883 master.cc:584] Master@127.27.58.254:42891 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4964 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10049 ms total)

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