[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:56.263438 30001 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.29.76.126:45637
I20260812 06:19:56.264451 30001 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:56.265003 30001 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:56.271003 30017 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:56.271044 30011 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:56.271267 30001 server_base.cc:1061] running on GCE node
W20260812 06:19:56.271281 30012 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:56.271838 30001 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:56.271950 30001 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:56.271993 30001 hybrid_clock.cc:648] HybridClock initialized: now 1786515596271991 us; error 0 us; skew 500 ppm
I20260812 06:19:56.273633 30001 webserver.cc:533] Webserver started at http://127.29.76.126:33093/ using document root <none> and password file <none>
I20260812 06:19:56.274142 30001 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:56.274207 30001 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:56.274426 30001 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:56.276074 30001 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/master-0-root/instance:
uuid: "5c9426cceba5420b958554bed0c66c98"
format_stamp: "Formatted at 2026-08-12 06:19:56 on dist-test-slave-jlzn"
I20260812 06:19:56.279351 30001 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:56.281383 30027 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:56.282284 30001 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:19:56.282392 30001 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/master-0-root
uuid: "5c9426cceba5420b958554bed0c66c98"
format_stamp: "Formatted at 2026-08-12 06:19:56 on dist-test-slave-jlzn"
I20260812 06:19:56.282480 30001 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:56.301790 30001 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:56.302374 30001 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:56.302525 30001 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:56.309646 30001 rpc_server.cc:307] RPC server started. Bound to: 127.29.76.126:45637
I20260812 06:19:56.309664 30112 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.76.126:45637 every 8 connection(s)
I20260812 06:19:56.311743 30113 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:56.316913 30113 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98: Bootstrap starting.
I20260812 06:19:56.319084 30113 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:56.319908 30113 log.cc:826] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:56.321419 30113 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98: No bootstrap required, opened a new log
I20260812 06:19:56.324038 30113 raft_consensus.cc:359] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5c9426cceba5420b958554bed0c66c98" member_type: VOTER }
I20260812 06:19:56.324195 30113 raft_consensus.cc:385] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:56.324259 30113 raft_consensus.cc:740] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5c9426cceba5420b958554bed0c66c98, State: Initialized, Role: FOLLOWER
I20260812 06:19:56.324884 30113 consensus_queue.cc:260] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98 [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: "5c9426cceba5420b958554bed0c66c98" member_type: VOTER }
I20260812 06:19:56.325037 30113 raft_consensus.cc:399] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:56.325083 30113 raft_consensus.cc:493] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:56.325172 30113 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:56.325847 30113 raft_consensus.cc:515] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5c9426cceba5420b958554bed0c66c98" member_type: VOTER }
I20260812 06:19:56.326216 30113 leader_election.cc:304] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98 [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: 5c9426cceba5420b958554bed0c66c98; no voters: 
I20260812 06:19:56.326455 30113 leader_election.cc:290] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:56.326566 30122 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:56.326787 30122 raft_consensus.cc:697] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98 [term 1 LEADER]: Becoming Leader. State: Replica: 5c9426cceba5420b958554bed0c66c98, State: Running, Role: LEADER
I20260812 06:19:56.327163 30122 consensus_queue.cc:237] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98 [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: "5c9426cceba5420b958554bed0c66c98" member_type: VOTER }
I20260812 06:19:56.327319 30113 sys_catalog.cc:565] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:56.328930 30123 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "5c9426cceba5420b958554bed0c66c98" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5c9426cceba5420b958554bed0c66c98" member_type: VOTER } }
I20260812 06:19:56.329035 30123 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:56.328996 30126 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 5c9426cceba5420b958554bed0c66c98. Latest consensus state: current_term: 1 leader_uuid: "5c9426cceba5420b958554bed0c66c98" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5c9426cceba5420b958554bed0c66c98" member_type: VOTER } }
I20260812 06:19:56.329090 30126 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:56.329460 30143 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:56.329486 30001 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:56.331507 30143 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:56.335634 30143 catalog_manager.cc:1383] Generated new cluster ID: 15c3cb1268884b6abeaf6276e43dba4d
I20260812 06:19:56.335702 30143 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:56.345729 30143 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:56.346756 30143 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:56.356616 30143 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98: Generated new TSK 0
I20260812 06:19:56.357277 30143 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:56.361994 30001 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:56.364851 30151 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:56.365091 30001 server_base.cc:1061] running on GCE node
W20260812 06:19:56.364941 30152 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:56.365092 30156 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:56.365439 30001 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:56.365486 30001 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:56.365500 30001 hybrid_clock.cc:648] HybridClock initialized: now 1786515596365501 us; error 0 us; skew 500 ppm
I20260812 06:19:56.366317 30001 webserver.cc:533] Webserver started at http://127.29.76.65:38963/ using document root <none> and password file <none>
I20260812 06:19:56.366473 30001 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:56.366521 30001 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:56.366602 30001 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:56.366986 30001 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/instance:
uuid: "e6f2c4eba3b748c1af9e028004fd935d"
format_stamp: "Formatted at 2026-08-12 06:19:56 on dist-test-slave-jlzn"
I20260812 06:19:56.368419 30001 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:56.369350 30161 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:56.369608 30001 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:56.369689 30001 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root
uuid: "e6f2c4eba3b748c1af9e028004fd935d"
format_stamp: "Formatted at 2026-08-12 06:19:56 on dist-test-slave-jlzn"
I20260812 06:19:56.369753 30001 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:56.376763 30001 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:56.377182 30001 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:56.377624 30001 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:56.378554 30001 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:56.378618 30001 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:56.378681 30001 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:56.378711 30001 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:56.385254 30001 rpc_server.cc:307] RPC server started. Bound to: 127.29.76.65:42523
I20260812 06:19:56.385428 30278 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.76.65:42523 every 8 connection(s)
I20260812 06:19:56.394714 30280 heartbeater.cc:344] Connected to a master server at 127.29.76.126:45637
I20260812 06:19:56.394932 30280 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:56.395383 30280 heartbeater.cc:507] Master 127.29.76.126:45637 requested a full tablet report, sending...
I20260812 06:19:56.396756 30051 ts_manager.cc:194] Registered new tserver with Master: e6f2c4eba3b748c1af9e028004fd935d (127.29.76.65:42523)
I20260812 06:19:56.397013 30001 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011138506s
I20260812 06:19:56.397946 30051 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:48852
I20260812 06:19:56.406407 30051 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:48866:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:56.420482 30212 tablet_service.cc:1511] Processing CreateTablet for tablet 0f4729f657e54a1598190e18212e7511 (DEFAULT_TABLE table=heavy-update-compaction-test [id=84b3da59f867434c86ee03aa9f5e82a1]), partition=
I20260812 06:19:56.420941 30212 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 0f4729f657e54a1598190e18212e7511. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:56.424208 30301 tablet_bootstrap.cc:492] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Bootstrap starting.
I20260812 06:19:56.425076 30301 tablet_bootstrap.cc:654] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:56.426103 30301 tablet_bootstrap.cc:492] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: No bootstrap required, opened a new log
I20260812 06:19:56.426198 30301 ts_tablet_manager.cc:1403] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:56.426592 30301 raft_consensus.cc:359] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e6f2c4eba3b748c1af9e028004fd935d" member_type: VOTER last_known_addr { host: "127.29.76.65" port: 42523 } }
I20260812 06:19:56.426692 30301 raft_consensus.cc:385] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:56.426723 30301 raft_consensus.cc:740] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e6f2c4eba3b748c1af9e028004fd935d, State: Initialized, Role: FOLLOWER
I20260812 06:19:56.426864 30301 consensus_queue.cc:260] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d [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: "e6f2c4eba3b748c1af9e028004fd935d" member_type: VOTER last_known_addr { host: "127.29.76.65" port: 42523 } }
I20260812 06:19:56.426960 30301 raft_consensus.cc:399] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:56.427003 30301 raft_consensus.cc:493] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:56.427052 30301 raft_consensus.cc:3060] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:56.428118 30301 raft_consensus.cc:515] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e6f2c4eba3b748c1af9e028004fd935d" member_type: VOTER last_known_addr { host: "127.29.76.65" port: 42523 } }
I20260812 06:19:56.428247 30301 leader_election.cc:304] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d [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: e6f2c4eba3b748c1af9e028004fd935d; no voters: 
I20260812 06:19:56.428452 30301 leader_election.cc:290] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:56.428537 30303 raft_consensus.cc:2804] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:56.428725 30303 raft_consensus.cc:697] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d [term 1 LEADER]: Becoming Leader. State: Replica: e6f2c4eba3b748c1af9e028004fd935d, State: Running, Role: LEADER
I20260812 06:19:56.428774 30301 ts_tablet_manager.cc:1434] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:56.429139 30280 heartbeater.cc:499] Master 127.29.76.126:45637 was elected leader, sending a full tablet report...
I20260812 06:19:56.429106 30303 consensus_queue.cc:237] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d [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: "e6f2c4eba3b748c1af9e028004fd935d" member_type: VOTER last_known_addr { host: "127.29.76.65" port: 42523 } }
I20260812 06:19:56.431687 30051 catalog_manager.cc:5719] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d reported cstate change: term changed from 0 to 1, leader changed from <none> to e6f2c4eba3b748c1af9e028004fd935d (127.29.76.65). New cstate: current_term: 1 leader_uuid: "e6f2c4eba3b748c1af9e028004fd935d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e6f2c4eba3b748c1af9e028004fd935d" member_type: VOTER last_known_addr { host: "127.29.76.65" port: 42523 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:56.493997 30001 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.018s	sys 0.008s
I20260812 06:19:56.636554 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushMRSOp(0f4729f657e54a1598190e18212e7511): perf score=19.054940
I20260812 06:19:56.821555 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushMRSOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.185s	user 0.139s	sys 0.044s Metrics: {"bytes_written":16409901,"cfile_init":1,"compiler_manager_pool.queue_time_us":209,"delete_count":0,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":254,"dirs.run_wall_time_us":918,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45598,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":113,"threads_started":1,"update_count":2000}
I20260812 06:19:56.822966 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling LogGCOp(0f4729f657e54a1598190e18212e7511): free 20743880 bytes of WAL
I20260812 06:19:56.823372 30173 log_reader.cc:385] T 0f4729f657e54a1598190e18212e7511: removed 2 log segments from log reader
I20260812 06:19:56.823503 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000001 (ops 1-6)
I20260812 06:19:56.823623 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000002 (ops 7-11)
I20260812 06:19:56.828474 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: LogGCOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.005s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:19:56.828926 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling UndoDeltaBlockGCOp(0f4729f657e54a1598190e18212e7511): 16411394 bytes on disk
I20260812 06:19:56.829588 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: UndoDeltaBlockGCOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:19:56.830111 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=3.181125
I20260812 06:19:56.856601 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.026s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6144,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:56.857180 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=2.188937
I20260812 06:19:56.868876 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4312,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:56.869558 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511): perf score=1.000000
I20260812 06:19:57.058892 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.189s	user 0.134s	sys 0.043s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877206,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1040,"lbm_read_time_us":13650,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":668,"lbm_write_time_us":30378,"lbm_writes_lt_1ms":643,"mutex_wait_us":219,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"thread_start_us":283,"threads_started":5,"update_count":3000}
I20260812 06:19:57.059329 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=14.095187
I20260812 06:19:57.111189 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.052s	user 0.038s	sys 0.000s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":17712,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.111743 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=2.188937
I20260812 06:19:57.126380 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.014s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5317,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.126906 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511): perf score=1.000000
I20260812 06:19:57.279259 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.152s	user 0.090s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":212,"lbm_read_time_us":10612,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24998,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2500}
I20260812 06:19:57.279793 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=14.095187
I20260812 06:19:57.333776 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.054s	user 0.023s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21105,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.334295 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=2.188937
I20260812 06:19:57.344290 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3676,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.344703 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511): perf score=1.000000
I20260812 06:19:57.498215 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.153s	user 0.103s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2100,"lbm_read_time_us":11084,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24142,"lbm_writes_lt_1ms":543,"mutex_wait_us":851,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:57.498749 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=11.118625
I20260812 06:19:57.527652 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.029s	user 0.003s	sys 0.023s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":11906,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:57.528224 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=2.188937
I20260812 06:19:57.555672 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.027s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3816,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:57.556113 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=2.188937
I20260812 06:19:57.565866 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3752,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.566286 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511): perf score=1.000000
I20260812 06:19:57.721096 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.155s	user 0.117s	sys 0.034s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":925,"lbm_read_time_us":10256,"lbm_reads_lt_1ms":573,"lbm_write_time_us":25885,"lbm_writes_lt_1ms":543,"mutex_wait_us":252,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:57.721741 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=11.118625
I20260812 06:19:57.753291 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.031s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":12999,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:57.753849 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=2.188937
I20260812 06:19:57.765056 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3974,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:57.765626 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511): perf score=1.000000
I20260812 06:19:57.888577 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.123s	user 0.089s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672270,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":246,"lbm_read_time_us":7637,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22378,"lbm_writes_lt_1ms":443,"mutex_wait_us":67,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.889428 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=10.126437
I20260812 06:19:57.934551 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.045s	user 0.024s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14342,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:57.935088 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=2.188937
I20260812 06:19:57.950012 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5134,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.950795 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushMRSOp(0f4729f657e54a1598190e18212e7511): perf score=1.000000
I20260812 06:19:57.977931 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushMRSOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.027s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":310,"dirs.run_cpu_time_us":277,"dirs.run_wall_time_us":1464,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1390,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:57.978701 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling LogGCOp(0f4729f657e54a1598190e18212e7511): free 112239303 bytes of WAL
I20260812 06:19:57.978924 30173 log_reader.cc:385] T 0f4729f657e54a1598190e18212e7511: removed 11 log segments from log reader
I20260812 06:19:57.978972 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000003 (ops 12-16)
I20260812 06:19:57.979001 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000004 (ops 17-21)
I20260812 06:19:57.979038 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000005 (ops 22-26)
I20260812 06:19:57.979071 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000006 (ops 27-30)
I20260812 06:19:57.979103 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000007 (ops 31-35)
I20260812 06:19:57.979136 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000008 (ops 36-40)
I20260812 06:19:57.979169 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000009 (ops 41-45)
I20260812 06:19:57.979200 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000010 (ops 46-50)
I20260812 06:19:57.979233 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000011 (ops 51-55)
I20260812 06:19:57.979264 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000012 (ops 56-60)
I20260812 06:19:57.979295 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000013 (ops 61-65)
I20260812 06:19:57.998265 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: LogGCOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.019s	user 0.000s	sys 0.017s Metrics: {}
I20260812 06:19:57.998643 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=3.181125
I20260812 06:19:58.018955 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.020s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6682,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:58.019443 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling UndoDeltaBlockGCOp(0f4729f657e54a1598190e18212e7511): 462 bytes on disk
I20260812 06:19:58.019856 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: UndoDeltaBlockGCOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:19:58.020305 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=2.188937
I20260812 06:19:58.029054 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.009s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3126,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:58.029425 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511): perf score=1.000000
I20260812 06:19:58.194809 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.165s	user 0.116s	sys 0.045s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":412,"lbm_read_time_us":11609,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30336,"lbm_writes_lt_1ms":643,"mutex_wait_us":38,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6528,"thread_start_us":82,"threads_started":1,"update_count":3000}
I20260812 06:19:58.195317 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=14.095187
I20260812 06:19:58.245453 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.050s	user 0.029s	sys 0.015s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":19843,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.246016 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=2.188937
I20260812 06:19:58.255754 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3454,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.256356 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511): perf score=1.000000
I20260812 06:19:58.392491 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.136s	user 0.108s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":220,"lbm_read_time_us":8938,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28312,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16896,"update_count":2500}
I20260812 06:19:58.393078 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=10.126437
I20260812 06:19:58.435739 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.043s	user 0.027s	sys 0.011s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":20753,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:58.436190 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=2.188937
I20260812 06:19:58.448683 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4945,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.449119 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511): perf score=1.000000
I20260812 06:19:58.567489 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.118s	user 0.100s	sys 0.018s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":799,"lbm_read_time_us":8640,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21899,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2000}
I20260812 06:19:58.568053 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=10.126437
I20260812 06:19:58.600888 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.033s	user 0.019s	sys 0.010s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13380,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:58.601310 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=2.188937
I20260812 06:19:58.611181 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3603,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.611783 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511): perf score=1.000000
I20260812 06:19:58.726293 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.114s	user 0.094s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":178,"lbm_read_time_us":8032,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22341,"lbm_writes_lt_1ms":443,"mutex_wait_us":54,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.726801 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=10.126437
I20260812 06:19:58.770198 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.043s	user 0.020s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13314,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:58.770738 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=2.188937
I20260812 06:19:58.780860 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3794,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.781275 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511): perf score=1.000000
I20260812 06:19:58.919574 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.138s	user 0.086s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":241,"lbm_read_time_us":10215,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22054,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:19:58.920275 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=10.126437
I20260812 06:19:58.958400 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.038s	user 0.019s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15678,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:58.958923 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=2.188937
I20260812 06:19:58.974305 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5548,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.974836 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511): perf score=1.000000
I20260812 06:19:59.091677 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.117s	user 0.100s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":937,"lbm_read_time_us":7931,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21947,"lbm_writes_lt_1ms":443,"mutex_wait_us":273,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:19:59.092203 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=10.126437
I20260812 06:19:59.126665 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.034s	user 0.016s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12339,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:59.127118 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=2.188937
I20260812 06:19:59.141551 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.014s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5326,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.142025 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511): perf score=1.000000
I20260812 06:19:59.261703 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.119s	user 0.108s	sys 0.008s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":815,"lbm_read_time_us":9030,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21679,"lbm_writes_lt_1ms":443,"mutex_wait_us":228,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.262216 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=10.126437
I20260812 06:19:59.308076 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.046s	user 0.032s	sys 0.002s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12059,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:59.308625 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=2.188937
I20260812 06:19:59.318933 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3760,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.319507 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushMRSOp(0f4729f657e54a1598190e18212e7511): perf score=1.000000
I20260812 06:19:59.357122 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushMRSOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.037s	user 0.024s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":170,"dirs.run_wall_time_us":1329,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1586,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:59.357831 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling LogGCOp(0f4729f657e54a1598190e18212e7511): free 132571314 bytes of WAL
I20260812 06:19:59.358043 30173 log_reader.cc:385] T 0f4729f657e54a1598190e18212e7511: removed 13 log segments from log reader
I20260812 06:19:59.358090 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000014 (ops 66-70)
I20260812 06:19:59.358119 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000015 (ops 71-74)
I20260812 06:19:59.358151 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000016 (ops 75-79)
I20260812 06:19:59.358183 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000017 (ops 80-84)
I20260812 06:19:59.358215 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000018 (ops 85-89)
I20260812 06:19:59.358255 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000019 (ops 90-94)
I20260812 06:19:59.358287 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000020 (ops 95-99)
I20260812 06:19:59.358319 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000021 (ops 100-104)
I20260812 06:19:59.358351 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000022 (ops 105-109)
I20260812 06:19:59.358382 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000023 (ops 110-114)
I20260812 06:19:59.358413 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000024 (ops 115-119)
I20260812 06:19:59.358445 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000025 (ops 120-124)
I20260812 06:19:59.358476 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000026 (ops 125-128)
I20260812 06:19:59.380828 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: LogGCOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.023s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:19:59.381302 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling UndoDeltaBlockGCOp(0f4729f657e54a1598190e18212e7511): 482 bytes on disk
I20260812 06:19:59.381776 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: UndoDeltaBlockGCOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:19:59.382311 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=2.188937
I20260812 06:19:59.403085 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.021s	user 0.000s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5506,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.403546 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=2.188937
I20260812 06:19:59.413127 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3427,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.413548 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511): perf score=1.000000
I20260812 06:19:59.597661 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.184s	user 0.120s	sys 0.063s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877340,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1384,"lbm_read_time_us":11078,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30978,"lbm_writes_lt_1ms":643,"mutex_wait_us":917,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":75,"threads_started":1,"update_count":3000}
I20260812 06:19:59.598217 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=14.095187
I20260812 06:19:59.651772 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.053s	user 0.027s	sys 0.015s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19176,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.652314 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=2.188937
I20260812 06:19:59.667124 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5238,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.667713 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511): perf score=1.000000
I20260812 06:19:59.833827 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.166s	user 0.124s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":544,"lbm_read_time_us":11970,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26649,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2500}
I20260812 06:19:59.834338 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=14.095187
I20260812 06:19:59.890298 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.056s	user 0.043s	sys 0.005s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20727,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.890795 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=2.188937
I20260812 06:19:59.901259 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3829,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.901739 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511): perf score=1.000000
I20260812 06:20:00.073954 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.172s	user 0.107s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":902,"lbm_read_time_us":10419,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26718,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2500}
I20260812 06:20:00.074558 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=14.095187
I20260812 06:20:00.125337 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.051s	user 0.030s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19740,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.125897 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=2.188937
I20260812 06:20:00.136178 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3881,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.136684 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511): perf score=1.000000
I20260812 06:20:00.322504 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.186s	user 0.119s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":577,"lbm_read_time_us":13662,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28720,"lbm_writes_lt_1ms":543,"mutex_wait_us":308,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2500}
I20260812 06:20:00.323071 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=14.095187
I20260812 06:20:00.369964 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.047s	user 0.026s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19788,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.370503 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=2.188937
I20260812 06:20:00.389374 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.019s	user 0.010s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3855,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.389900 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511): perf score=1.000000
I20260812 06:20:00.571195 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.181s	user 0.109s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":478,"lbm_read_time_us":12631,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29779,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15232,"update_count":2500}
I20260812 06:20:00.571698 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=14.095187
I20260812 06:20:00.620469 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.049s	user 0.021s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22317,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.621047 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=2.188937
I20260812 06:20:00.633196 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4530,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.633689 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511): perf score=1.000000
I20260812 06:20:00.811024 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.177s	user 0.119s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":821,"lbm_read_time_us":10004,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30848,"lbm_writes_lt_1ms":543,"mutex_wait_us":341,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21120,"update_count":2500}
I20260812 06:20:00.811641 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=14.095187
I20260812 06:20:00.860975 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.049s	user 0.028s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20172,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.861454 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=2.188937
I20260812 06:20:00.877748 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.016s	user 0.010s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5387,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.878252 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushMRSOp(0f4729f657e54a1598190e18212e7511): perf score=1.000000
I20260812 06:20:00.906373 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushMRSOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.027s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":208,"dirs.run_wall_time_us":1486,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1600,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:00.907080 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling LogGCOp(0f4729f657e54a1598190e18212e7511): free 133477700 bytes of WAL
I20260812 06:20:00.907315 30173 log_reader.cc:385] T 0f4729f657e54a1598190e18212e7511: removed 13 log segments from log reader
I20260812 06:20:00.907361 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000027 (ops 129-133)
I20260812 06:20:00.907387 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000028 (ops 134-138)
I20260812 06:20:00.907418 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000029 (ops 139-143)
I20260812 06:20:00.907450 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000030 (ops 144-148)
I20260812 06:20:00.907481 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000031 (ops 149-153)
I20260812 06:20:00.907523 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000032 (ops 154-158)
I20260812 06:20:00.907545 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000033 (ops 159-163)
I20260812 06:20:00.907577 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000034 (ops 164-168)
I20260812 06:20:00.907617 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000035 (ops 169-173)
I20260812 06:20:00.907649 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000036 (ops 174-178)
I20260812 06:20:00.907680 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000037 (ops 179-183)
I20260812 06:20:00.907711 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000038 (ops 184-188)
I20260812 06:20:00.907742 30173 log.cc:1079] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/0f4729f657e54a1598190e18212e7511/wal-000000039 (ops 189-193)
I20260812 06:20:00.930155 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: LogGCOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.023s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:20:00.930521 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling UndoDeltaBlockGCOp(0f4729f657e54a1598190e18212e7511): 493 bytes on disk
I20260812 06:20:00.930927 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: UndoDeltaBlockGCOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:20:00.931540 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=4.173312
I20260812 06:20:00.949450 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.018s	user 0.008s	sys 0.008s Metrics: {"bytes_written":5948753,"delete_count":0,"lbm_write_time_us":7213,"lbm_writes_lt_1ms":148,"reinsert_count":0,"update_count":725}
I20260812 06:20:00.949950 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511): perf score=1.196750
I20260812 06:20:00.960263 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: FlushDeltaMemStoresOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":2256529,"delete_count":0,"lbm_write_time_us":3255,"lbm_writes_lt_1ms":58,"reinsert_count":0,"update_count":275}
I20260812 06:20:00.960932 30282 maintenance_manager.cc:419] P e6f2c4eba3b748c1af9e028004fd935d: Scheduling MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511): perf score=1.000000
I20260812 06:20:01.042054 30001 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.548s	user 1.664s	sys 0.143s
I20260812 06:20:01.141824 30001 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.099s	user 0.001s	sys 0.000s
I20260812 06:20:01.142458 30001 tablet_server.cc:179] TabletServer@127.29.76.65:0 shutting down...
I20260812 06:20:01.157526 30173 maintenance_manager.cc:643] P e6f2c4eba3b748c1af9e028004fd935d: MajorDeltaCompactionOp(0f4729f657e54a1598190e18212e7511) complete. Timing: real 0.196s	user 0.098s	sys 0.095s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979709,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1944,"lbm_read_time_us":16094,"lbm_reads_lt_1ms":770,"lbm_write_time_us":29504,"lbm_writes_lt_1ms":743,"mutex_wait_us":1591,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":18048,"thread_start_us":74,"threads_started":1,"update_count":3500}
I20260812 06:20:01.158056 30001 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:01.158493 30001 tablet_replica.cc:333] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d: stopping tablet replica
I20260812 06:20:01.158716 30001 raft_consensus.cc:2243] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:01.158952 30001 raft_consensus.cc:2272] T 0f4729f657e54a1598190e18212e7511 P e6f2c4eba3b748c1af9e028004fd935d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:01.174878 30001 tablet_server.cc:196] TabletServer@127.29.76.65:0 shutdown complete.
I20260812 06:20:01.213740 30001 master.cc:562] Master@127.29.76.126:45637 shutting down...
I20260812 06:20:01.217628 30001 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:01.217797 30001 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:01.217851 30001 tablet_replica.cc:333] T 00000000000000000000000000000000 P 5c9426cceba5420b958554bed0c66c98: stopping tablet replica
I20260812 06:20:01.229941 30001 master.cc:584] Master@127.29.76.126:45637 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5034 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:01.308446 30001 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.29.76.126:39283
I20260812 06:20:01.308835 30001 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:01.310962 30331 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:01.311025 30328 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:01.311044 30001 server_base.cc:1061] running on GCE node
W20260812 06:20:01.311025 30335 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:01.311414 30001 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:01.311462 30001 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:01.311478 30001 hybrid_clock.cc:648] HybridClock initialized: now 1786515601311478 us; error 0 us; skew 500 ppm
I20260812 06:20:01.312327 30001 webserver.cc:533] Webserver started at http://127.29.76.126:35417/ using document root <none> and password file <none>
I20260812 06:20:01.312481 30001 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:01.312527 30001 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:01.312604 30001 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:01.312973 30001 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/master-0-root/instance:
uuid: "b5bd273ccf9642a4a90fb75d8e609f79"
format_stamp: "Formatted at 2026-08-12 06:20:01 on dist-test-slave-jlzn"
I20260812 06:20:01.314383 30001 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:01.315233 30342 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:01.315433 30001 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:01.315501 30001 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/master-0-root
uuid: "b5bd273ccf9642a4a90fb75d8e609f79"
format_stamp: "Formatted at 2026-08-12 06:20:01 on dist-test-slave-jlzn"
I20260812 06:20:01.315569 30001 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-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:01.348816 30001 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:01.349252 30001 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:01.353327 30001 rpc_server.cc:307] RPC server started. Bound to: 127.29.76.126:39283
I20260812 06:20:01.356408 30420 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.76.126:39283 every 8 connection(s)
I20260812 06:20:01.357569 30426 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:01.359481 30426 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79: Bootstrap starting.
I20260812 06:20:01.360355 30426 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:01.361382 30426 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79: No bootstrap required, opened a new log
I20260812 06:20:01.361830 30426 raft_consensus.cc:359] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b5bd273ccf9642a4a90fb75d8e609f79" member_type: VOTER }
I20260812 06:20:01.361925 30426 raft_consensus.cc:385] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:01.361948 30426 raft_consensus.cc:740] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b5bd273ccf9642a4a90fb75d8e609f79, State: Initialized, Role: FOLLOWER
I20260812 06:20:01.362047 30426 consensus_queue.cc:260] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79 [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: "b5bd273ccf9642a4a90fb75d8e609f79" member_type: VOTER }
I20260812 06:20:01.362103 30426 raft_consensus.cc:399] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:01.362124 30426 raft_consensus.cc:493] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:01.362157 30426 raft_consensus.cc:3060] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:01.362850 30426 raft_consensus.cc:515] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b5bd273ccf9642a4a90fb75d8e609f79" member_type: VOTER }
I20260812 06:20:01.362968 30426 leader_election.cc:304] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79 [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: b5bd273ccf9642a4a90fb75d8e609f79; no voters: 
I20260812 06:20:01.363148 30426 leader_election.cc:290] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:01.363260 30431 raft_consensus.cc:2804] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:01.363453 30431 raft_consensus.cc:697] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79 [term 1 LEADER]: Becoming Leader. State: Replica: b5bd273ccf9642a4a90fb75d8e609f79, State: Running, Role: LEADER
I20260812 06:20:01.363591 30426 sys_catalog.cc:565] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:01.363579 30431 consensus_queue.cc:237] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79 [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: "b5bd273ccf9642a4a90fb75d8e609f79" member_type: VOTER }
I20260812 06:20:01.364113 30434 sys_catalog.cc:455] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "b5bd273ccf9642a4a90fb75d8e609f79" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b5bd273ccf9642a4a90fb75d8e609f79" member_type: VOTER } }
I20260812 06:20:01.364151 30437 sys_catalog.cc:455] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79 [sys.catalog]: SysCatalogTable state changed. Reason: New leader b5bd273ccf9642a4a90fb75d8e609f79. Latest consensus state: current_term: 1 leader_uuid: "b5bd273ccf9642a4a90fb75d8e609f79" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b5bd273ccf9642a4a90fb75d8e609f79" member_type: VOTER } }
I20260812 06:20:01.364208 30434 sys_catalog.cc:458] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:01.364238 30437 sys_catalog.cc:458] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:01.364456 30442 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:01.365252 30442 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:01.365404 30001 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:01.367066 30442 catalog_manager.cc:1383] Generated new cluster ID: dcfdc0ba840f434a88312cffd4f02dc0
I20260812 06:20:01.367120 30442 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:01.400499 30442 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:01.401057 30442 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:01.408051 30442 catalog_manager.cc:6092] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79: Generated new TSK 0
I20260812 06:20:01.408211 30442 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:01.430032 30001 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:01.432000 30459 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:01.432123 30001 server_base.cc:1061] running on GCE node
W20260812 06:20:01.432029 30462 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:01.432255 30458 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:01.432435 30001 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:01.432476 30001 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:01.432497 30001 hybrid_clock.cc:648] HybridClock initialized: now 1786515601432496 us; error 0 us; skew 500 ppm
I20260812 06:20:01.433262 30001 webserver.cc:533] Webserver started at http://127.29.76.65:41773/ using document root <none> and password file <none>
I20260812 06:20:01.433403 30001 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:01.433445 30001 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:01.433501 30001 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:01.433871 30001 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/instance:
uuid: "d992d92b0a5e404bbe9659e44542196f"
format_stamp: "Formatted at 2026-08-12 06:20:01 on dist-test-slave-jlzn"
I20260812 06:20:01.435237 30001 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:01.436136 30472 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:01.436367 30001 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:01.436434 30001 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root
uuid: "d992d92b0a5e404bbe9659e44542196f"
format_stamp: "Formatted at 2026-08-12 06:20:01 on dist-test-slave-jlzn"
I20260812 06:20:01.436491 30001 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-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:01.460446 30001 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:01.460825 30001 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:01.461118 30001 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:01.461624 30001 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:01.461669 30001 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:01.461705 30001 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:01.461728 30001 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:01.466193 30001 rpc_server.cc:307] RPC server started. Bound to: 127.29.76.65:38109
I20260812 06:20:01.467669 30569 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.76.65:38109 every 8 connection(s)
I20260812 06:20:01.475688 30571 heartbeater.cc:344] Connected to a master server at 127.29.76.126:39283
I20260812 06:20:01.475867 30571 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:01.476123 30571 heartbeater.cc:507] Master 127.29.76.126:39283 requested a full tablet report, sending...
I20260812 06:20:01.476866 30365 ts_manager.cc:194] Registered new tserver with Master: d992d92b0a5e404bbe9659e44542196f (127.29.76.65:38109)
I20260812 06:20:01.476974 30001 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010042188s
I20260812 06:20:01.477936 30365 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:36058
I20260812 06:20:01.484088 30365 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:36072:
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:01.492574 30517 tablet_service.cc:1511] Processing CreateTablet for tablet 17156467415e4a05a83ab8f9723008d1 (DEFAULT_TABLE table=heavy-update-compaction-test [id=5ce5d5da2c2d4d808c72d52a77f8acdb]), partition=
I20260812 06:20:01.492863 30517 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 17156467415e4a05a83ab8f9723008d1. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:01.494825 30591 tablet_bootstrap.cc:492] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Bootstrap starting.
I20260812 06:20:01.495754 30591 tablet_bootstrap.cc:654] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:01.497042 30591 tablet_bootstrap.cc:492] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: No bootstrap required, opened a new log
I20260812 06:20:01.497138 30591 ts_tablet_manager.cc:1403] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:01.497572 30591 raft_consensus.cc:359] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d992d92b0a5e404bbe9659e44542196f" member_type: VOTER last_known_addr { host: "127.29.76.65" port: 38109 } }
I20260812 06:20:01.497679 30591 raft_consensus.cc:385] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:01.497711 30591 raft_consensus.cc:740] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d992d92b0a5e404bbe9659e44542196f, State: Initialized, Role: FOLLOWER
I20260812 06:20:01.497833 30591 consensus_queue.cc:260] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f [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: "d992d92b0a5e404bbe9659e44542196f" member_type: VOTER last_known_addr { host: "127.29.76.65" port: 38109 } }
I20260812 06:20:01.497938 30591 raft_consensus.cc:399] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:01.497984 30591 raft_consensus.cc:493] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:01.498035 30591 raft_consensus.cc:3060] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:01.498834 30591 raft_consensus.cc:515] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d992d92b0a5e404bbe9659e44542196f" member_type: VOTER last_known_addr { host: "127.29.76.65" port: 38109 } }
I20260812 06:20:01.498957 30591 leader_election.cc:304] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f [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: d992d92b0a5e404bbe9659e44542196f; no voters: 
I20260812 06:20:01.499148 30591 leader_election.cc:290] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:01.499301 30596 raft_consensus.cc:2804] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:01.499450 30571 heartbeater.cc:499] Master 127.29.76.126:39283 was elected leader, sending a full tablet report...
I20260812 06:20:01.499523 30596 raft_consensus.cc:697] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f [term 1 LEADER]: Becoming Leader. State: Replica: d992d92b0a5e404bbe9659e44542196f, State: Running, Role: LEADER
I20260812 06:20:01.499653 30591 ts_tablet_manager.cc:1434] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:01.499706 30596 consensus_queue.cc:237] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f [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: "d992d92b0a5e404bbe9659e44542196f" member_type: VOTER last_known_addr { host: "127.29.76.65" port: 38109 } }
I20260812 06:20:01.501032 30365 catalog_manager.cc:5719] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f reported cstate change: term changed from 0 to 1, leader changed from <none> to d992d92b0a5e404bbe9659e44542196f (127.29.76.65). New cstate: current_term: 1 leader_uuid: "d992d92b0a5e404bbe9659e44542196f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d992d92b0a5e404bbe9659e44542196f" member_type: VOTER last_known_addr { host: "127.29.76.65" port: 38109 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:01.559017 30001 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.022s	sys 0.001s
I20260812 06:20:01.718104 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushMRSOp(17156467415e4a05a83ab8f9723008d1): perf score=23.023690
I20260812 06:20:01.875411 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushMRSOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.157s	user 0.126s	sys 0.028s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":176,"dirs.run_wall_time_us":801,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40127,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:20:01.876199 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling LogGCOp(17156467415e4a05a83ab8f9723008d1): free 20743880 bytes of WAL
I20260812 06:20:01.876449 30480 log_reader.cc:385] T 17156467415e4a05a83ab8f9723008d1: removed 2 log segments from log reader
I20260812 06:20:01.876502 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000001 (ops 1-6)
I20260812 06:20:01.876541 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000002 (ops 7-11)
I20260812 06:20:01.880031 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: LogGCOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:01.880353 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling UndoDeltaBlockGCOp(17156467415e4a05a83ab8f9723008d1): 20513811 bytes on disk
I20260812 06:20:01.880743 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: UndoDeltaBlockGCOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:20:01.881111 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=2.188937
I20260812 06:20:01.893358 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4628,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.893899 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1): perf score=1.000000
I20260812 06:20:02.024643 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.131s	user 0.079s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":448,"lbm_read_time_us":8991,"lbm_reads_lt_1ms":460,"lbm_write_time_us":20845,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"thread_start_us":327,"threads_started":5,"update_count":2000}
I20260812 06:20:02.025290 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=10.126437
I20260812 06:20:02.052886 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.027s	user 0.014s	sys 0.012s Metrics: {"bytes_written":12348516,"delete_count":0,"lbm_write_time_us":11755,"lbm_writes_lt_1ms":304,"reinsert_count":0,"update_count":1505}
I20260812 06:20:02.053347 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=2.188937
I20260812 06:20:02.071768 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.018s	user 0.000s	sys 0.011s Metrics: {"bytes_written":4061634,"delete_count":0,"lbm_write_time_us":4875,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":495}
I20260812 06:20:02.072237 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1): perf score=1.000000
I20260812 06:20:02.215875 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.143s	user 0.110s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":135,"lbm_read_time_us":9631,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21086,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2000}
I20260812 06:20:02.216414 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=14.095187
I20260812 06:20:02.260175 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.044s	user 0.026s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17123,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.260697 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=2.188937
I20260812 06:20:02.277944 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.017s	user 0.000s	sys 0.015s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3671,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.278575 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1): perf score=1.000000
I20260812 06:20:02.463716 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.185s	user 0.109s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":885,"lbm_read_time_us":11523,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29201,"lbm_writes_lt_1ms":543,"mutex_wait_us":286,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:20:02.464178 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=14.095187
I20260812 06:20:02.508733 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.044s	user 0.022s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16466,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.509248 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=2.188937
I20260812 06:20:02.519133 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3685,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.519748 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1): perf score=1.000000
I20260812 06:20:02.693689 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.174s	user 0.119s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":931,"lbm_read_time_us":10702,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26243,"lbm_writes_lt_1ms":543,"mutex_wait_us":313,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17920,"update_count":2500}
I20260812 06:20:02.694180 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=14.095187
I20260812 06:20:02.740681 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.046s	user 0.022s	sys 0.023s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18442,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.741235 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=2.188937
I20260812 06:20:02.753288 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.012s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3635,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.753768 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1): perf score=1.000000
I20260812 06:20:02.908500 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.155s	user 0.122s	sys 0.025s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":899,"lbm_read_time_us":8766,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27001,"lbm_writes_lt_1ms":543,"mutex_wait_us":274,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:20:02.909060 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=14.095187
I20260812 06:20:02.952247 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.043s	user 0.027s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16722,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.952787 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=2.188937
I20260812 06:20:02.962606 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3669,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.963186 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushMRSOp(17156467415e4a05a83ab8f9723008d1): perf score=1.000000
I20260812 06:20:02.994271 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushMRSOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":246,"dirs.run_wall_time_us":1274,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1926,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:02.994865 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling LogGCOp(17156467415e4a05a83ab8f9723008d1): free 112692367 bytes of WAL
I20260812 06:20:02.995083 30480 log_reader.cc:385] T 17156467415e4a05a83ab8f9723008d1: removed 11 log segments from log reader
I20260812 06:20:02.995141 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000003 (ops 12-16)
I20260812 06:20:02.995169 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000004 (ops 17-21)
I20260812 06:20:02.995199 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000005 (ops 22-26)
I20260812 06:20:02.995230 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000006 (ops 27-31)
I20260812 06:20:02.995255 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000007 (ops 32-36)
I20260812 06:20:02.995287 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000008 (ops 37-41)
I20260812 06:20:02.995325 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000009 (ops 42-46)
I20260812 06:20:02.995357 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000010 (ops 47-51)
I20260812 06:20:02.995389 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000011 (ops 52-56)
I20260812 06:20:02.995421 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000012 (ops 57-61)
I20260812 06:20:02.995453 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000013 (ops 62-66)
I20260812 06:20:03.013938 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: LogGCOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.019s	user 0.000s	sys 0.017s Metrics: {}
I20260812 06:20:03.014410 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=2.188937
I20260812 06:20:03.039098 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.025s	user 0.010s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4560,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.039517 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=2.188937
I20260812 06:20:03.049180 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3666,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.049562 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling UndoDeltaBlockGCOp(17156467415e4a05a83ab8f9723008d1): 447 bytes on disk
I20260812 06:20:03.049930 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: UndoDeltaBlockGCOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:20:03.050338 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1): perf score=1.000000
I20260812 06:20:03.276770 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.226s	user 0.144s	sys 0.078s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020743,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1326,"lbm_read_time_us":14555,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36731,"lbm_writes_lt_1ms":743,"mutex_wait_us":1113,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":76,"threads_started":1,"update_count":3500}
I20260812 06:20:03.277307 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=15.087375
I20260812 06:20:03.323171 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.046s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":20016,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:03.323702 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=2.188937
I20260812 06:20:03.334591 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4132,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:03.334998 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1): perf score=1.000000
I20260812 06:20:03.509760 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.175s	user 0.127s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815672,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":653,"lbm_read_time_us":10767,"lbm_reads_lt_1ms":568,"lbm_write_time_us":30231,"lbm_writes_lt_1ms":543,"mutex_wait_us":283,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:03.510319 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=14.095187
I20260812 06:20:03.562152 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.052s	user 0.037s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18224,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.562721 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=2.188937
I20260812 06:20:03.575208 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4396,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.575645 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1): perf score=1.000000
I20260812 06:20:03.739885 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.164s	user 0.108s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":221,"lbm_read_time_us":10822,"lbm_reads_lt_1ms":568,"lbm_write_time_us":24835,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:03.740774 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=14.095187
I20260812 06:20:03.802434 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.061s	user 0.032s	sys 0.024s Metrics: {"bytes_written":16409939,"delete_count":0,"lbm_write_time_us":21202,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.803048 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=2.188937
I20260812 06:20:03.818110 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5584,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.818624 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1): perf score=1.000000
I20260812 06:20:03.991940 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.173s	user 0.113s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815721,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":276,"lbm_read_time_us":11865,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27242,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:20:03.992496 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=14.095187
I20260812 06:20:04.037434 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.045s	user 0.029s	sys 0.009s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17098,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.037925 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=2.188937
I20260812 06:20:04.047598 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3639,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.048200 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1): perf score=1.000000
I20260812 06:20:04.206982 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.158s	user 0.090s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":576,"lbm_read_time_us":8907,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24973,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2500}
I20260812 06:20:04.207538 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=14.095187
I20260812 06:20:04.255605 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.048s	user 0.011s	sys 0.032s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20018,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.256178 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=2.188937
I20260812 06:20:04.266145 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3559,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.266692 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1): perf score=1.000000
I20260812 06:20:04.414789 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.148s	user 0.103s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":499,"lbm_read_time_us":9058,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27386,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:20:04.415447 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=11.118625
I20260812 06:20:04.455761 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.040s	user 0.033s	sys 0.002s Metrics: {"bytes_written":13456166,"delete_count":0,"lbm_write_time_us":16292,"lbm_writes_lt_1ms":331,"mutex_wait_us":126,"reinsert_count":0,"update_count":1640}
I20260812 06:20:04.456349 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=2.188937
I20260812 06:20:04.475320 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.019s	user 0.005s	sys 0.006s Metrics: {"bytes_written":3364209,"delete_count":0,"lbm_write_time_us":4637,"lbm_writes_lt_1ms":85,"reinsert_count":0,"update_count":410}
I20260812 06:20:04.475845 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=2.188937
I20260812 06:20:04.484929 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3164,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:04.485394 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushMRSOp(17156467415e4a05a83ab8f9723008d1): perf score=1.000000
I20260812 06:20:04.517884 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushMRSOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.032s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":234,"dirs.run_wall_time_us":1932,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1386,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:04.518540 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling LogGCOp(17156467415e4a05a83ab8f9723008d1): free 136275181 bytes of WAL
I20260812 06:20:04.518770 30480 log_reader.cc:385] T 17156467415e4a05a83ab8f9723008d1: removed 13 log segments from log reader
I20260812 06:20:04.518829 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000014 (ops 67-71)
I20260812 06:20:04.518872 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000015 (ops 72-76)
I20260812 06:20:04.518905 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000016 (ops 77-81)
I20260812 06:20:04.518936 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000017 (ops 82-86)
I20260812 06:20:04.518965 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000018 (ops 87-91)
I20260812 06:20:04.518991 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000019 (ops 92-96)
I20260812 06:20:04.519029 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000020 (ops 97-101)
I20260812 06:20:04.519062 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000021 (ops 102-106)
I20260812 06:20:04.519091 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000022 (ops 107-111)
I20260812 06:20:04.519119 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000023 (ops 112-116)
I20260812 06:20:04.519146 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000024 (ops 117-121)
I20260812 06:20:04.519176 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000025 (ops 122-126)
I20260812 06:20:04.519207 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000026 (ops 127-130)
I20260812 06:20:04.546561 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: LogGCOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:04.546994 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=3.181125
I20260812 06:20:04.569928 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.023s	user 0.014s	sys 0.004s Metrics: {"bytes_written":4512901,"delete_count":0,"lbm_write_time_us":7122,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:04.570448 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling UndoDeltaBlockGCOp(17156467415e4a05a83ab8f9723008d1): 492 bytes on disk
I20260812 06:20:04.570959 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: UndoDeltaBlockGCOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:20:04.571501 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=2.188937
I20260812 06:20:04.580950 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3430,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:04.581521 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1): perf score=1.000000
I20260812 06:20:04.803930 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.222s	user 0.151s	sys 0.064s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020825,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":291,"lbm_read_time_us":16599,"lbm_reads_lt_1ms":775,"lbm_write_time_us":32761,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":92,"threads_started":1,"update_count":3500}
I20260812 06:20:04.804454 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=18.063937
I20260812 06:20:04.865476 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.061s	user 0.032s	sys 0.015s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":21340,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:04.865988 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=2.188937
I20260812 06:20:04.880155 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5061,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.880689 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1): perf score=1.000000
I20260812 06:20:05.063982 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.183s	user 0.112s	sys 0.068s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918100,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":440,"lbm_read_time_us":12133,"lbm_reads_lt_1ms":672,"lbm_write_time_us":28608,"lbm_writes_lt_1ms":643,"mutex_wait_us":96,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":3000}
I20260812 06:20:05.064670 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=14.095187
I20260812 06:20:05.113551 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.049s	user 0.022s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21614,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.114055 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=2.188937
I20260812 06:20:05.124764 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.011s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3779,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.125191 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1): perf score=1.000000
I20260812 06:20:05.287057 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.162s	user 0.103s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":600,"lbm_read_time_us":10749,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26767,"lbm_writes_lt_1ms":543,"mutex_wait_us":280,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:20:05.287627 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=14.095187
I20260812 06:20:05.346913 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.059s	user 0.024s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21658,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.347599 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=2.188937
I20260812 06:20:05.363119 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5911,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.363662 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1): perf score=1.000000
I20260812 06:20:05.551115 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.187s	user 0.128s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":217,"lbm_read_time_us":15579,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28814,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2500}
I20260812 06:20:05.551681 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=14.095187
I20260812 06:20:05.613096 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.061s	user 0.037s	sys 0.022s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24680,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.613682 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=2.188937
I20260812 06:20:05.625967 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4563,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.626453 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1): perf score=1.000000
I20260812 06:20:05.800493 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.174s	user 0.125s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":909,"lbm_read_time_us":13060,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29995,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:20:05.801187 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=14.095187
I20260812 06:20:05.856343 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.055s	user 0.032s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18763,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.856844 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=2.188937
I20260812 06:20:05.872377 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5899,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.872931 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushMRSOp(17156467415e4a05a83ab8f9723008d1): perf score=1.000000
I20260812 06:20:05.905579 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushMRSOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.032s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":86,"dirs.run_cpu_time_us":211,"dirs.run_wall_time_us":1059,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1294,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:05.906337 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling LogGCOp(17156467415e4a05a83ab8f9723008d1): free 112692618 bytes of WAL
I20260812 06:20:05.906602 30480 log_reader.cc:385] T 17156467415e4a05a83ab8f9723008d1: removed 11 log segments from log reader
I20260812 06:20:05.906674 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000027 (ops 131-135)
I20260812 06:20:05.906715 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000028 (ops 136-140)
I20260812 06:20:05.906749 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000029 (ops 141-145)
I20260812 06:20:05.906780 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000030 (ops 146-150)
I20260812 06:20:05.906810 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000031 (ops 151-155)
I20260812 06:20:05.906842 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000032 (ops 156-160)
I20260812 06:20:05.906872 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000033 (ops 161-165)
I20260812 06:20:05.906896 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000034 (ops 166-170)
I20260812 06:20:05.906926 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000035 (ops 171-175)
I20260812 06:20:05.906957 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000036 (ops 176-180)
I20260812 06:20:05.906988 30480 log.cc:1079] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: Deleting log segment in path: /tmp/dist-test-taskSTrUQG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515596253019-30001-0/minicluster-data/ts-0-root/wals/17156467415e4a05a83ab8f9723008d1/wal-000000037 (ops 181-185)
I20260812 06:20:05.926602 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: LogGCOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.020s	user 0.000s	sys 0.017s Metrics: {}
I20260812 06:20:05.927067 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling UndoDeltaBlockGCOp(17156467415e4a05a83ab8f9723008d1): 448 bytes on disk
I20260812 06:20:05.927583 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: UndoDeltaBlockGCOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:20:05.928211 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=2.188937
I20260812 06:20:05.945652 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.017s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4444,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.946056 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=2.188937
I20260812 06:20:05.955684 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3488,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.956132 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1): perf score=1.000000
I20260812 06:20:06.171746 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.215s	user 0.143s	sys 0.072s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020746,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":285,"lbm_read_time_us":16514,"lbm_reads_lt_1ms":774,"lbm_write_time_us":35875,"lbm_writes_lt_1ms":743,"mutex_wait_us":27,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":107264,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:20:06.172576 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=14.095187
I20260812 06:20:06.199029 30001 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.640s	user 1.685s	sys 0.161s
I20260812 06:20:06.216044 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.043s	user 0.039s	sys 0.004s Metrics: {"bytes_written":16450930,"delete_count":0,"lbm_write_time_us":20184,"lbm_writes_lt_1ms":404,"reinsert_count":0,"update_count":2005}
I20260812 06:20:06.217445 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1): perf score=2.188937
I20260812 06:20:06.228838 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: FlushDeltaMemStoresOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.011s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4061633,"delete_count":0,"lbm_write_time_us":3999,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":495}
I20260812 06:20:06.229380 30572 maintenance_manager.cc:419] P d992d92b0a5e404bbe9659e44542196f: Scheduling MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1): perf score=1.000000
I20260812 06:20:06.234440 30001 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.035s	user 0.000s	sys 0.000s
I20260812 06:20:06.234887 30001 tablet_server.cc:179] TabletServer@127.29.76.65:0 shutting down...
I20260812 06:20:06.361334 30480 maintenance_manager.cc:643] P d992d92b0a5e404bbe9659e44542196f: MajorDeltaCompactionOp(17156467415e4a05a83ab8f9723008d1) complete. Timing: real 0.132s	user 0.104s	sys 0.028s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4303385,"cfile_cache_miss":502,"cfile_cache_miss_bytes":20512301,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":392,"lbm_read_time_us":7438,"lbm_reads_lt_1ms":518,"lbm_write_time_us":22884,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:06.362195 30001 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:06.362442 30001 tablet_replica.cc:333] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f: stopping tablet replica
I20260812 06:20:06.362558 30001 raft_consensus.cc:2243] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:06.362723 30001 raft_consensus.cc:2272] T 17156467415e4a05a83ab8f9723008d1 P d992d92b0a5e404bbe9659e44542196f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:06.367579 30001 tablet_server.cc:196] TabletServer@127.29.76.65:0 shutdown complete.
I20260812 06:20:06.408591 30001 master.cc:562] Master@127.29.76.126:39283 shutting down...
I20260812 06:20:06.412003 30001 raft_consensus.cc:2243] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:06.412180 30001 raft_consensus.cc:2272] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:06.412231 30001 tablet_replica.cc:333] T 00000000000000000000000000000000 P b5bd273ccf9642a4a90fb75d8e609f79: stopping tablet replica
I20260812 06:20:06.424494 30001 master.cc:584] Master@127.29.76.126:39283 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5197 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10232 ms total)

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