[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:20:13.790468 16216 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.15.214.62:42901
I20260812 06:20:13.791699 16216 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:20:13.792435 16216 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:13.800271 16226 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:13.800244 16216 server_base.cc:1061] running on GCE node
W20260812 06:20:13.800235 16228 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:13.800575 16224 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:13.801218 16216 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:13.801365 16216 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:13.801421 16216 hybrid_clock.cc:648] HybridClock initialized: now 1786515613801418 us; error 0 us; skew 500 ppm
I20260812 06:20:13.803583 16216 webserver.cc:533] Webserver started at http://127.15.214.62:33425/ using document root <none> and password file <none>
I20260812 06:20:13.804232 16216 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:13.804301 16216 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:13.804584 16216 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:13.806562 16216 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/master-0-root/instance:
uuid: "59daab2faab74b3fa55fca7625cf33eb"
format_stamp: "Formatted at 2026-08-12 06:20:13 on dist-test-slave-vxj2"
I20260812 06:20:13.810974 16216 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.001s	sys 0.003s
I20260812 06:20:13.813915 16236 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:13.815261 16216 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:13.815459 16216 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/master-0-root
uuid: "59daab2faab74b3fa55fca7625cf33eb"
format_stamp: "Formatted at 2026-08-12 06:20:13 on dist-test-slave-vxj2"
I20260812 06:20:13.815603 16216 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:13.834385 16216 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:13.835218 16216 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:20:13.835448 16216 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:13.844301 16216 rpc_server.cc:307] RPC server started. Bound to: 127.15.214.62:42901
I20260812 06:20:13.844297 16311 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.214.62:42901 every 8 connection(s)
I20260812 06:20:13.847009 16312 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:13.853628 16312 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb: Bootstrap starting.
I20260812 06:20:13.856639 16312 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:13.857935 16312 log.cc:826] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:13.860106 16312 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb: No bootstrap required, opened a new log
I20260812 06:20:13.863881 16312 raft_consensus.cc:359] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "59daab2faab74b3fa55fca7625cf33eb" member_type: VOTER }
I20260812 06:20:13.864117 16312 raft_consensus.cc:385] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:13.864223 16312 raft_consensus.cc:740] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 59daab2faab74b3fa55fca7625cf33eb, State: Initialized, Role: FOLLOWER
I20260812 06:20:13.864984 16312 consensus_queue.cc:260] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb [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: "59daab2faab74b3fa55fca7625cf33eb" member_type: VOTER }
I20260812 06:20:13.865229 16312 raft_consensus.cc:399] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:13.865319 16312 raft_consensus.cc:493] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:13.865535 16312 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:13.866760 16312 raft_consensus.cc:515] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "59daab2faab74b3fa55fca7625cf33eb" member_type: VOTER }
I20260812 06:20:13.867394 16312 leader_election.cc:304] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb [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: 59daab2faab74b3fa55fca7625cf33eb; no voters: 
I20260812 06:20:13.867859 16312 leader_election.cc:290] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:13.868110 16315 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:13.868397 16315 raft_consensus.cc:697] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb [term 1 LEADER]: Becoming Leader. State: Replica: 59daab2faab74b3fa55fca7625cf33eb, State: Running, Role: LEADER
I20260812 06:20:13.868896 16315 consensus_queue.cc:237] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb [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: "59daab2faab74b3fa55fca7625cf33eb" member_type: VOTER }
I20260812 06:20:13.869267 16312 sys_catalog.cc:565] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:13.871209 16317 sys_catalog.cc:455] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb [sys.catalog]: SysCatalogTable state changed. Reason: New leader 59daab2faab74b3fa55fca7625cf33eb. Latest consensus state: current_term: 1 leader_uuid: "59daab2faab74b3fa55fca7625cf33eb" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "59daab2faab74b3fa55fca7625cf33eb" member_type: VOTER } }
I20260812 06:20:13.871250 16316 sys_catalog.cc:455] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "59daab2faab74b3fa55fca7625cf33eb" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "59daab2faab74b3fa55fca7625cf33eb" member_type: VOTER } }
I20260812 06:20:13.871394 16317 sys_catalog.cc:458] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:13.871448 16316 sys_catalog.cc:458] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:13.872191 16216 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:20:13.874869 16333 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:20:13.874991 16333 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:20:13.875067 16329 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:13.875825 16329 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:13.882117 16329 catalog_manager.cc:1383] Generated new cluster ID: 968678f45dfb4e3d8f0d17ef79f21661
I20260812 06:20:13.882225 16329 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:13.897482 16329 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:13.898633 16329 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:13.909650 16329 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb: Generated new TSK 0
I20260812 06:20:13.910586 16329 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:13.938544 16216 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:13.942183 16340 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:13.942423 16216 server_base.cc:1061] running on GCE node
W20260812 06:20:13.942390 16339 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:13.942457 16342 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:13.943477 16216 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:13.943539 16216 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:13.943563 16216 hybrid_clock.cc:648] HybridClock initialized: now 1786515613943563 us; error 0 us; skew 500 ppm
I20260812 06:20:13.944653 16216 webserver.cc:533] Webserver started at http://127.15.214.1:33119/ using document root <none> and password file <none>
I20260812 06:20:13.944844 16216 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:13.944905 16216 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:13.944980 16216 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:13.945489 16216 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/instance:
uuid: "4e3cd43091ca40298582f17e2d52fb59"
format_stamp: "Formatted at 2026-08-12 06:20:13 on dist-test-slave-vxj2"
I20260812 06:20:13.947598 16216 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:13.948889 16348 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:13.949239 16216 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:13.949329 16216 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root
uuid: "4e3cd43091ca40298582f17e2d52fb59"
format_stamp: "Formatted at 2026-08-12 06:20:13 on dist-test-slave-vxj2"
I20260812 06:20:13.949397 16216 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:13.958513 16216 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:13.959108 16216 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:13.959692 16216 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:13.960718 16216 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:13.960784 16216 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:13.960870 16216 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:13.960907 16216 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:13.969233 16216 rpc_server.cc:307] RPC server started. Bound to: 127.15.214.1:45849
I20260812 06:20:13.969321 16428 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.214.1:45849 every 8 connection(s)
I20260812 06:20:13.981653 16429 heartbeater.cc:344] Connected to a master server at 127.15.214.62:42901
I20260812 06:20:13.982059 16429 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:13.982622 16429 heartbeater.cc:507] Master 127.15.214.62:42901 requested a full tablet report, sending...
I20260812 06:20:13.984583 16261 ts_manager.cc:194] Registered new tserver with Master: 4e3cd43091ca40298582f17e2d52fb59 (127.15.214.1:45849)
I20260812 06:20:13.985054 16216 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015026346s
I20260812 06:20:13.986244 16261 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:41740
I20260812 06:20:13.996374 16261 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:41756:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:14.015425 16385 tablet_service.cc:1511] Processing CreateTablet for tablet 470ddd60dea34dedabf184a4f3092d16 (DEFAULT_TABLE table=heavy-update-compaction-test [id=6c840c08a40a41c98cc48a9751e0a6cf]), partition=
I20260812 06:20:14.015995 16385 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 470ddd60dea34dedabf184a4f3092d16. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:14.019361 16443 tablet_bootstrap.cc:492] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Bootstrap starting.
I20260812 06:20:14.020689 16443 tablet_bootstrap.cc:654] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:14.022187 16443 tablet_bootstrap.cc:492] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: No bootstrap required, opened a new log
I20260812 06:20:14.022346 16443 ts_tablet_manager.cc:1403] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:14.022941 16443 raft_consensus.cc:359] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4e3cd43091ca40298582f17e2d52fb59" member_type: VOTER last_known_addr { host: "127.15.214.1" port: 45849 } }
I20260812 06:20:14.023089 16443 raft_consensus.cc:385] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:14.023141 16443 raft_consensus.cc:740] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4e3cd43091ca40298582f17e2d52fb59, State: Initialized, Role: FOLLOWER
I20260812 06:20:14.023329 16443 consensus_queue.cc:260] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59 [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: "4e3cd43091ca40298582f17e2d52fb59" member_type: VOTER last_known_addr { host: "127.15.214.1" port: 45849 } }
I20260812 06:20:14.023456 16443 raft_consensus.cc:399] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:14.023509 16443 raft_consensus.cc:493] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:14.023566 16443 raft_consensus.cc:3060] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:14.024744 16443 raft_consensus.cc:515] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4e3cd43091ca40298582f17e2d52fb59" member_type: VOTER last_known_addr { host: "127.15.214.1" port: 45849 } }
I20260812 06:20:14.024952 16443 leader_election.cc:304] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59 [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: 4e3cd43091ca40298582f17e2d52fb59; no voters: 
I20260812 06:20:14.025267 16443 leader_election.cc:290] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:14.025388 16446 raft_consensus.cc:2804] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:14.025590 16446 raft_consensus.cc:697] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59 [term 1 LEADER]: Becoming Leader. State: Replica: 4e3cd43091ca40298582f17e2d52fb59, State: Running, Role: LEADER
I20260812 06:20:14.025712 16443 ts_tablet_manager.cc:1434] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:20:14.025811 16446 consensus_queue.cc:237] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59 [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: "4e3cd43091ca40298582f17e2d52fb59" member_type: VOTER last_known_addr { host: "127.15.214.1" port: 45849 } }
I20260812 06:20:14.026036 16429 heartbeater.cc:499] Master 127.15.214.62:42901 was elected leader, sending a full tablet report...
I20260812 06:20:14.029273 16260 catalog_manager.cc:5719] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59 reported cstate change: term changed from 0 to 1, leader changed from <none> to 4e3cd43091ca40298582f17e2d52fb59 (127.15.214.1). New cstate: current_term: 1 leader_uuid: "4e3cd43091ca40298582f17e2d52fb59" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4e3cd43091ca40298582f17e2d52fb59" member_type: VOTER last_known_addr { host: "127.15.214.1" port: 45849 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:14.101122 16216 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.063s	user 0.021s	sys 0.009s
I20260812 06:20:14.220853 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushMRSOp(470ddd60dea34dedabf184a4f3092d16): perf score=15.086190
I20260812 06:20:14.379364 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushMRSOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.158s	user 0.104s	sys 0.050s Metrics: {"bytes_written":9394780,"cfile_init":1,"compiler_manager_pool.queue_time_us":312,"delete_count":0,"dirs.queue_time_us":105,"dirs.run_cpu_time_us":280,"dirs.run_wall_time_us":1134,"drs_written":1,"lbm_read_time_us":130,"lbm_reads_lt_1ms":4,"lbm_write_time_us":35214,"lbm_writes_lt_1ms":586,"mutex_wait_us":238,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"spinlock_wait_cycles":274560,"thread_start_us":159,"threads_started":1,"update_count":1145}
I20260812 06:20:14.380858 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling LogGCOp(470ddd60dea34dedabf184a4f3092d16): free 11976772 bytes of WAL
I20260812 06:20:14.381294 16355 log_reader.cc:385] T 470ddd60dea34dedabf184a4f3092d16: removed 1 log segments from log reader
I20260812 06:20:14.381417 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000001 (ops 1-6)
I20260812 06:20:14.384828 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: LogGCOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.004s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:14.385490 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling UndoDeltaBlockGCOp(470ddd60dea34dedabf184a4f3092d16): 12308958 bytes on disk
I20260812 06:20:14.386161 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: UndoDeltaBlockGCOp(470ddd60dea34dedabf184a4f3092d16) 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:20:14.386860 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.196750
I20260812 06:20:14.400436 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":2912930,"delete_count":0,"lbm_write_time_us":3998,"lbm_writes_lt_1ms":74,"reinsert_count":0,"update_count":355}
I20260812 06:20:14.401237 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:14.534091 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.133s	user 0.110s	sys 0.012s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528873,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":954,"lbm_read_time_us":7820,"lbm_reads_lt_1ms":360,"lbm_write_time_us":20916,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":367,"threads_started":5,"update_count":1500}
I20260812 06:20:14.534715 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=10.126437
I20260812 06:20:14.587740 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.053s	user 0.019s	sys 0.021s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19868,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.588550 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=2.188937
I20260812 06:20:14.601070 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4153,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.601816 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:14.747148 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.145s	user 0.116s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1470,"lbm_read_time_us":9791,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28221,"lbm_writes_lt_1ms":443,"mutex_wait_us":409,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2000}
I20260812 06:20:14.747917 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=10.126437
I20260812 06:20:14.793762 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.046s	user 0.029s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14140,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.794338 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:14.925724 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.131s	user 0.100s	sys 0.031s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1092,"lbm_read_time_us":8909,"lbm_reads_lt_1ms":363,"lbm_write_time_us":19921,"lbm_writes_lt_1ms":343,"mutex_wait_us":345,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":1500}
I20260812 06:20:14.926541 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=10.126437
I20260812 06:20:14.973093 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.046s	user 0.016s	sys 0.021s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":17711,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.973727 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=2.188937
I20260812 06:20:14.984992 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4211,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.985704 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:15.119673 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.134s	user 0.088s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631315,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":223,"lbm_read_time_us":9212,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25462,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:20:15.120591 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=10.126437
I20260812 06:20:15.171348 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.051s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15663,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.172078 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=2.188937
I20260812 06:20:15.190675 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.018s	user 0.015s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6643,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.191324 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:15.324905 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.133s	user 0.091s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2113,"lbm_read_time_us":9332,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26121,"lbm_writes_lt_1ms":443,"mutex_wait_us":601,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2000}
I20260812 06:20:15.325860 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=10.126437
I20260812 06:20:15.379053 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.053s	user 0.009s	sys 0.042s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":19435,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.379767 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=2.188937
I20260812 06:20:15.397095 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.017s	user 0.000s	sys 0.015s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6930,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.398877 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:15.553601 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.155s	user 0.102s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":238,"lbm_read_time_us":12041,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25838,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15744,"update_count":2000}
I20260812 06:20:15.554333 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=10.126437
I20260812 06:20:15.608752 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.054s	user 0.025s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22526,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.609413 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=2.188937
I20260812 06:20:15.623325 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.014s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4721,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.623917 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:15.765945 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.142s	user 0.125s	sys 0.015s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":304,"lbm_read_time_us":10574,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28959,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:15.766739 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=10.126437
I20260812 06:20:15.805910 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.039s	user 0.027s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15907,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.806681 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushMRSOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:15.845258 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushMRSOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.038s	user 0.024s	sys 0.005s Metrics: {"bytes_written":1234474,"cfile_init":1,"dirs.queue_time_us":90,"dirs.run_cpu_time_us":314,"dirs.run_wall_time_us":1852,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1859,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:15.846338 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=3.181125
I20260812 06:20:15.858877 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4522,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:15.859582 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling LogGCOp(470ddd60dea34dedabf184a4f3092d16): free 129320489 bytes of WAL
I20260812 06:20:15.859905 16355 log_reader.cc:385] T 470ddd60dea34dedabf184a4f3092d16: removed 13 log segments from log reader
I20260812 06:20:15.859993 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000002 (ops 7-11)
I20260812 06:20:15.860049 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000003 (ops 12-16)
I20260812 06:20:15.860109 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000004 (ops 17-21)
I20260812 06:20:15.860152 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000005 (ops 22-26)
I20260812 06:20:15.860194 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000006 (ops 27-31)
I20260812 06:20:15.860234 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000007 (ops 32-36)
I20260812 06:20:15.860273 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000008 (ops 37-40)
I20260812 06:20:15.860313 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000009 (ops 41-45)
I20260812 06:20:15.860365 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000010 (ops 46-50)
I20260812 06:20:15.860404 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000011 (ops 51-55)
I20260812 06:20:15.860443 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000012 (ops 56-60)
I20260812 06:20:15.860483 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000013 (ops 61-64)
I20260812 06:20:15.860522 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000014 (ops 65-69)
I20260812 06:20:15.892333 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: LogGCOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.032s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:20:15.893064 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling UndoDeltaBlockGCOp(470ddd60dea34dedabf184a4f3092d16): 471 bytes on disk
I20260812 06:20:15.893622 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: UndoDeltaBlockGCOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:20:15.894281 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=2.188937
I20260812 06:20:15.906704 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.012s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4624,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.907388 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=2.188937
I20260812 06:20:15.918727 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4125,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:15.919441 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:16.095901 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.176s	user 0.146s	sys 0.023s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836360,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":614,"lbm_read_time_us":12750,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34581,"lbm_writes_lt_1ms":643,"mutex_wait_us":53,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10496,"thread_start_us":123,"threads_started":1,"update_count":3000}
I20260812 06:20:16.098824 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=11.118625
I20260812 06:20:16.148983 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.049s	user 0.030s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":19229,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:20:16.149667 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=2.188937
I20260812 06:20:16.167640 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.018s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5053,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.168604 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=2.188937
I20260812 06:20:16.183784 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5080,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:16.184621 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:16.356309 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.171s	user 0.133s	sys 0.025s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733834,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":489,"lbm_read_time_us":10378,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31064,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:20:16.356896 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=14.095187
I20260812 06:20:16.417546 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.060s	user 0.047s	sys 0.003s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22441,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.418233 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=2.188937
I20260812 06:20:16.431200 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4491,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.431723 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:16.634075 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.202s	user 0.140s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733726,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":720,"lbm_read_time_us":13015,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36067,"lbm_writes_lt_1ms":543,"mutex_wait_us":313,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":141056,"update_count":2500}
I20260812 06:20:16.635236 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=14.095187
I20260812 06:20:16.689965 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.054s	user 0.045s	sys 0.008s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23375,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.690712 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:16.851248 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.160s	user 0.112s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631191,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":171,"lbm_read_time_us":11472,"lbm_reads_lt_1ms":467,"lbm_write_time_us":27689,"lbm_writes_lt_1ms":443,"mutex_wait_us":67,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":23936,"update_count":2000}
I20260812 06:20:16.852046 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=10.126437
I20260812 06:20:16.899386 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.047s	user 0.033s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19907,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.900444 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=2.188937
I20260812 06:20:16.920285 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.019s	user 0.014s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7481,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.921039 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:17.063521 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.142s	user 0.109s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":251,"lbm_read_time_us":9171,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27000,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19200,"update_count":2000}
I20260812 06:20:17.064692 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=10.126437
I20260812 06:20:17.110769 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.045s	user 0.032s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18808,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":1500}
I20260812 06:20:17.111398 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=2.188937
I20260812 06:20:17.123258 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4494,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.123824 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:17.261950 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.138s	user 0.098s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1083,"lbm_read_time_us":8546,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28038,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19840,"update_count":2000}
I20260812 06:20:17.262905 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=10.126437
I20260812 06:20:17.307711 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.045s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16182,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.308270 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=2.188937
I20260812 06:20:17.320214 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4317,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.320896 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushMRSOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:17.354375 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushMRSOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.033s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":211,"dirs.run_cpu_time_us":242,"dirs.run_wall_time_us":1705,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2251,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28,"spinlock_wait_cycles":15744}
I20260812 06:20:17.355244 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling LogGCOp(470ddd60dea34dedabf184a4f3092d16): free 112239265 bytes of WAL
I20260812 06:20:17.355511 16355 log_reader.cc:385] T 470ddd60dea34dedabf184a4f3092d16: removed 11 log segments from log reader
I20260812 06:20:17.355556 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000015 (ops 70-74)
I20260812 06:20:17.355587 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000016 (ops 75-79)
I20260812 06:20:17.355648 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000017 (ops 80-84)
I20260812 06:20:17.355682 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000018 (ops 85-89)
I20260812 06:20:17.355718 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000019 (ops 90-94)
I20260812 06:20:17.355749 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000020 (ops 95-99)
I20260812 06:20:17.355788 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000021 (ops 100-104)
I20260812 06:20:17.355837 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000022 (ops 105-109)
I20260812 06:20:17.355872 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000023 (ops 110-114)
I20260812 06:20:17.355906 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000024 (ops 115-118)
I20260812 06:20:17.355943 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000025 (ops 119-123)
I20260812 06:20:17.381315 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: LogGCOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.026s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:17.381994 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling UndoDeltaBlockGCOp(470ddd60dea34dedabf184a4f3092d16): 448 bytes on disk
I20260812 06:20:17.382807 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: UndoDeltaBlockGCOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":104,"lbm_reads_lt_1ms":4}
I20260812 06:20:17.383823 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=3.181125
I20260812 06:20:17.411420 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.027s	user 0.014s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7764,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:17.412007 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=2.188937
I20260812 06:20:17.426254 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5330,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:17.426903 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:17.628697 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.202s	user 0.163s	sys 0.027s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836363,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":811,"lbm_read_time_us":13573,"lbm_reads_lt_1ms":674,"lbm_write_time_us":39382,"lbm_writes_lt_1ms":643,"mutex_wait_us":71,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16512,"thread_start_us":95,"threads_started":1,"update_count":3000}
I20260812 06:20:17.629494 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=14.095187
I20260812 06:20:17.678745 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.049s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20910,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.679297 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=2.188937
I20260812 06:20:17.692399 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4688,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.693019 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:17.860441 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.167s	user 0.126s	sys 0.034s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1112,"lbm_read_time_us":11768,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29282,"lbm_writes_lt_1ms":543,"mutex_wait_us":416,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":34560,"update_count":2500}
I20260812 06:20:17.861241 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=12.110812
I20260812 06:20:17.899609 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.038s	user 0.023s	sys 0.012s Metrics: {"bytes_written":13661281,"delete_count":0,"lbm_write_time_us":16644,"lbm_writes_lt_1ms":336,"reinsert_count":0,"update_count":1665}
I20260812 06:20:17.900398 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.196750
I20260812 06:20:17.922264 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.022s	user 0.008s	sys 0.004s Metrics: {"bytes_written":2748830,"delete_count":0,"lbm_write_time_us":4739,"lbm_writes_lt_1ms":70,"reinsert_count":0,"update_count":335}
I20260812 06:20:17.922837 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:18.082981 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.160s	user 0.110s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631274,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":293,"lbm_read_time_us":10929,"lbm_reads_lt_1ms":464,"lbm_write_time_us":29542,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:20:18.083786 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=10.126437
I20260812 06:20:18.119138 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.035s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15322,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:18.119807 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=2.188937
I20260812 06:20:18.139673 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.020s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7695,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.140288 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:18.290347 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.150s	user 0.109s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1278,"lbm_read_time_us":11159,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26614,"lbm_writes_lt_1ms":443,"mutex_wait_us":411,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2000}
I20260812 06:20:18.291319 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=10.126437
I20260812 06:20:18.337368 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.046s	user 0.038s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19849,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:18.338171 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=2.188937
I20260812 06:20:18.356489 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.018s	user 0.004s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7096,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.357239 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:18.503360 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.146s	user 0.125s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":858,"lbm_read_time_us":10717,"lbm_reads_lt_1ms":468,"lbm_write_time_us":28215,"lbm_writes_lt_1ms":443,"mutex_wait_us":377,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":24576,"update_count":2000}
I20260812 06:20:18.504122 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=10.126437
I20260812 06:20:18.572146 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.068s	user 0.028s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":27124,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:20:18.572880 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=2.188937
I20260812 06:20:18.586046 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5053,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.586900 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:18.731069 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.144s	user 0.109s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":208,"lbm_read_time_us":11024,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27500,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2000}
I20260812 06:20:18.732198 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=10.126437
I20260812 06:20:18.794101 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.062s	user 0.042s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":21532,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:18.794847 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=2.188937
I20260812 06:20:18.807734 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4786,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.808367 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:18.986805 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.178s	user 0.118s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":501,"lbm_read_time_us":13155,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28473,"lbm_writes_lt_1ms":443,"mutex_wait_us":68,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2000}
I20260812 06:20:18.987605 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=10.126437
I20260812 06:20:19.040019 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.052s	user 0.021s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21765,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.040686 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=2.188937
I20260812 06:20:19.055724 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5072,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.056617 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushMRSOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:19.093600 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushMRSOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.037s	user 0.029s	sys 0.008s Metrics: {"bytes_written":1275445,"cfile_init":1,"dirs.queue_time_us":108,"dirs.run_cpu_time_us":330,"dirs.run_wall_time_us":1533,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2629,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:19.094626 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling LogGCOp(470ddd60dea34dedabf184a4f3092d16): free 129320817 bytes of WAL
I20260812 06:20:19.094995 16355 log_reader.cc:385] T 470ddd60dea34dedabf184a4f3092d16: removed 13 log segments from log reader
I20260812 06:20:19.095073 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000026 (ops 124-128)
I20260812 06:20:19.095119 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000027 (ops 129-132)
I20260812 06:20:19.095148 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000028 (ops 133-137)
I20260812 06:20:19.095175 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000029 (ops 138-142)
I20260812 06:20:19.095196 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000030 (ops 143-146)
I20260812 06:20:19.095227 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000031 (ops 147-151)
I20260812 06:20:19.095250 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000032 (ops 152-156)
I20260812 06:20:19.095273 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000033 (ops 157-161)
I20260812 06:20:19.095296 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000034 (ops 162-166)
I20260812 06:20:19.095319 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000035 (ops 167-171)
I20260812 06:20:19.095343 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000036 (ops 172-176)
I20260812 06:20:19.095368 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000037 (ops 177-181)
I20260812 06:20:19.095393 16355 log.cc:1079] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/470ddd60dea34dedabf184a4f3092d16/wal-000000038 (ops 182-186)
I20260812 06:20:19.130988 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: LogGCOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.036s	user 0.000s	sys 0.034s Metrics: {}
I20260812 06:20:19.131630 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=2.188937
I20260812 06:20:19.155839 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.024s	user 0.003s	sys 0.016s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4503,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.156471 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=2.188937
I20260812 06:20:19.167968 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4278,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.168591 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling UndoDeltaBlockGCOp(470ddd60dea34dedabf184a4f3092d16): 482 bytes on disk
I20260812 06:20:19.169085 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: UndoDeltaBlockGCOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:20:19.169703 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:19.394193 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.224s	user 0.170s	sys 0.048s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836373,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":227,"lbm_read_time_us":16109,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38090,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20096,"thread_start_us":84,"threads_started":1,"update_count":3000}
I20260812 06:20:19.394727 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=14.095187
I20260812 06:20:19.465642 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.071s	user 0.034s	sys 0.031s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25406,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.466313 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16): perf score=2.188937
I20260812 06:20:19.478161 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: FlushDeltaMemStoresOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.012s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4519,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.478724 16430 maintenance_manager.cc:419] P 4e3cd43091ca40298582f17e2d52fb59: Scheduling MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16): perf score=1.000000
I20260812 06:20:19.542951 16216 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.442s	user 1.976s	sys 0.152s
I20260812 06:20:19.625600 16216 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.082s	user 0.005s	sys 0.000s
I20260812 06:20:19.626385 16216 tablet_server.cc:179] TabletServer@127.15.214.1:0 shutting down...
I20260812 06:20:19.647310 16355 maintenance_manager.cc:643] P 4e3cd43091ca40298582f17e2d52fb59: MajorDeltaCompactionOp(470ddd60dea34dedabf184a4f3092d16) complete. Timing: real 0.168s	user 0.134s	sys 0.034s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":853,"lbm_read_time_us":12606,"lbm_reads_lt_1ms":568,"lbm_write_time_us":27362,"lbm_writes_lt_1ms":543,"mutex_wait_us":214,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2500}
I20260812 06:20:19.648113 16216 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:19.648662 16216 tablet_replica.cc:333] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59: stopping tablet replica
I20260812 06:20:19.648976 16216 raft_consensus.cc:2243] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:19.649329 16216 raft_consensus.cc:2272] T 470ddd60dea34dedabf184a4f3092d16 P 4e3cd43091ca40298582f17e2d52fb59 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:19.666564 16216 tablet_server.cc:196] TabletServer@127.15.214.1:0 shutdown complete.
I20260812 06:20:19.693846 16216 master.cc:562] Master@127.15.214.62:42901 shutting down...
I20260812 06:20:19.698418 16216 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:19.698685 16216 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:19.698774 16216 tablet_replica.cc:333] T 00000000000000000000000000000000 P 59daab2faab74b3fa55fca7625cf33eb: stopping tablet replica
I20260812 06:20:19.711545 16216 master.cc:584] Master@127.15.214.62:42901 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6016 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:19.819545 16216 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.15.214.62:44363
I20260812 06:20:19.820036 16216 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:19.823082 16469 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:19.823179 16216 server_base.cc:1061] running on GCE node
W20260812 06:20:19.823222 16464 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:19.823208 16466 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:19.823608 16216 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:19.823659 16216 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:19.823686 16216 hybrid_clock.cc:648] HybridClock initialized: now 1786515619823687 us; error 0 us; skew 500 ppm
I20260812 06:20:19.824620 16216 webserver.cc:533] Webserver started at http://127.15.214.62:37707/ using document root <none> and password file <none>
I20260812 06:20:19.824790 16216 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:19.824843 16216 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:19.824913 16216 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:19.825407 16216 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/master-0-root/instance:
uuid: "798ac66bdaff47468f5c2b0364461eb6"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-vxj2"
I20260812 06:20:19.827128 16216 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:20:19.828334 16474 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.828886 16216 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:19.829013 16216 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/master-0-root
uuid: "798ac66bdaff47468f5c2b0364461eb6"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-vxj2"
I20260812 06:20:19.829128 16216 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:19.833266 16216 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:19.833673 16216 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:19.838402 16216 rpc_server.cc:307] RPC server started. Bound to: 127.15.214.62:44363
I20260812 06:20:19.840018 16541 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.214.62:44363 every 8 connection(s)
I20260812 06:20:19.840571 16542 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:19.842638 16542 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6: Bootstrap starting.
I20260812 06:20:19.843506 16542 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:19.844664 16542 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6: No bootstrap required, opened a new log
I20260812 06:20:19.845132 16542 raft_consensus.cc:359] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "798ac66bdaff47468f5c2b0364461eb6" member_type: VOTER }
I20260812 06:20:19.845310 16542 raft_consensus.cc:385] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:19.845384 16542 raft_consensus.cc:740] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 798ac66bdaff47468f5c2b0364461eb6, State: Initialized, Role: FOLLOWER
I20260812 06:20:19.845568 16542 consensus_queue.cc:260] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6 [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: "798ac66bdaff47468f5c2b0364461eb6" member_type: VOTER }
I20260812 06:20:19.845681 16542 raft_consensus.cc:399] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:19.845729 16542 raft_consensus.cc:493] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:19.845786 16542 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:19.846586 16542 raft_consensus.cc:515] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "798ac66bdaff47468f5c2b0364461eb6" member_type: VOTER }
I20260812 06:20:19.846751 16542 leader_election.cc:304] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6 [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: 798ac66bdaff47468f5c2b0364461eb6; no voters: 
I20260812 06:20:19.846998 16542 leader_election.cc:290] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:19.847219 16545 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:19.847472 16545 raft_consensus.cc:697] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6 [term 1 LEADER]: Becoming Leader. State: Replica: 798ac66bdaff47468f5c2b0364461eb6, State: Running, Role: LEADER
I20260812 06:20:19.847631 16542 sys_catalog.cc:565] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:19.847664 16545 consensus_queue.cc:237] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6 [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: "798ac66bdaff47468f5c2b0364461eb6" member_type: VOTER }
I20260812 06:20:19.848269 16546 sys_catalog.cc:455] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "798ac66bdaff47468f5c2b0364461eb6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "798ac66bdaff47468f5c2b0364461eb6" member_type: VOTER } }
I20260812 06:20:19.848297 16547 sys_catalog.cc:455] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 798ac66bdaff47468f5c2b0364461eb6. Latest consensus state: current_term: 1 leader_uuid: "798ac66bdaff47468f5c2b0364461eb6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "798ac66bdaff47468f5c2b0364461eb6" member_type: VOTER } }
I20260812 06:20:19.848378 16546 sys_catalog.cc:458] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:19.848385 16547 sys_catalog.cc:458] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:19.848683 16552 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:19.849617 16552 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:19.849843 16216 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:19.852084 16552 catalog_manager.cc:1383] Generated new cluster ID: f3a0fa86b6a5482594c38aeea896698b
I20260812 06:20:19.852152 16552 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:19.878760 16552 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:19.879465 16552 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:19.888846 16552 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6: Generated new TSK 0
I20260812 06:20:19.889123 16552 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:19.914716 16216 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:19.917335 16568 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:19.917416 16216 server_base.cc:1061] running on GCE node
W20260812 06:20:19.917377 16564 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:19.917335 16565 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:19.917768 16216 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:19.917841 16216 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:19.917870 16216 hybrid_clock.cc:648] HybridClock initialized: now 1786515619917870 us; error 0 us; skew 500 ppm
I20260812 06:20:19.918855 16216 webserver.cc:533] Webserver started at http://127.15.214.1:39971/ using document root <none> and password file <none>
I20260812 06:20:19.919063 16216 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:19.919140 16216 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:19.919236 16216 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:19.919683 16216 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/instance:
uuid: "c53e5c667aa74e8686994f8a8297a7d2"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-vxj2"
I20260812 06:20:19.921495 16216 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:19.922617 16575 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.922976 16216 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:19.923076 16216 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root
uuid: "c53e5c667aa74e8686994f8a8297a7d2"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-vxj2"
I20260812 06:20:19.923174 16216 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:19.929469 16216 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:19.929983 16216 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:19.930335 16216 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:19.930863 16216 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:19.930938 16216 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.931026 16216 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:19.931077 16216 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.935895 16216 rpc_server.cc:307] RPC server started. Bound to: 127.15.214.1:35927
I20260812 06:20:19.937435 16654 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.214.1:35927 every 8 connection(s)
I20260812 06:20:19.947062 16655 heartbeater.cc:344] Connected to a master server at 127.15.214.62:44363
I20260812 06:20:19.947248 16655 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:19.947553 16655 heartbeater.cc:507] Master 127.15.214.62:44363 requested a full tablet report, sending...
I20260812 06:20:19.948465 16498 ts_manager.cc:194] Registered new tserver with Master: c53e5c667aa74e8686994f8a8297a7d2 (127.15.214.1:35927)
I20260812 06:20:19.949290 16216 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012359655s
I20260812 06:20:19.949445 16498 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:48546
I20260812 06:20:19.960201 16498 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:48562:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:19.971218 16605 tablet_service.cc:1511] Processing CreateTablet for tablet 249946902ecf46ec99bb90da9751022a (DEFAULT_TABLE table=heavy-update-compaction-test [id=115938c8733a47cd82ef99b8cb56d2af]), partition=
I20260812 06:20:19.971529 16605 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 249946902ecf46ec99bb90da9751022a. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:19.974535 16670 tablet_bootstrap.cc:492] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Bootstrap starting.
I20260812 06:20:19.975720 16670 tablet_bootstrap.cc:654] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:19.977438 16670 tablet_bootstrap.cc:492] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: No bootstrap required, opened a new log
I20260812 06:20:19.977691 16670 ts_tablet_manager.cc:1403] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:19.978335 16670 raft_consensus.cc:359] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c53e5c667aa74e8686994f8a8297a7d2" member_type: VOTER last_known_addr { host: "127.15.214.1" port: 35927 } }
I20260812 06:20:19.978490 16670 raft_consensus.cc:385] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:19.978530 16670 raft_consensus.cc:740] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c53e5c667aa74e8686994f8a8297a7d2, State: Initialized, Role: FOLLOWER
I20260812 06:20:19.978683 16670 consensus_queue.cc:260] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2 [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: "c53e5c667aa74e8686994f8a8297a7d2" member_type: VOTER last_known_addr { host: "127.15.214.1" port: 35927 } }
I20260812 06:20:19.978770 16670 raft_consensus.cc:399] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:19.978796 16670 raft_consensus.cc:493] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:19.978830 16670 raft_consensus.cc:3060] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:19.979712 16670 raft_consensus.cc:515] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c53e5c667aa74e8686994f8a8297a7d2" member_type: VOTER last_known_addr { host: "127.15.214.1" port: 35927 } }
I20260812 06:20:19.979869 16670 leader_election.cc:304] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2 [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: c53e5c667aa74e8686994f8a8297a7d2; no voters: 
I20260812 06:20:19.980096 16670 leader_election.cc:290] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:19.980290 16672 raft_consensus.cc:2804] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:19.980527 16670 ts_tablet_manager.cc:1434] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:19.980552 16655 heartbeater.cc:499] Master 127.15.214.62:44363 was elected leader, sending a full tablet report...
I20260812 06:20:19.980561 16672 raft_consensus.cc:697] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2 [term 1 LEADER]: Becoming Leader. State: Replica: c53e5c667aa74e8686994f8a8297a7d2, State: Running, Role: LEADER
I20260812 06:20:19.980834 16672 consensus_queue.cc:237] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2 [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: "c53e5c667aa74e8686994f8a8297a7d2" member_type: VOTER last_known_addr { host: "127.15.214.1" port: 35927 } }
I20260812 06:20:19.983044 16498 catalog_manager.cc:5719] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2 reported cstate change: term changed from 0 to 1, leader changed from <none> to c53e5c667aa74e8686994f8a8297a7d2 (127.15.214.1). New cstate: current_term: 1 leader_uuid: "c53e5c667aa74e8686994f8a8297a7d2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c53e5c667aa74e8686994f8a8297a7d2" member_type: VOTER last_known_addr { host: "127.15.214.1" port: 35927 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:20.053289 16216 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.064s	user 0.017s	sys 0.007s
I20260812 06:20:20.188185 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushMRSOp(249946902ecf46ec99bb90da9751022a): perf score=15.086190
I20260812 06:20:20.323623 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushMRSOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.135s	user 0.078s	sys 0.055s Metrics: {"bytes_written":8943514,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":95,"dirs.run_cpu_time_us":281,"dirs.run_wall_time_us":1071,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":31203,"lbm_writes_lt_1ms":575,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"spinlock_wait_cycles":14080,"update_count":1090}
I20260812 06:20:20.324447 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling LogGCOp(249946902ecf46ec99bb90da9751022a): free 8725963 bytes of WAL
I20260812 06:20:20.324743 16580 log_reader.cc:385] T 249946902ecf46ec99bb90da9751022a: removed 1 log segments from log reader
I20260812 06:20:20.324784 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000001 (ops 1-6)
I20260812 06:20:20.326761 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: LogGCOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:20.327248 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling UndoDeltaBlockGCOp(249946902ecf46ec99bb90da9751022a): 12308959 bytes on disk
I20260812 06:20:20.328002 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: UndoDeltaBlockGCOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":130,"lbm_reads_lt_1ms":4}
I20260812 06:20:20.328902 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=2.188937
I20260812 06:20:20.344180 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.015s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3364205,"delete_count":0,"lbm_write_time_us":5105,"lbm_writes_lt_1ms":85,"reinsert_count":0,"update_count":410}
I20260812 06:20:20.344683 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a): perf score=1.000000
I20260812 06:20:20.467108 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.122s	user 0.086s	sys 0.035s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528882,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":699,"lbm_read_time_us":8652,"lbm_reads_lt_1ms":360,"lbm_write_time_us":19960,"lbm_writes_lt_1ms":343,"mutex_wait_us":73,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":15488,"thread_start_us":398,"threads_started":5,"update_count":1500}
I20260812 06:20:20.467756 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=10.126437
I20260812 06:20:20.517794 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.050s	user 0.035s	sys 0.008s Metrics: {"bytes_written":12307496,"delete_count":0,"lbm_write_time_us":18828,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.518467 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=2.188937
I20260812 06:20:20.529829 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4296,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.530841 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a): perf score=1.000000
I20260812 06:20:20.670437 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.139s	user 0.095s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631318,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":213,"lbm_read_time_us":8713,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24344,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.671236 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=10.126437
I20260812 06:20:20.708590 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.037s	user 0.011s	sys 0.023s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16873,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.709235 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a): perf score=1.000000
I20260812 06:20:20.847482 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.138s	user 0.097s	sys 0.037s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528780,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":271,"lbm_read_time_us":9715,"lbm_reads_lt_1ms":367,"lbm_write_time_us":20791,"lbm_writes_lt_1ms":343,"mutex_wait_us":28,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":14976,"update_count":1500}
I20260812 06:20:20.848344 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=10.126437
I20260812 06:20:20.885627 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.037s	user 0.031s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15339,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.886682 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a): perf score=1.000000
I20260812 06:20:21.006362 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.119s	user 0.086s	sys 0.024s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528782,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":841,"lbm_read_time_us":8190,"lbm_reads_lt_1ms":363,"lbm_write_time_us":19458,"lbm_writes_lt_1ms":343,"mutex_wait_us":314,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":1500}
I20260812 06:20:21.007246 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=10.126437
I20260812 06:20:21.057937 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.050s	user 0.029s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18512,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"mutex_wait_us":2,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.058539 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=2.188937
I20260812 06:20:21.071070 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.012s	user 0.007s	sys 0.004s 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:20:21.071868 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a): perf score=1.000000
I20260812 06:20:21.214829 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.143s	user 0.127s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":374,"lbm_read_time_us":10985,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24763,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17536,"update_count":2000}
I20260812 06:20:21.215600 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=10.126437
I20260812 06:20:21.274659 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.059s	user 0.024s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17439,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.275513 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=2.188937
I20260812 06:20:21.288182 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5073,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.288806 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a): perf score=1.000000
I20260812 06:20:21.464926 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.176s	user 0.115s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1053,"lbm_read_time_us":12041,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27687,"lbm_writes_lt_1ms":443,"mutex_wait_us":317,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2000}
I20260812 06:20:21.465757 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=10.126437
I20260812 06:20:21.524603 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.059s	user 0.039s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":23251,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.525309 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=2.188937
I20260812 06:20:21.537268 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4334,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.538091 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a): perf score=1.000000
I20260812 06:20:21.687973 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.150s	user 0.113s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1052,"lbm_read_time_us":11417,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28747,"lbm_writes_lt_1ms":443,"mutex_wait_us":123,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:20:21.688774 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=10.126437
I20260812 06:20:21.735513 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.047s	user 0.024s	sys 0.019s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":21846,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.736171 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=2.188937
I20260812 06:20:21.750986 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.015s	user 0.002s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5048,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.751667 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushMRSOp(249946902ecf46ec99bb90da9751022a): perf score=1.000000
I20260812 06:20:21.782934 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushMRSOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1193504,"cfile_init":1,"dirs.queue_time_us":95,"dirs.run_cpu_time_us":340,"dirs.run_wall_time_us":1777,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2076,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:21.783684 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling LogGCOp(249946902ecf46ec99bb90da9751022a): free 124710289 bytes of WAL
I20260812 06:20:21.784091 16580 log_reader.cc:385] T 249946902ecf46ec99bb90da9751022a: removed 12 log segments from log reader
I20260812 06:20:21.784143 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000002 (ops 7-11)
I20260812 06:20:21.784181 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000003 (ops 12-16)
I20260812 06:20:21.784271 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000004 (ops 17-21)
I20260812 06:20:21.784340 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000005 (ops 22-26)
I20260812 06:20:21.784395 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000006 (ops 27-31)
I20260812 06:20:21.784466 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000007 (ops 32-36)
I20260812 06:20:21.784502 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000008 (ops 37-41)
I20260812 06:20:21.784549 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000009 (ops 42-46)
I20260812 06:20:21.784595 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000010 (ops 47-51)
I20260812 06:20:21.784641 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000011 (ops 52-56)
I20260812 06:20:21.784685 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000012 (ops 57-61)
I20260812 06:20:21.784730 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000013 (ops 62-66)
I20260812 06:20:21.813525 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: LogGCOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.029s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:20:21.814046 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling UndoDeltaBlockGCOp(249946902ecf46ec99bb90da9751022a): 463 bytes on disk
I20260812 06:20:21.814571 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: UndoDeltaBlockGCOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:20:21.815119 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=4.173312
I20260812 06:20:21.832050 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":5579537,"delete_count":0,"lbm_write_time_us":6723,"lbm_writes_lt_1ms":139,"reinsert_count":0,"update_count":680}
I20260812 06:20:21.832700 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=1.196750
I20260812 06:20:21.843909 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":2625754,"delete_count":0,"lbm_write_time_us":3700,"lbm_writes_lt_1ms":67,"reinsert_count":0,"update_count":320}
I20260812 06:20:21.844475 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a): perf score=1.000000
I20260812 06:20:22.019490 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.175s	user 0.113s	sys 0.059s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836343,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":827,"lbm_read_time_us":11331,"lbm_reads_lt_1ms":666,"lbm_write_time_us":36046,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"mutex_wait_us":103,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4736,"thread_start_us":91,"threads_started":1,"update_count":3000}
I20260812 06:20:22.020311 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=14.095187
I20260812 06:20:22.081198 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.061s	user 0.035s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25544,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.081821 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=2.188937
I20260812 06:20:22.094437 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.012s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4511,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.094954 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a): perf score=1.000000
I20260812 06:20:22.267609 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.172s	user 0.126s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":210,"lbm_read_time_us":9878,"lbm_reads_lt_1ms":572,"lbm_write_time_us":37942,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2500}
I20260812 06:20:22.268433 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=10.126437
I20260812 06:20:22.309605 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.041s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17832,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.310444 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=2.188937
I20260812 06:20:22.330133 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.019s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5521,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.330649 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a): perf score=1.000000
I20260812 06:20:22.502415 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.172s	user 0.130s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":3551,"dirs.run_cpu_time_us":713,"dirs.run_wall_time_us":4208,"lbm_read_time_us":11168,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27327,"lbm_writes_lt_1ms":443,"mutex_wait_us":2991,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2000}
I20260812 06:20:22.503446 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=14.095187
I20260812 06:20:22.565429 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.062s	user 0.033s	sys 0.027s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":30875,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.566265 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=2.188937
I20260812 06:20:22.592259 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.026s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5243,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.593104 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a): perf score=1.000000
I20260812 06:20:22.770090 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.177s	user 0.119s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733726,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":245,"lbm_read_time_us":12340,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29825,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2500}
I20260812 06:20:22.770932 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=14.095187
I20260812 06:20:22.846556 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.075s	user 0.050s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":33658,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.847234 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=2.188937
I20260812 06:20:22.860546 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4430,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.861115 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a): perf score=1.000000
I20260812 06:20:23.057809 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.196s	user 0.129s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":242,"lbm_read_time_us":12017,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31481,"lbm_writes_lt_1ms":543,"mutex_wait_us":68,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":2500}
I20260812 06:20:23.058598 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=14.095187
I20260812 06:20:23.120910 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.062s	user 0.028s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25198,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.121665 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=3.181125
I20260812 06:20:23.135787 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4999,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:23.136371 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=2.188937
I20260812 06:20:23.148046 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4213,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.148846 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a): perf score=1.000000
I20260812 06:20:23.373498 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.224s	user 0.155s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836241,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":633,"lbm_read_time_us":15396,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36812,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16000,"update_count":3000}
I20260812 06:20:23.374265 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=15.087375
I20260812 06:20:23.452606 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.078s	user 0.044s	sys 0.024s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":28463,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":411,"reinsert_count":0,"update_count":2050}
I20260812 06:20:23.453326 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=6.157687
I20260812 06:20:23.474464 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.021s	user 0.011s	sys 0.008s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8299,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:20:23.475299 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushMRSOp(249946902ecf46ec99bb90da9751022a): perf score=1.000000
I20260812 06:20:23.516067 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushMRSOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.041s	user 0.030s	sys 0.003s Metrics: {"bytes_written":1357580,"cfile_init":1,"dirs.queue_time_us":108,"dirs.run_cpu_time_us":320,"dirs.run_wall_time_us":1979,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1948,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:20:23.516945 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling LogGCOp(249946902ecf46ec99bb90da9751022a): free 132571318 bytes of WAL
I20260812 06:20:23.517311 16580 log_reader.cc:385] T 249946902ecf46ec99bb90da9751022a: removed 13 log segments from log reader
I20260812 06:20:23.517385 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000014 (ops 67-71)
I20260812 06:20:23.517426 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000015 (ops 72-76)
I20260812 06:20:23.517450 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000016 (ops 77-80)
I20260812 06:20:23.517484 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000017 (ops 81-85)
I20260812 06:20:23.517519 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000018 (ops 86-90)
I20260812 06:20:23.517551 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000019 (ops 91-95)
I20260812 06:20:23.517578 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000020 (ops 96-100)
I20260812 06:20:23.517609 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000021 (ops 101-105)
I20260812 06:20:23.517637 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000022 (ops 106-110)
I20260812 06:20:23.517663 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000023 (ops 111-115)
I20260812 06:20:23.517696 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000024 (ops 116-120)
I20260812 06:20:23.517724 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000025 (ops 121-124)
I20260812 06:20:23.517748 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000026 (ops 125-129)
I20260812 06:20:23.554291 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: LogGCOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.037s	user 0.000s	sys 0.036s Metrics: {}
I20260812 06:20:23.554841 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling UndoDeltaBlockGCOp(249946902ecf46ec99bb90da9751022a): 506 bytes on disk
I20260812 06:20:23.555390 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: UndoDeltaBlockGCOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:20:23.556222 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=2.188937
I20260812 06:20:23.582046 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.026s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4871,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.582697 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=2.188937
I20260812 06:20:23.594341 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4353,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.595129 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a): perf score=1.000000
I20260812 06:20:23.865593 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.270s	user 0.176s	sys 0.094s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37041197,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":603,"lbm_read_time_us":18145,"lbm_reads_lt_1ms":874,"lbm_write_time_us":49499,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":9472,"thread_start_us":89,"threads_started":1,"update_count":4000}
I20260812 06:20:23.866412 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=18.063937
I20260812 06:20:23.939698 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.073s	user 0.038s	sys 0.032s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":32862,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:23.940532 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=2.188937
I20260812 06:20:23.959940 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.019s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6990,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.960475 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a): perf score=1.000000
I20260812 06:20:24.144582 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.184s	user 0.140s	sys 0.044s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836137,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":381,"lbm_read_time_us":13759,"lbm_reads_lt_1ms":664,"lbm_write_time_us":36496,"lbm_writes_lt_1ms":643,"mutex_wait_us":75,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":3000}
I20260812 06:20:24.145553 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=14.095187
I20260812 06:20:24.205186 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.059s	user 0.034s	sys 0.021s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":25479,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.205897 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=2.188937
I20260812 06:20:24.223995 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.018s	user 0.009s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6994,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.224596 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a): perf score=1.000000
I20260812 06:20:24.407611 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.183s	user 0.123s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733727,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":992,"lbm_read_time_us":11294,"lbm_reads_lt_1ms":568,"lbm_write_time_us":33999,"lbm_writes_lt_1ms":543,"mutex_wait_us":116,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22144,"update_count":2500}
I20260812 06:20:24.408231 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=14.095187
I20260812 06:20:24.475730 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.067s	user 0.036s	sys 0.019s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":24614,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.476461 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=2.188937
I20260812 06:20:24.488411 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4201,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.489269 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a): perf score=1.000000
I20260812 06:20:24.689977 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.200s	user 0.125s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733720,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":301,"lbm_read_time_us":12972,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34734,"lbm_writes_lt_1ms":543,"mutex_wait_us":104,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:20:24.690771 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=14.095187
I20260812 06:20:24.758430 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.067s	user 0.038s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":30235,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.759101 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=2.188937
I20260812 06:20:24.773401 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.014s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5467,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.774063 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a): perf score=1.000000
I20260812 06:20:24.970548 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.196s	user 0.156s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1315,"lbm_read_time_us":15256,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35040,"lbm_writes_lt_1ms":543,"mutex_wait_us":348,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":28032,"update_count":2500}
I20260812 06:20:24.971453 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=14.095187
I20260812 06:20:25.039827 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.068s	user 0.046s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25412,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.040593 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=2.188937
I20260812 06:20:25.053913 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4845,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.054927 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushMRSOp(249946902ecf46ec99bb90da9751022a): perf score=1.000000
I20260812 06:20:25.099670 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushMRSOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.044s	user 0.032s	sys 0.007s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":115,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":1739,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2139,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:25.100476 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling LogGCOp(249946902ecf46ec99bb90da9751022a): free 121006697 bytes of WAL
I20260812 06:20:25.100740 16580 log_reader.cc:385] T 249946902ecf46ec99bb90da9751022a: removed 12 log segments from log reader
I20260812 06:20:25.100791 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000027 (ops 130-134)
I20260812 06:20:25.100822 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000028 (ops 135-138)
I20260812 06:20:25.100893 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000029 (ops 139-143)
I20260812 06:20:25.100925 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000030 (ops 144-148)
I20260812 06:20:25.100963 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000031 (ops 149-153)
I20260812 06:20:25.101004 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000032 (ops 154-158)
I20260812 06:20:25.101044 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000033 (ops 159-163)
I20260812 06:20:25.101084 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000034 (ops 164-168)
I20260812 06:20:25.101123 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000035 (ops 169-173)
I20260812 06:20:25.101200 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000036 (ops 174-178)
I20260812 06:20:25.101246 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000037 (ops 179-183)
I20260812 06:20:25.101285 16580 log.cc:1079] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: Deleting log segment in path: /tmp/dist-test-taskvO0aKF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613778680-16216-0/minicluster-data/ts-0-root/wals/249946902ecf46ec99bb90da9751022a/wal-000000038 (ops 184-188)
I20260812 06:20:25.130517 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: LogGCOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.030s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:20:25.131016 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling UndoDeltaBlockGCOp(249946902ecf46ec99bb90da9751022a): 447 bytes on disk
I20260812 06:20:25.131536 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: UndoDeltaBlockGCOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:20:25.132133 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=3.181125
I20260812 06:20:25.159894 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.027s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7134,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:25.160713 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=2.188937
I20260812 06:20:25.171998 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3956,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:25.172762 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a): perf score=1.000000
I20260812 06:20:25.414394 16216 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.361s	user 1.909s	sys 0.207s
I20260812 06:20:25.417794 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: MajorDeltaCompactionOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.245s	user 0.164s	sys 0.072s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938773,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":346,"lbm_read_time_us":17259,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41508,"lbm_writes_lt_1ms":743,"mutex_wait_us":41,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":21376,"thread_start_us":83,"threads_started":1,"update_count":3500}
I20260812 06:20:25.418581 16656 maintenance_manager.cc:419] P c53e5c667aa74e8686994f8a8297a7d2: Scheduling FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a): perf score=18.063937
I20260812 06:20:25.445917 16216 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.031s	user 0.003s	sys 0.000s
I20260812 06:20:25.446538 16216 tablet_server.cc:179] TabletServer@127.15.214.1:0 shutting down...
I20260812 06:20:25.472074 16580 maintenance_manager.cc:643] P c53e5c667aa74e8686994f8a8297a7d2: FlushDeltaMemStoresOp(249946902ecf46ec99bb90da9751022a) complete. Timing: real 0.053s	user 0.030s	sys 0.020s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":24221,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:25.472766 16216 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:25.472990 16216 tablet_replica.cc:333] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2: stopping tablet replica
I20260812 06:20:25.473143 16216 raft_consensus.cc:2243] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:25.473429 16216 raft_consensus.cc:2272] T 249946902ecf46ec99bb90da9751022a P c53e5c667aa74e8686994f8a8297a7d2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:25.476914 16216 tablet_server.cc:196] TabletServer@127.15.214.1:0 shutdown complete.
I20260812 06:20:25.480077 16216 master.cc:562] Master@127.15.214.62:44363 shutting down...
I20260812 06:20:25.483877 16216 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:25.484127 16216 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:25.484228 16216 tablet_replica.cc:333] T 00000000000000000000000000000000 P 798ac66bdaff47468f5c2b0364461eb6: stopping tablet replica
I20260812 06:20:25.497700 16216 master.cc:584] Master@127.15.214.62:44363 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5794 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11812 ms total)

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