[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:50.793058 10216 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.9.250.62:34509
I20260812 06:19:50.794009 10216 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:50.794561 10216 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:50.800503 10227 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:50.800625 10216 server_base.cc:1061] running on GCE node
W20260812 06:19:50.800530 10230 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:19:50.800765 10225 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:50.801229 10216 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:50.801327 10216 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:50.801368 10216 hybrid_clock.cc:648] HybridClock initialized: now 1786515590801365 us; error 0 us; skew 500 ppm
I20260812 06:19:50.802997 10216 webserver.cc:533] Webserver started at http://127.9.250.62:46445/ using document root <none> and password file <none>
I20260812 06:19:50.803500 10216 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:50.803565 10216 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:50.803831 10216 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:50.805461 10216 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/master-0-root/instance:
uuid: "996ec68489e14c919b0bc2a53609d2e1"
format_stamp: "Formatted at 2026-08-12 06:19:50 on dist-test-slave-nj21"
I20260812 06:19:50.808840 10216 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:19:50.810802 10245 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:50.811815 10216 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:50.811918 10216 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/master-0-root
uuid: "996ec68489e14c919b0bc2a53609d2e1"
format_stamp: "Formatted at 2026-08-12 06:19:50 on dist-test-slave-nj21"
I20260812 06:19:50.812005 10216 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:50.824389 10216 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:50.824952 10216 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:50.825098 10216 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:50.832291 10216 rpc_server.cc:307] RPC server started. Bound to: 127.9.250.62:34509
I20260812 06:19:50.832291 10345 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.9.250.62:34509 every 8 connection(s)
I20260812 06:19:50.834448 10346 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:50.839738 10346 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1: Bootstrap starting.
I20260812 06:19:50.842015 10346 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:50.842900 10346 log.cc:826] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:50.844554 10346 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1: No bootstrap required, opened a new log
I20260812 06:19:50.847249 10346 raft_consensus.cc:359] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "996ec68489e14c919b0bc2a53609d2e1" member_type: VOTER }
I20260812 06:19:50.847419 10346 raft_consensus.cc:385] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:50.847481 10346 raft_consensus.cc:740] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 996ec68489e14c919b0bc2a53609d2e1, State: Initialized, Role: FOLLOWER
I20260812 06:19:50.848089 10346 consensus_queue.cc:260] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1 [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: "996ec68489e14c919b0bc2a53609d2e1" member_type: VOTER }
I20260812 06:19:50.848244 10346 raft_consensus.cc:399] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:50.848320 10346 raft_consensus.cc:493] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:50.848448 10346 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:50.849189 10346 raft_consensus.cc:515] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "996ec68489e14c919b0bc2a53609d2e1" member_type: VOTER }
I20260812 06:19:50.849659 10346 leader_election.cc:304] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1 [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: 996ec68489e14c919b0bc2a53609d2e1; no voters: 
I20260812 06:19:50.849977 10346 leader_election.cc:290] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:50.850183 10350 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:50.850495 10350 raft_consensus.cc:697] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1 [term 1 LEADER]: Becoming Leader. State: Replica: 996ec68489e14c919b0bc2a53609d2e1, State: Running, Role: LEADER
I20260812 06:19:50.850965 10350 consensus_queue.cc:237] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1 [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: "996ec68489e14c919b0bc2a53609d2e1" member_type: VOTER }
I20260812 06:19:50.851020 10346 sys_catalog.cc:565] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:50.853022 10352 sys_catalog.cc:455] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "996ec68489e14c919b0bc2a53609d2e1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "996ec68489e14c919b0bc2a53609d2e1" member_type: VOTER } }
I20260812 06:19:50.853145 10352 sys_catalog.cc:458] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:50.853453 10216 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:50.853490 10376 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:50.853468 10353 sys_catalog.cc:455] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 996ec68489e14c919b0bc2a53609d2e1. Latest consensus state: current_term: 1 leader_uuid: "996ec68489e14c919b0bc2a53609d2e1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "996ec68489e14c919b0bc2a53609d2e1" member_type: VOTER } }
I20260812 06:19:50.853565 10353 sys_catalog.cc:458] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:50.855713 10376 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:50.860169 10376 catalog_manager.cc:1383] Generated new cluster ID: 88eca9bdb88d42209685952b7da23eb5
I20260812 06:19:50.860234 10376 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:50.866899 10376 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:50.868036 10376 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:50.880479 10376 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1: Generated new TSK 0
I20260812 06:19:50.881223 10376 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:50.885854 10216 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:50.888271 10384 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:50.888377 10386 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:50.888542 10388 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:50.888551 10216 server_base.cc:1061] running on GCE node
I20260812 06:19:50.888796 10216 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:50.888836 10216 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:50.888850 10216 hybrid_clock.cc:648] HybridClock initialized: now 1786515590888851 us; error 0 us; skew 500 ppm
I20260812 06:19:50.889657 10216 webserver.cc:533] Webserver started at http://127.9.250.1:40597/ using document root <none> and password file <none>
I20260812 06:19:50.889811 10216 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:50.889855 10216 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:50.889957 10216 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:50.890419 10216 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/instance:
uuid: "15a1234d554042e291720b7e5b11989f"
format_stamp: "Formatted at 2026-08-12 06:19:50 on dist-test-slave-nj21"
I20260812 06:19:50.892035 10216 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:50.893114 10400 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:50.893391 10216 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:50.893471 10216 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root
uuid: "15a1234d554042e291720b7e5b11989f"
format_stamp: "Formatted at 2026-08-12 06:19:50 on dist-test-slave-nj21"
I20260812 06:19:50.893548 10216 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:50.908178 10216 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:50.908975 10216 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:50.909457 10216 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:50.910308 10216 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:50.910359 10216 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:50.910406 10216 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:50.910437 10216 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:50.916630 10216 rpc_server.cc:307] RPC server started. Bound to: 127.9.250.1:36339
I20260812 06:19:50.916673 10504 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.9.250.1:36339 every 8 connection(s)
I20260812 06:19:50.926198 10507 heartbeater.cc:344] Connected to a master server at 127.9.250.62:34509
I20260812 06:19:50.926427 10507 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:50.926822 10507 heartbeater.cc:507] Master 127.9.250.62:34509 requested a full tablet report, sending...
I20260812 06:19:50.928190 10272 ts_manager.cc:194] Registered new tserver with Master: 15a1234d554042e291720b7e5b11989f (127.9.250.1:36339)
I20260812 06:19:50.928335 10216 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011121772s
I20260812 06:19:50.929658 10272 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:53738
I20260812 06:19:50.937424 10272 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:53740:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:50.950810 10444 tablet_service.cc:1511] Processing CreateTablet for tablet a5e38d548b984a71a1b2032a6249a42d (DEFAULT_TABLE table=heavy-update-compaction-test [id=107ab60977f646f8a395bc006ddb245b]), partition=
I20260812 06:19:50.951272 10444 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet a5e38d548b984a71a1b2032a6249a42d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:50.953575 10527 tablet_bootstrap.cc:492] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Bootstrap starting.
I20260812 06:19:50.954685 10527 tablet_bootstrap.cc:654] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:50.955796 10527 tablet_bootstrap.cc:492] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: No bootstrap required, opened a new log
I20260812 06:19:50.955916 10527 ts_tablet_manager.cc:1403] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:50.956279 10527 raft_consensus.cc:359] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "15a1234d554042e291720b7e5b11989f" member_type: VOTER last_known_addr { host: "127.9.250.1" port: 36339 } }
I20260812 06:19:50.956382 10527 raft_consensus.cc:385] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:50.956414 10527 raft_consensus.cc:740] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 15a1234d554042e291720b7e5b11989f, State: Initialized, Role: FOLLOWER
I20260812 06:19:50.956548 10527 consensus_queue.cc:260] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f [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: "15a1234d554042e291720b7e5b11989f" member_type: VOTER last_known_addr { host: "127.9.250.1" port: 36339 } }
I20260812 06:19:50.956640 10527 raft_consensus.cc:399] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:50.956683 10527 raft_consensus.cc:493] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:50.956732 10527 raft_consensus.cc:3060] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:50.957386 10527 raft_consensus.cc:515] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "15a1234d554042e291720b7e5b11989f" member_type: VOTER last_known_addr { host: "127.9.250.1" port: 36339 } }
I20260812 06:19:50.957517 10527 leader_election.cc:304] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f [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: 15a1234d554042e291720b7e5b11989f; no voters: 
I20260812 06:19:50.957697 10527 leader_election.cc:290] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:50.957804 10529 raft_consensus.cc:2804] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:50.958002 10529 raft_consensus.cc:697] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f [term 1 LEADER]: Becoming Leader. State: Replica: 15a1234d554042e291720b7e5b11989f, State: Running, Role: LEADER
I20260812 06:19:50.958139 10527 ts_tablet_manager.cc:1434] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:50.958179 10529 consensus_queue.cc:237] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f [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: "15a1234d554042e291720b7e5b11989f" member_type: VOTER last_known_addr { host: "127.9.250.1" port: 36339 } }
I20260812 06:19:50.958590 10507 heartbeater.cc:499] Master 127.9.250.62:34509 was elected leader, sending a full tablet report...
I20260812 06:19:50.961010 10272 catalog_manager.cc:5719] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f reported cstate change: term changed from 0 to 1, leader changed from <none> to 15a1234d554042e291720b7e5b11989f (127.9.250.1). New cstate: current_term: 1 leader_uuid: "15a1234d554042e291720b7e5b11989f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "15a1234d554042e291720b7e5b11989f" member_type: VOTER last_known_addr { host: "127.9.250.1" port: 36339 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:51.025915 10216 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.022s	sys 0.004s
I20260812 06:19:51.167757 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushMRSOp(a5e38d548b984a71a1b2032a6249a42d): perf score=19.054940
I20260812 06:19:51.317916 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushMRSOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.150s	user 0.099s	sys 0.041s Metrics: {"bytes_written":12307492,"cfile_init":1,"compiler_manager_pool.queue_time_us":204,"delete_count":0,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":203,"dirs.run_wall_time_us":754,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36516,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":110,"threads_started":1,"update_count":1500}
I20260812 06:19:51.318866 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling LogGCOp(a5e38d548b984a71a1b2032a6249a42d): free 20743880 bytes of WAL
I20260812 06:19:51.319139 10406 log_reader.cc:385] T a5e38d548b984a71a1b2032a6249a42d: removed 2 log segments from log reader
I20260812 06:19:51.319195 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000001 (ops 1-6)
I20260812 06:19:51.319249 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000002 (ops 7-11)
I20260812 06:19:51.322631 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: LogGCOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:51.322906 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling UndoDeltaBlockGCOp(a5e38d548b984a71a1b2032a6249a42d): 16411394 bytes on disk
I20260812 06:19:51.323405 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: UndoDeltaBlockGCOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:19:51.323781 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:51.339071 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.015s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5158,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.339484 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d): perf score=1.000000
I20260812 06:19:51.476146 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.137s	user 0.091s	sys 0.038s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":573,"lbm_read_time_us":6897,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24779,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"thread_start_us":247,"threads_started":5,"update_count":2000}
I20260812 06:19:51.476872 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=10.126437
I20260812 06:19:51.524385 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.047s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15930,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.524821 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:51.535298 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3707,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.535887 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d): perf score=1.000000
I20260812 06:19:51.655514 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.119s	user 0.099s	sys 0.021s 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":251,"lbm_read_time_us":7286,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22998,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16000,"update_count":2000}
I20260812 06:19:51.656047 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=10.126437
I20260812 06:19:51.688815 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.033s	user 0.016s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14107,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.689251 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:51.700109 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4023,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.700615 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d): perf score=1.000000
I20260812 06:19:51.811439 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.111s	user 0.086s	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":151,"lbm_read_time_us":7658,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20227,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:19:51.811929 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=10.126437
I20260812 06:19:51.861567 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.050s	user 0.013s	sys 0.030s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16198,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.862062 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:51.877593 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5806,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.878170 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d): perf score=1.000000
I20260812 06:19:52.029805 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.151s	user 0.121s	sys 0.027s 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":284,"lbm_read_time_us":10003,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26403,"lbm_writes_lt_1ms":443,"mutex_wait_us":95,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:52.030362 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=10.126437
I20260812 06:19:52.074311 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.044s	user 0.024s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13030,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:52.074797 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:52.084774 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3688,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.085285 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d): perf score=1.000000
I20260812 06:19:52.202795 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.117s	user 0.105s	sys 0.012s 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":517,"lbm_read_time_us":7805,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22823,"lbm_writes_lt_1ms":443,"mutex_wait_us":274,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":2000}
I20260812 06:19:52.203349 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=10.126437
I20260812 06:19:52.239208 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.036s	user 0.016s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14029,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:52.239727 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:52.249629 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3690,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.250061 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d): perf score=1.000000
I20260812 06:19:52.368079 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.118s	user 0.098s	sys 0.020s 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":110,"lbm_read_time_us":7760,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22810,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":46080,"update_count":2000}
I20260812 06:19:52.368564 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=10.126437
I20260812 06:19:52.411418 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.043s	user 0.030s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15507,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:52.411962 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:52.422008 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3846,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.422397 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushMRSOp(a5e38d548b984a71a1b2032a6249a42d): perf score=1.000000
I20260812 06:19:52.462386 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushMRSOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.040s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":102,"dirs.run_cpu_time_us":209,"dirs.run_wall_time_us":1088,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1313,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:52.463198 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling LogGCOp(a5e38d548b984a71a1b2032a6249a42d): free 112692367 bytes of WAL
I20260812 06:19:52.463423 10406 log_reader.cc:385] T a5e38d548b984a71a1b2032a6249a42d: removed 11 log segments from log reader
I20260812 06:19:52.463469 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000003 (ops 12-16)
I20260812 06:19:52.463498 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000004 (ops 17-21)
I20260812 06:19:52.463531 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000005 (ops 22-26)
I20260812 06:19:52.463562 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000006 (ops 27-31)
I20260812 06:19:52.463593 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000007 (ops 32-36)
I20260812 06:19:52.463625 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000008 (ops 37-41)
I20260812 06:19:52.463657 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000009 (ops 42-46)
I20260812 06:19:52.463711 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000010 (ops 47-51)
I20260812 06:19:52.463742 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000011 (ops 52-56)
I20260812 06:19:52.463774 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000012 (ops 57-61)
I20260812 06:19:52.463805 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000013 (ops 62-66)
I20260812 06:19:52.482239 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: LogGCOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.019s	user 0.000s	sys 0.016s Metrics: {}
I20260812 06:19:52.482623 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=3.181125
I20260812 06:19:52.506800 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.024s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5980,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:52.507287 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:52.516284 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3119,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:52.516865 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling UndoDeltaBlockGCOp(a5e38d548b984a71a1b2032a6249a42d): 447 bytes on disk
I20260812 06:19:52.517344 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: UndoDeltaBlockGCOp(a5e38d548b984a71a1b2032a6249a42d) 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:19:52.517845 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d): perf score=1.000000
I20260812 06:19:52.694949 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.177s	user 0.117s	sys 0.060s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":255,"lbm_read_time_us":11254,"lbm_reads_lt_1ms":674,"lbm_write_time_us":29488,"lbm_writes_lt_1ms":643,"mutex_wait_us":26,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6784,"thread_start_us":75,"threads_started":1,"update_count":3000}
I20260812 06:19:52.695459 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=14.095187
I20260812 06:19:52.738987 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.043s	user 0.031s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17806,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:52.739495 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d): perf score=1.000000
I20260812 06:19:52.880878 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.141s	user 0.113s	sys 0.028s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":102,"lbm_read_time_us":9985,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24192,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":59136,"update_count":2000}
I20260812 06:19:52.881362 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=10.126437
I20260812 06:19:52.915629 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.034s	user 0.023s	sys 0.007s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14352,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:52.916218 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:52.934082 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.018s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6349,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.934608 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d): perf score=1.000000
I20260812 06:19:53.058872 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.124s	user 0.095s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":279,"lbm_read_time_us":7702,"lbm_reads_lt_1ms":468,"lbm_write_time_us":24998,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:19:53.059553 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=10.126437
I20260812 06:19:53.089362 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.030s	user 0.023s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12326,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:53.089846 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:53.100934 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4160,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.101441 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d): perf score=1.000000
I20260812 06:19:53.214610 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.113s	user 0.105s	sys 0.008s 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":769,"lbm_read_time_us":7817,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20253,"lbm_writes_lt_1ms":443,"mutex_wait_us":346,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:19:53.215315 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=10.126437
I20260812 06:19:53.255505 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.040s	user 0.027s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14477,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:53.256026 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:53.265880 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3591,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.266321 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d): perf score=1.000000
I20260812 06:19:53.382673 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.116s	user 0.094s	sys 0.021s 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":109,"lbm_read_time_us":9059,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21576,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":62080,"update_count":2000}
I20260812 06:19:53.383363 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=10.126437
I20260812 06:19:53.436177 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.053s	user 0.027s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14816,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:53.436779 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:53.451663 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5680,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.452175 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d): perf score=1.000000
I20260812 06:19:53.596457 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.144s	user 0.100s	sys 0.044s 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":199,"lbm_read_time_us":10727,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23716,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":54272,"update_count":2000}
I20260812 06:19:53.597084 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=10.126437
I20260812 06:19:53.635113 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.038s	user 0.013s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13540,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:53.635658 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:53.645709 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3682,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.646432 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d): perf score=1.000000
I20260812 06:19:53.769798 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.123s	user 0.107s	sys 0.016s 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":637,"lbm_read_time_us":9089,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22328,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2000}
I20260812 06:19:53.770428 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=10.126437
I20260812 06:19:53.812093 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.041s	user 0.015s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14534,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:53.812582 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:53.827787 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.015s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5468,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.828311 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushMRSOp(a5e38d548b984a71a1b2032a6249a42d): perf score=1.000000
I20260812 06:19:53.856353 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushMRSOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.028s	user 0.024s	sys 0.001s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":225,"dirs.run_wall_time_us":1107,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1453,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:53.857187 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling LogGCOp(a5e38d548b984a71a1b2032a6249a42d): free 124710298 bytes of WAL
I20260812 06:19:53.857437 10406 log_reader.cc:385] T a5e38d548b984a71a1b2032a6249a42d: removed 12 log segments from log reader
I20260812 06:19:53.857497 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000014 (ops 67-71)
I20260812 06:19:53.857544 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000015 (ops 72-76)
I20260812 06:19:53.857579 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000016 (ops 77-81)
I20260812 06:19:53.857609 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000017 (ops 82-86)
I20260812 06:19:53.857637 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000018 (ops 87-91)
I20260812 06:19:53.857668 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000019 (ops 92-96)
I20260812 06:19:53.857700 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000020 (ops 97-101)
I20260812 06:19:53.857728 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000021 (ops 102-106)
I20260812 06:19:53.857755 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000022 (ops 107-111)
I20260812 06:19:53.857782 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000023 (ops 112-116)
I20260812 06:19:53.857811 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000024 (ops 117-121)
I20260812 06:19:53.857844 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000025 (ops 122-126)
I20260812 06:19:53.883451 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: LogGCOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.026s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:19:53.883870 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=3.181125
I20260812 06:19:53.898120 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.014s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4056,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:53.898622 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:53.909322 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3802,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:53.909904 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d): perf score=1.000000
I20260812 06:19:54.072300 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.162s	user 0.131s	sys 0.031s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":462,"lbm_read_time_us":10970,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31366,"lbm_writes_lt_1ms":643,"mutex_wait_us":62,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2560,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:19:54.072855 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling UndoDeltaBlockGCOp(a5e38d548b984a71a1b2032a6249a42d): 472 bytes on disk
I20260812 06:19:54.073274 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: UndoDeltaBlockGCOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:19:54.073861 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=14.095187
I20260812 06:19:54.119545 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.046s	user 0.017s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17464,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.120100 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:54.135468 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.015s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5883,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.136032 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d): perf score=1.000000
I20260812 06:19:54.279100 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.143s	user 0.106s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":241,"lbm_read_time_us":8774,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27310,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2500}
I20260812 06:19:54.280092 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=12.110812
I20260812 06:19:54.331661 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.051s	user 0.030s	sys 0.017s Metrics: {"bytes_written":13538210,"delete_count":0,"lbm_write_time_us":23725,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":330,"reinsert_count":0,"update_count":1650}
I20260812 06:19:54.332142 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:54.342981 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.011s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3282159,"delete_count":0,"lbm_write_time_us":3059,"lbm_writes_lt_1ms":83,"reinsert_count":0,"update_count":400}
I20260812 06:19:54.343390 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:54.352384 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3213,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:54.352787 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d): perf score=1.000000
I20260812 06:19:54.515285 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.162s	user 0.111s	sys 0.048s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774774,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":548,"lbm_read_time_us":12820,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26874,"lbm_writes_lt_1ms":543,"mutex_wait_us":283,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:19:54.515955 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=14.095187
I20260812 06:19:54.570155 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.054s	user 0.023s	sys 0.021s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20698,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.570675 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:54.581328 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4006,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.581722 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d): perf score=1.000000
I20260812 06:19:54.742033 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.160s	user 0.106s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1118,"lbm_read_time_us":11342,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26947,"lbm_writes_lt_1ms":543,"mutex_wait_us":329,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:19:54.742606 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=14.095187
I20260812 06:19:54.800719 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.058s	user 0.029s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21817,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.801321 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:54.811713 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3843,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.812247 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d): perf score=1.000000
I20260812 06:19:54.977365 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.165s	user 0.100s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":163,"lbm_read_time_us":11436,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27980,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:54.978050 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=11.118625
I20260812 06:19:55.014091 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.036s	user 0.028s	sys 0.005s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15073,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:55.015429 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:55.042520 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.027s	user 0.002s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4935,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:55.043031 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:55.053696 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3958,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.054212 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d): perf score=1.000000
I20260812 06:19:55.230131 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.176s	user 0.113s	sys 0.056s 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":109,"lbm_read_time_us":10410,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28994,"lbm_writes_lt_1ms":543,"mutex_wait_us":19,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2500}
I20260812 06:19:55.230681 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=14.095187
I20260812 06:19:55.273176 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.042s	user 0.018s	sys 0.020s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":16836,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.273734 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:55.290985 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.017s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3888,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.291690 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushMRSOp(a5e38d548b984a71a1b2032a6249a42d): perf score=1.000000
I20260812 06:19:55.328639 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushMRSOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.037s	user 0.025s	sys 0.005s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":213,"dirs.run_wall_time_us":998,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1490,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:55.329392 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling LogGCOp(a5e38d548b984a71a1b2032a6249a42d): free 132571583 bytes of WAL
I20260812 06:19:55.329669 10406 log_reader.cc:385] T a5e38d548b984a71a1b2032a6249a42d: removed 13 log segments from log reader
I20260812 06:19:55.329727 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000026 (ops 127-131)
I20260812 06:19:55.329774 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000027 (ops 132-136)
I20260812 06:19:55.329808 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000028 (ops 137-140)
I20260812 06:19:55.329838 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000029 (ops 141-145)
I20260812 06:19:55.329866 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000030 (ops 146-150)
I20260812 06:19:55.329895 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000031 (ops 151-154)
I20260812 06:19:55.329926 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000032 (ops 155-159)
I20260812 06:19:55.329957 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000033 (ops 160-164)
I20260812 06:19:55.329984 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000034 (ops 165-169)
I20260812 06:19:55.330011 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000035 (ops 170-174)
I20260812 06:19:55.330040 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000036 (ops 175-179)
I20260812 06:19:55.330072 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000037 (ops 180-184)
I20260812 06:19:55.330104 10406 log.cc:1079] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/a5e38d548b984a71a1b2032a6249a42d/wal-000000038 (ops 185-189)
I20260812 06:19:55.358615 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: LogGCOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:55.359082 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:55.378213 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.019s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4143684,"delete_count":0,"lbm_write_time_us":6145,"lbm_writes_lt_1ms":104,"reinsert_count":0,"update_count":505}
I20260812 06:19:55.378698 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling UndoDeltaBlockGCOp(a5e38d548b984a71a1b2032a6249a42d): 493 bytes on disk
I20260812 06:19:55.379155 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: UndoDeltaBlockGCOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:19:55.379756 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=2.188937
I20260812 06:19:55.394433 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4061633,"delete_count":0,"lbm_write_time_us":5366,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":495}
I20260812 06:19:55.394996 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d): perf score=1.000000
I20260812 06:19:55.570250 10216 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.544s	user 1.737s	sys 0.104s
I20260812 06:19:55.598557 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.203s	user 0.129s	sys 0.071s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979753,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":13440,"lbm_reads_lt_1ms":770,"lbm_write_time_us":33671,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":3500}
I20260812 06:19:55.599089 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d): perf score=14.095187
I20260812 06:19:55.630897 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: FlushDeltaMemStoresOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.032s	user 0.027s	sys 0.004s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":14769,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.631337 10511 maintenance_manager.cc:419] P 15a1234d554042e291720b7e5b11989f: Scheduling MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d): perf score=1.000000
I20260812 06:19:55.672401 10216 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.102s	user 0.005s	sys 0.000s
I20260812 06:19:55.673141 10216 tablet_server.cc:179] TabletServer@127.9.250.1:0 shutting down...
I20260812 06:19:55.746874 10406 maintenance_manager.cc:643] P 15a1234d554042e291720b7e5b11989f: MajorDeltaCompactionOp(a5e38d548b984a71a1b2032a6249a42d) complete. Timing: real 0.115s	user 0.087s	sys 0.028s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":280,"lbm_read_time_us":8424,"lbm_reads_lt_1ms":467,"lbm_write_time_us":22887,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":71,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:19:55.747581 10216 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:55.748102 10216 tablet_replica.cc:333] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f: stopping tablet replica
I20260812 06:19:55.748335 10216 raft_consensus.cc:2243] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:55.748581 10216 raft_consensus.cc:2272] T a5e38d548b984a71a1b2032a6249a42d P 15a1234d554042e291720b7e5b11989f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:55.763314 10216 tablet_server.cc:196] TabletServer@127.9.250.1:0 shutdown complete.
I20260812 06:19:55.789603 10216 master.cc:562] Master@127.9.250.62:34509 shutting down...
I20260812 06:19:55.792827 10216 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:55.792980 10216 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:55.793033 10216 tablet_replica.cc:333] T 00000000000000000000000000000000 P 996ec68489e14c919b0bc2a53609d2e1: stopping tablet replica
I20260812 06:19:55.805132 10216 master.cc:584] Master@127.9.250.62:34509 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5085 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:55.889042 10216 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.9.250.62:37783
I20260812 06:19:55.889462 10216 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:55.891389 10562 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:55.891407 10216 server_base.cc:1061] running on GCE node
W20260812 06:19:55.891470 10564 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:55.891389 10567 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:55.891700 10216 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:55.891748 10216 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:55.891777 10216 hybrid_clock.cc:648] HybridClock initialized: now 1786515595891777 us; error 0 us; skew 500 ppm
I20260812 06:19:55.892505 10216 webserver.cc:533] Webserver started at http://127.9.250.62:38335/ using document root <none> and password file <none>
I20260812 06:19:55.892633 10216 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:55.892673 10216 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:55.892755 10216 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:55.893141 10216 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/master-0-root/instance:
uuid: "6b2eacc7539e46fca2655a799454bcad"
format_stamp: "Formatted at 2026-08-12 06:19:55 on dist-test-slave-nj21"
I20260812 06:19:55.894593 10216 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:55.895524 10577 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:55.895795 10216 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:55.895871 10216 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/master-0-root
uuid: "6b2eacc7539e46fca2655a799454bcad"
format_stamp: "Formatted at 2026-08-12 06:19:55 on dist-test-slave-nj21"
I20260812 06:19:55.895939 10216 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:55.904922 10216 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:55.905233 10216 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:55.909011 10216 rpc_server.cc:307] RPC server started. Bound to: 127.9.250.62:37783
I20260812 06:19:55.909034 10668 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.9.250.62:37783 every 8 connection(s)
I20260812 06:19:55.909799 10670 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:55.911535 10670 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad: Bootstrap starting.
I20260812 06:19:55.912313 10670 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:55.913244 10670 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad: No bootstrap required, opened a new log
I20260812 06:19:55.913625 10670 raft_consensus.cc:359] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6b2eacc7539e46fca2655a799454bcad" member_type: VOTER }
I20260812 06:19:55.913708 10670 raft_consensus.cc:385] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:55.913741 10670 raft_consensus.cc:740] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6b2eacc7539e46fca2655a799454bcad, State: Initialized, Role: FOLLOWER
I20260812 06:19:55.913882 10670 consensus_queue.cc:260] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad [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: "6b2eacc7539e46fca2655a799454bcad" member_type: VOTER }
I20260812 06:19:55.913954 10670 raft_consensus.cc:399] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:55.913988 10670 raft_consensus.cc:493] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:55.914038 10670 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:55.914676 10670 raft_consensus.cc:515] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6b2eacc7539e46fca2655a799454bcad" member_type: VOTER }
I20260812 06:19:55.914798 10670 leader_election.cc:304] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad [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: 6b2eacc7539e46fca2655a799454bcad; no voters: 
I20260812 06:19:55.914974 10670 leader_election.cc:290] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:55.915061 10674 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:55.915258 10674 raft_consensus.cc:697] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad [term 1 LEADER]: Becoming Leader. State: Replica: 6b2eacc7539e46fca2655a799454bcad, State: Running, Role: LEADER
I20260812 06:19:55.915374 10670 sys_catalog.cc:565] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:55.915400 10674 consensus_queue.cc:237] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad [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: "6b2eacc7539e46fca2655a799454bcad" member_type: VOTER }
I20260812 06:19:55.915834 10677 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "6b2eacc7539e46fca2655a799454bcad" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6b2eacc7539e46fca2655a799454bcad" member_type: VOTER } }
I20260812 06:19:55.915855 10679 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad [sys.catalog]: SysCatalogTable state changed. Reason: New leader 6b2eacc7539e46fca2655a799454bcad. Latest consensus state: current_term: 1 leader_uuid: "6b2eacc7539e46fca2655a799454bcad" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6b2eacc7539e46fca2655a799454bcad" member_type: VOTER } }
I20260812 06:19:55.915940 10677 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:55.915954 10679 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:55.916219 10686 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:55.917011 10686 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:55.917186 10216 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:55.918828 10686 catalog_manager.cc:1383] Generated new cluster ID: 1add697067a54315be0b060ad54337ce
I20260812 06:19:55.918879 10686 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:55.923418 10686 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:55.923977 10686 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:55.934638 10686 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad: Generated new TSK 0
I20260812 06:19:55.934793 10686 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:55.949514 10216 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:55.951472 10706 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:55.951576 10707 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:55.951658 10709 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:55.951817 10216 server_base.cc:1061] running on GCE node
I20260812 06:19:55.951982 10216 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:55.952019 10216 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:55.952040 10216 hybrid_clock.cc:648] HybridClock initialized: now 1786515595952040 us; error 0 us; skew 500 ppm
I20260812 06:19:55.952818 10216 webserver.cc:533] Webserver started at http://127.9.250.1:45775/ using document root <none> and password file <none>
I20260812 06:19:55.952972 10216 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:55.953024 10216 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:55.953097 10216 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:55.953480 10216 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/instance:
uuid: "e51ac9450fbc46ba8b60b12d3cfc006f"
format_stamp: "Formatted at 2026-08-12 06:19:55 on dist-test-slave-nj21"
I20260812 06:19:55.954898 10216 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:55.955765 10716 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:55.955991 10216 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:55.956060 10216 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root
uuid: "e51ac9450fbc46ba8b60b12d3cfc006f"
format_stamp: "Formatted at 2026-08-12 06:19:55 on dist-test-slave-nj21"
I20260812 06:19:55.956120 10216 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:55.966364 10216 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:55.966683 10216 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:55.966941 10216 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:55.967391 10216 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:55.967428 10216 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:55.967463 10216 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:55.967492 10216 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:55.971514 10216 rpc_server.cc:307] RPC server started. Bound to: 127.9.250.1:34707
I20260812 06:19:55.971581 10822 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.9.250.1:34707 every 8 connection(s)
I20260812 06:19:55.979234 10823 heartbeater.cc:344] Connected to a master server at 127.9.250.62:37783
I20260812 06:19:55.979360 10823 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:55.979629 10823 heartbeater.cc:507] Master 127.9.250.62:37783 requested a full tablet report, sending...
I20260812 06:19:55.980315 10602 ts_manager.cc:194] Registered new tserver with Master: e51ac9450fbc46ba8b60b12d3cfc006f (127.9.250.1:34707)
I20260812 06:19:55.980851 10216 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008914281s
I20260812 06:19:55.981081 10602 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:48186
I20260812 06:19:55.987649 10602 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:48202:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:55.995532 10767 tablet_service.cc:1511] Processing CreateTablet for tablet fd89aa95f6864759af31948ddb3cbf41 (DEFAULT_TABLE table=heavy-update-compaction-test [id=9c95cb3e758746ce99f4ac8251b65a53]), partition=
I20260812 06:19:55.995811 10767 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet fd89aa95f6864759af31948ddb3cbf41. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:55.997767 10841 tablet_bootstrap.cc:492] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Bootstrap starting.
I20260812 06:19:55.998633 10841 tablet_bootstrap.cc:654] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:55.999607 10841 tablet_bootstrap.cc:492] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: No bootstrap required, opened a new log
I20260812 06:19:55.999715 10841 ts_tablet_manager.cc:1403] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:56.000128 10841 raft_consensus.cc:359] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e51ac9450fbc46ba8b60b12d3cfc006f" member_type: VOTER last_known_addr { host: "127.9.250.1" port: 34707 } }
I20260812 06:19:56.000216 10841 raft_consensus.cc:385] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:56.000238 10841 raft_consensus.cc:740] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e51ac9450fbc46ba8b60b12d3cfc006f, State: Initialized, Role: FOLLOWER
I20260812 06:19:56.000353 10841 consensus_queue.cc:260] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f [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: "e51ac9450fbc46ba8b60b12d3cfc006f" member_type: VOTER last_known_addr { host: "127.9.250.1" port: 34707 } }
I20260812 06:19:56.000414 10841 raft_consensus.cc:399] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:56.000442 10841 raft_consensus.cc:493] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:56.000474 10841 raft_consensus.cc:3060] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:56.001273 10841 raft_consensus.cc:515] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e51ac9450fbc46ba8b60b12d3cfc006f" member_type: VOTER last_known_addr { host: "127.9.250.1" port: 34707 } }
I20260812 06:19:56.001416 10841 leader_election.cc:304] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f [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: e51ac9450fbc46ba8b60b12d3cfc006f; no voters: 
I20260812 06:19:56.001567 10841 leader_election.cc:290] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:56.001672 10845 raft_consensus.cc:2804] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:56.001858 10841 ts_tablet_manager.cc:1434] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:56.001896 10823 heartbeater.cc:499] Master 127.9.250.62:37783 was elected leader, sending a full tablet report...
I20260812 06:19:56.001904 10845 raft_consensus.cc:697] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f [term 1 LEADER]: Becoming Leader. State: Replica: e51ac9450fbc46ba8b60b12d3cfc006f, State: Running, Role: LEADER
I20260812 06:19:56.002070 10845 consensus_queue.cc:237] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f [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: "e51ac9450fbc46ba8b60b12d3cfc006f" member_type: VOTER last_known_addr { host: "127.9.250.1" port: 34707 } }
I20260812 06:19:56.003330 10602 catalog_manager.cc:5719] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f reported cstate change: term changed from 0 to 1, leader changed from <none> to e51ac9450fbc46ba8b60b12d3cfc006f (127.9.250.1). New cstate: current_term: 1 leader_uuid: "e51ac9450fbc46ba8b60b12d3cfc006f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e51ac9450fbc46ba8b60b12d3cfc006f" member_type: VOTER last_known_addr { host: "127.9.250.1" port: 34707 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:56.056740 10216 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.020s	sys 0.003s
I20260812 06:19:56.222493 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushMRSOp(fd89aa95f6864759af31948ddb3cbf41): perf score=23.023690
I20260812 06:19:56.391117 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushMRSOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.168s	user 0.114s	sys 0.051s Metrics: {"bytes_written":12717737,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":117,"dirs.run_cpu_time_us":192,"dirs.run_wall_time_us":800,"drs_written":1,"lbm_read_time_us":91,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40472,"lbm_writes_lt_1ms":867,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1550}
I20260812 06:19:56.391956 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling LogGCOp(fd89aa95f6864759af31948ddb3cbf41): free 20743880 bytes of WAL
I20260812 06:19:56.392231 10722 log_reader.cc:385] T fd89aa95f6864759af31948ddb3cbf41: removed 2 log segments from log reader
I20260812 06:19:56.392309 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000001 (ops 1-6)
I20260812 06:19:56.392351 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000002 (ops 7-11)
I20260812 06:19:56.396798 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: LogGCOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:56.397118 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling UndoDeltaBlockGCOp(fd89aa95f6864759af31948ddb3cbf41): 20513813 bytes on disk
I20260812 06:19:56.397614 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: UndoDeltaBlockGCOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:19:56.398049 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=2.188937
I20260812 06:19:56.419885 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.022s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4011,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.420324 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=2.188937
I20260812 06:19:56.429291 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3216,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:56.429744 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41): perf score=1.000000
I20260812 06:19:56.592624 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.163s	user 0.119s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815796,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":251,"lbm_read_time_us":10637,"lbm_reads_lt_1ms":569,"lbm_write_time_us":24988,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"thread_start_us":303,"threads_started":5,"update_count":2500}
I20260812 06:19:56.593133 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=14.095187
I20260812 06:19:56.643932 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.051s	user 0.031s	sys 0.015s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":15195,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.644538 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=2.188937
I20260812 06:19:56.659732 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.015s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5828,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.660192 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41): perf score=1.000000
I20260812 06:19:56.832943 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.173s	user 0.078s	sys 0.086s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815679,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":559,"lbm_read_time_us":12121,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25942,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:56.833420 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=14.095187
I20260812 06:19:56.878131 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.045s	user 0.027s	sys 0.010s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":16571,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.878680 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=2.188937
I20260812 06:19:56.899955 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.021s	user 0.010s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3904,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.900457 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41): perf score=1.000000
I20260812 06:19:57.075779 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.172s	user 0.102s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1181,"lbm_read_time_us":11181,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26906,"lbm_writes_lt_1ms":543,"mutex_wait_us":504,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:19:57.076254 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=14.095187
I20260812 06:19:57.130249 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.054s	user 0.027s	sys 0.025s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":25568,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.130875 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=2.188937
I20260812 06:19:57.150169 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.019s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5304,"lbm_writes_lt_1ms":103,"mutex_wait_us":31,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.150691 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41): perf score=1.000000
I20260812 06:19:57.320508 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.170s	user 0.106s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":190,"lbm_read_time_us":8821,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26964,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2500}
I20260812 06:19:57.321118 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=14.095187
I20260812 06:19:57.361140 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.040s	user 0.027s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16989,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.361692 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=2.188937
I20260812 06:19:57.373803 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4187,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.374485 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41): perf score=1.000000
I20260812 06:19:57.519357 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.145s	user 0.120s	sys 0.020s 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":540,"lbm_read_time_us":11097,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25134,"lbm_writes_lt_1ms":543,"mutex_wait_us":294,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":41088,"update_count":2500}
I20260812 06:19:57.519925 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=11.118625
I20260812 06:19:57.555306 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.035s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14676,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:57.555887 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=2.188937
I20260812 06:19:57.568393 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.012s	user 0.002s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4298,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:57.568909 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushMRSOp(fd89aa95f6864759af31948ddb3cbf41): perf score=1.000000
I20260812 06:19:57.605206 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushMRSOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.036s	user 0.021s	sys 0.003s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":246,"dirs.run_wall_time_us":1271,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1516,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:57.606009 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=3.181125
I20260812 06:19:57.618014 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":3988,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:57.618484 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling LogGCOp(fd89aa95f6864759af31948ddb3cbf41): free 124710287 bytes of WAL
I20260812 06:19:57.618712 10722 log_reader.cc:385] T fd89aa95f6864759af31948ddb3cbf41: removed 12 log segments from log reader
I20260812 06:19:57.618759 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000003 (ops 12-16)
I20260812 06:19:57.618788 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000004 (ops 17-21)
I20260812 06:19:57.618848 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000005 (ops 22-26)
I20260812 06:19:57.618884 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000006 (ops 27-31)
I20260812 06:19:57.618917 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000007 (ops 32-36)
I20260812 06:19:57.618947 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000008 (ops 37-41)
I20260812 06:19:57.618978 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000009 (ops 42-46)
I20260812 06:19:57.619009 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000010 (ops 47-51)
I20260812 06:19:57.619038 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000011 (ops 52-56)
I20260812 06:19:57.619069 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000012 (ops 57-61)
I20260812 06:19:57.619100 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000013 (ops 62-66)
I20260812 06:19:57.619130 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000014 (ops 67-71)
I20260812 06:19:57.638888 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: LogGCOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.020s	user 0.000s	sys 0.017s Metrics: {}
I20260812 06:19:57.639320 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=2.188937
I20260812 06:19:57.659144 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.020s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4622,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:57.659581 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=2.188937
I20260812 06:19:57.679838 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.020s	user 0.004s	sys 0.016s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3642,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.680433 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling UndoDeltaBlockGCOp(fd89aa95f6864759af31948ddb3cbf41): 473 bytes on disk
I20260812 06:19:57.683898 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: UndoDeltaBlockGCOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":99,"lbm_reads_lt_1ms":4}
I20260812 06:19:57.684512 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41): perf score=1.000000
I20260812 06:19:57.899174 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.214s	user 0.120s	sys 0.083s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020841,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":881,"lbm_read_time_us":13377,"lbm_reads_lt_1ms":775,"lbm_write_time_us":32319,"lbm_writes_lt_1ms":743,"mutex_wait_us":244,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1152,"thread_start_us":107,"threads_started":1,"update_count":3500}
I20260812 06:19:57.901191 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=18.063937
I20260812 06:19:57.965831 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.064s	user 0.025s	sys 0.036s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":28325,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:19:57.966344 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=2.188937
I20260812 06:19:57.984798 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.018s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4942,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.985281 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41): perf score=1.000000
I20260812 06:19:58.190289 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.205s	user 0.155s	sys 0.047s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":839,"lbm_read_time_us":13084,"lbm_reads_lt_1ms":664,"lbm_write_time_us":33542,"lbm_writes_lt_1ms":643,"mutex_wait_us":59,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":3000}
I20260812 06:19:58.190922 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=18.063937
I20260812 06:19:58.249521 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.058s	user 0.032s	sys 0.015s Metrics: {"bytes_written":20512324,"delete_count":0,"lbm_write_time_us":21482,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:58.250080 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=2.188937
I20260812 06:19:58.265878 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5931,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.266324 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41): perf score=1.000000
I20260812 06:19:58.461313 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.195s	user 0.119s	sys 0.075s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918106,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":574,"lbm_read_time_us":13275,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31465,"lbm_writes_lt_1ms":643,"mutex_wait_us":267,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":3000}
I20260812 06:19:58.461867 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=14.095187
I20260812 06:19:58.511271 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.049s	user 0.015s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18090,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.511766 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=2.188937
I20260812 06:19:58.521951 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3945,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.522382 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41): perf score=1.000000
I20260812 06:19:58.683470 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.161s	user 0.133s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":958,"lbm_read_time_us":10536,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24557,"lbm_writes_lt_1ms":543,"mutex_wait_us":273,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:58.684032 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=14.095187
I20260812 06:19:58.739612 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.055s	user 0.041s	sys 0.003s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20634,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.740244 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=2.188937
I20260812 06:19:58.750651 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3810,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.751237 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41): perf score=1.000000
I20260812 06:19:58.920403 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.169s	user 0.116s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":154,"lbm_read_time_us":10838,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27201,"lbm_writes_lt_1ms":543,"mutex_wait_us":72,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1152,"update_count":2500}
I20260812 06:19:58.920966 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=14.095187
I20260812 06:19:58.974886 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.054s	user 0.020s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18066,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.975520 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=2.188937
I20260812 06:19:58.985812 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3888,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.986235 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushMRSOp(fd89aa95f6864759af31948ddb3cbf41): perf score=1.000000
I20260812 06:19:59.016785 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushMRSOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.030s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":50,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":1135,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1548,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:59.017437 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling UndoDeltaBlockGCOp(fd89aa95f6864759af31948ddb3cbf41): 462 bytes on disk
I20260812 06:19:59.017792 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: UndoDeltaBlockGCOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:19:59.018330 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41): perf score=1.000000
I20260812 06:19:59.186630 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.168s	user 0.101s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":226,"lbm_read_time_us":11497,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26829,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":2500}
I20260812 06:19:59.187107 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling LogGCOp(fd89aa95f6864759af31948ddb3cbf41): free 124710258 bytes of WAL
I20260812 06:19:59.187330 10722 log_reader.cc:385] T fd89aa95f6864759af31948ddb3cbf41: removed 12 log segments from log reader
I20260812 06:19:59.187378 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000015 (ops 72-76)
I20260812 06:19:59.187417 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000016 (ops 77-81)
I20260812 06:19:59.187479 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000017 (ops 82-86)
I20260812 06:19:59.187518 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000018 (ops 87-91)
I20260812 06:19:59.187575 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000019 (ops 92-96)
I20260812 06:19:59.187611 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000020 (ops 97-101)
I20260812 06:19:59.187693 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000021 (ops 102-106)
I20260812 06:19:59.187731 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000022 (ops 107-111)
I20260812 06:19:59.187776 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000023 (ops 112-116)
I20260812 06:19:59.187819 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000024 (ops 117-121)
I20260812 06:19:59.187866 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000025 (ops 122-126)
I20260812 06:19:59.187901 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000026 (ops 127-131)
I20260812 06:19:59.210422 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: LogGCOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.023s	user 0.002s	sys 0.019s Metrics: {}
I20260812 06:19:59.210899 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=15.087375
I20260812 06:19:59.270887 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.060s	user 0.022s	sys 0.022s Metrics: {"bytes_written":16984243,"delete_count":0,"lbm_write_time_us":18028,"lbm_writes_lt_1ms":417,"reinsert_count":0,"update_count":2070}
I20260812 06:19:59.271386 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=6.157687
I20260812 06:19:59.289819 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.018s	user 0.008s	sys 0.008s Metrics: {"bytes_written":7630741,"delete_count":0,"lbm_write_time_us":7430,"lbm_writes_lt_1ms":189,"reinsert_count":0,"update_count":930}
I20260812 06:19:59.290277 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41): perf score=1.000000
I20260812 06:19:59.479287 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.189s	user 0.121s	sys 0.068s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918101,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":400,"lbm_read_time_us":12700,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32563,"lbm_writes_lt_1ms":643,"mutex_wait_us":64,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":3000}
I20260812 06:19:59.479952 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=14.095187
I20260812 06:19:59.531975 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.052s	user 0.032s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22480,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.532591 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=2.188937
I20260812 06:19:59.549009 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.016s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6261,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.549585 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41): perf score=1.000000
I20260812 06:19:59.724270 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.174s	user 0.131s	sys 0.044s 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":105,"lbm_read_time_us":13359,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28460,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2500}
I20260812 06:19:59.725136 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=14.095187
I20260812 06:19:59.777935 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.053s	user 0.032s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18330,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.778486 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=2.188937
I20260812 06:19:59.788857 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3995,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.789510 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41): perf score=1.000000
I20260812 06:19:59.974901 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.185s	user 0.114s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":946,"lbm_read_time_us":12549,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29132,"lbm_writes_lt_1ms":543,"mutex_wait_us":327,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:59.975438 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=14.095187
I20260812 06:20:00.025651 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.050s	user 0.043s	sys 0.000s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19238,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.026160 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=2.188937
I20260812 06:20:00.043867 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.018s	user 0.003s	sys 0.014s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3939,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.044363 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41): perf score=1.000000
I20260812 06:20:00.214126 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.170s	user 0.104s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":151,"lbm_read_time_us":10946,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27098,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2500}
I20260812 06:20:00.214676 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=14.095187
I20260812 06:20:00.260010 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.045s	user 0.031s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18791,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.260615 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=2.188937
I20260812 06:20:00.270972 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3811,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.271860 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41): perf score=1.000000
I20260812 06:20:00.451457 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.179s	user 0.102s	sys 0.067s 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":238,"lbm_read_time_us":8724,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28743,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2500}
I20260812 06:20:00.452075 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=14.095187
I20260812 06:20:00.497918 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.046s	user 0.018s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":15987,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.498402 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=2.188937
I20260812 06:20:00.508963 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3730,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.509459 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushMRSOp(fd89aa95f6864759af31948ddb3cbf41): perf score=1.000000
I20260812 06:20:00.540261 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushMRSOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.031s	user 0.029s	sys 0.001s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":1082,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1511,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:00.541025 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling LogGCOp(fd89aa95f6864759af31948ddb3cbf41): free 124257566 bytes of WAL
I20260812 06:20:00.541275 10722 log_reader.cc:385] T fd89aa95f6864759af31948ddb3cbf41: removed 12 log segments from log reader
I20260812 06:20:00.541327 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000027 (ops 132-136)
I20260812 06:20:00.541357 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000028 (ops 137-141)
I20260812 06:20:00.541378 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000029 (ops 142-146)
I20260812 06:20:00.541410 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000030 (ops 147-151)
I20260812 06:20:00.541445 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000031 (ops 152-156)
I20260812 06:20:00.541476 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000032 (ops 157-161)
I20260812 06:20:00.541507 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000033 (ops 162-166)
I20260812 06:20:00.541538 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000034 (ops 167-171)
I20260812 06:20:00.541568 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000035 (ops 172-176)
I20260812 06:20:00.541600 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000036 (ops 177-181)
I20260812 06:20:00.541630 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000037 (ops 182-186)
I20260812 06:20:00.541661 10722 log.cc:1079] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: Deleting log segment in path: /tmp/dist-test-taskF_sHXB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590782653-10216-0/minicluster-data/ts-0-root/wals/fd89aa95f6864759af31948ddb3cbf41/wal-000000038 (ops 187-190)
I20260812 06:20:00.562047 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: LogGCOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.021s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:20:00.565637 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=2.188937
I20260812 06:20:00.587065 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.021s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6110,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.587564 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling UndoDeltaBlockGCOp(fd89aa95f6864759af31948ddb3cbf41): 483 bytes on disk
I20260812 06:20:00.587996 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: UndoDeltaBlockGCOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:20:00.588593 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=2.188937
I20260812 06:20:00.598568 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3673,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.598960 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41): perf score=1.000000
I20260812 06:20:00.737339 10216 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.681s	user 1.685s	sys 0.177s
I20260812 06:20:00.809079 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: MajorDeltaCompactionOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.210s	user 0.148s	sys 0.060s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020746,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":14656,"lbm_reads_lt_1ms":770,"lbm_write_time_us":36325,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":3500}
I20260812 06:20:00.809643 10824 maintenance_manager.cc:419] P e51ac9450fbc46ba8b60b12d3cfc006f: Scheduling FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41): perf score=10.126437
I20260812 06:20:00.826987 10216 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.089s	user 0.001s	sys 0.000s
I20260812 06:20:00.827591 10216 tablet_server.cc:179] TabletServer@127.9.250.1:0 shutting down...
I20260812 06:20:00.854327 10722 maintenance_manager.cc:643] P e51ac9450fbc46ba8b60b12d3cfc006f: FlushDeltaMemStoresOp(fd89aa95f6864759af31948ddb3cbf41) complete. Timing: real 0.044s	user 0.023s	sys 0.019s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":14501,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:00.854925 10216 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:00.855150 10216 tablet_replica.cc:333] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f: stopping tablet replica
I20260812 06:20:00.855280 10216 raft_consensus.cc:2243] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:00.855458 10216 raft_consensus.cc:2272] T fd89aa95f6864759af31948ddb3cbf41 P e51ac9450fbc46ba8b60b12d3cfc006f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:00.860837 10216 tablet_server.cc:196] TabletServer@127.9.250.1:0 shutdown complete.
I20260812 06:20:00.867525 10216 master.cc:562] Master@127.9.250.62:37783 shutting down...
I20260812 06:20:00.870622 10216 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:00.870769 10216 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:00.870818 10216 tablet_replica.cc:333] T 00000000000000000000000000000000 P 6b2eacc7539e46fca2655a799454bcad: stopping tablet replica
I20260812 06:20:00.882934 10216 master.cc:584] Master@127.9.250.62:37783 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5075 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10161 ms total)

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