[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:20:02.600945 20250 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.19.198.190:36901
I20260812 06:20:02.602134 20250 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:20:02.602798 20250 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:02.609778 20257 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:02.609804 20259 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:02.609863 20250 server_base.cc:1061] running on GCE node
W20260812 06:20:02.610170 20256 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:02.610726 20250 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:02.610857 20250 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:02.610906 20250 hybrid_clock.cc:648] HybridClock initialized: now 1786515602610904 us; error 0 us; skew 500 ppm
I20260812 06:20:02.613065 20250 webserver.cc:533] Webserver started at http://127.19.198.190:35157/ using document root <none> and password file <none>
I20260812 06:20:02.613736 20250 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:02.613806 20250 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:02.614027 20250 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:02.615993 20250 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/master-0-root/instance:
uuid: "be382e8da28047458c14dfe40888dfd6"
format_stamp: "Formatted at 2026-08-12 06:20:02 on dist-test-slave-mn4r"
I20260812 06:20:02.620041 20250 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.005s	sys 0.000s
I20260812 06:20:02.622521 20265 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:02.623746 20250 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:02.623875 20250 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/master-0-root
uuid: "be382e8da28047458c14dfe40888dfd6"
format_stamp: "Formatted at 2026-08-12 06:20:02 on dist-test-slave-mn4r"
I20260812 06:20:02.624024 20250 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-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:02.643059 20250 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:02.643726 20250 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:20:02.643873 20250 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:02.652457 20250 rpc_server.cc:307] RPC server started. Bound to: 127.19.198.190:36901
I20260812 06:20:02.652484 20332 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.198.190:36901 every 8 connection(s)
I20260812 06:20:02.655090 20333 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:02.660871 20333 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6: Bootstrap starting.
I20260812 06:20:02.663447 20333 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:02.664435 20333 log.cc:826] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:02.666460 20333 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6: No bootstrap required, opened a new log
I20260812 06:20:02.669489 20333 raft_consensus.cc:359] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "be382e8da28047458c14dfe40888dfd6" member_type: VOTER }
I20260812 06:20:02.669679 20333 raft_consensus.cc:385] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:02.669759 20333 raft_consensus.cc:740] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: be382e8da28047458c14dfe40888dfd6, State: Initialized, Role: FOLLOWER
I20260812 06:20:02.670519 20333 consensus_queue.cc:260] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6 [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: "be382e8da28047458c14dfe40888dfd6" member_type: VOTER }
I20260812 06:20:02.670687 20333 raft_consensus.cc:399] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:02.670810 20333 raft_consensus.cc:493] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:02.670962 20333 raft_consensus.cc:3060] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:02.671854 20333 raft_consensus.cc:515] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "be382e8da28047458c14dfe40888dfd6" member_type: VOTER }
I20260812 06:20:02.672336 20333 leader_election.cc:304] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6 [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: be382e8da28047458c14dfe40888dfd6; no voters: 
I20260812 06:20:02.672693 20333 leader_election.cc:290] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:02.672932 20336 raft_consensus.cc:2804] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:02.673223 20336 raft_consensus.cc:697] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6 [term 1 LEADER]: Becoming Leader. State: Replica: be382e8da28047458c14dfe40888dfd6, State: Running, Role: LEADER
I20260812 06:20:02.673656 20336 consensus_queue.cc:237] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6 [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: "be382e8da28047458c14dfe40888dfd6" member_type: VOTER }
I20260812 06:20:02.673868 20333 sys_catalog.cc:565] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:02.675837 20337 sys_catalog.cc:455] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "be382e8da28047458c14dfe40888dfd6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "be382e8da28047458c14dfe40888dfd6" member_type: VOTER } }
I20260812 06:20:02.675906 20338 sys_catalog.cc:455] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6 [sys.catalog]: SysCatalogTable state changed. Reason: New leader be382e8da28047458c14dfe40888dfd6. Latest consensus state: current_term: 1 leader_uuid: "be382e8da28047458c14dfe40888dfd6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "be382e8da28047458c14dfe40888dfd6" member_type: VOTER } }
I20260812 06:20:02.675989 20337 sys_catalog.cc:458] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:02.675999 20338 sys_catalog.cc:458] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:02.676360 20352 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:02.676486 20250 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:02.678825 20352 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:02.683764 20352 catalog_manager.cc:1383] Generated new cluster ID: fb3c4922cd47404690965f0633e699aa
I20260812 06:20:02.683848 20352 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:02.694779 20352 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:02.696012 20352 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:02.713559 20352 catalog_manager.cc:6092] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6: Generated new TSK 0
I20260812 06:20:02.714468 20352 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:02.741523 20250 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:02.744427 20364 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:02.744469 20361 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:02.744594 20362 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:02.744740 20250 server_base.cc:1061] running on GCE node
I20260812 06:20:02.745008 20250 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:02.745070 20250 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:02.745103 20250 hybrid_clock.cc:648] HybridClock initialized: now 1786515602745103 us; error 0 us; skew 500 ppm
I20260812 06:20:02.746053 20250 webserver.cc:533] Webserver started at http://127.19.198.129:35865/ using document root <none> and password file <none>
I20260812 06:20:02.746294 20250 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:02.746357 20250 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:02.746430 20250 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:02.746877 20250 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/instance:
uuid: "bfb78537fefc491bb004c1db11ef0f3a"
format_stamp: "Formatted at 2026-08-12 06:20:02 on dist-test-slave-mn4r"
I20260812 06:20:02.748777 20250 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:02.749912 20369 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:02.750242 20250 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:02.750308 20250 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root
uuid: "bfb78537fefc491bb004c1db11ef0f3a"
format_stamp: "Formatted at 2026-08-12 06:20:02 on dist-test-slave-mn4r"
I20260812 06:20:02.750399 20250 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-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:02.766662 20250 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:02.767227 20250 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:02.767814 20250 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:02.768716 20250 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:02.768769 20250 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:02.768842 20250 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:02.768887 20250 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:02.776407 20250 rpc_server.cc:307] RPC server started. Bound to: 127.19.198.129:39599
I20260812 06:20:02.776471 20445 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.198.129:39599 every 8 connection(s)
I20260812 06:20:02.790660 20446 heartbeater.cc:344] Connected to a master server at 127.19.198.190:36901
I20260812 06:20:02.790966 20446 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:02.791584 20446 heartbeater.cc:507] Master 127.19.198.190:36901 requested a full tablet report, sending...
I20260812 06:20:02.793304 20290 ts_manager.cc:194] Registered new tserver with Master: bfb78537fefc491bb004c1db11ef0f3a (127.19.198.129:39599)
I20260812 06:20:02.793857 20250 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016740092s
I20260812 06:20:02.794910 20290 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:59888
I20260812 06:20:02.804356 20290 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:59890:
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:02.820992 20402 tablet_service.cc:1511] Processing CreateTablet for tablet ab7736981a894bc1b0fee96685efc3d0 (DEFAULT_TABLE table=heavy-update-compaction-test [id=7fab8bec40e448aca946e4cb05919ba7]), partition=
I20260812 06:20:02.821503 20402 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ab7736981a894bc1b0fee96685efc3d0. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:02.824221 20459 tablet_bootstrap.cc:492] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Bootstrap starting.
I20260812 06:20:02.825443 20459 tablet_bootstrap.cc:654] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:02.827131 20459 tablet_bootstrap.cc:492] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: No bootstrap required, opened a new log
I20260812 06:20:02.827219 20459 ts_tablet_manager.cc:1403] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:02.827729 20459 raft_consensus.cc:359] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bfb78537fefc491bb004c1db11ef0f3a" member_type: VOTER last_known_addr { host: "127.19.198.129" port: 39599 } }
I20260812 06:20:02.827878 20459 raft_consensus.cc:385] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:02.827947 20459 raft_consensus.cc:740] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: bfb78537fefc491bb004c1db11ef0f3a, State: Initialized, Role: FOLLOWER
I20260812 06:20:02.828159 20459 consensus_queue.cc:260] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a [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: "bfb78537fefc491bb004c1db11ef0f3a" member_type: VOTER last_known_addr { host: "127.19.198.129" port: 39599 } }
I20260812 06:20:02.828271 20459 raft_consensus.cc:399] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:02.828321 20459 raft_consensus.cc:493] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:02.828387 20459 raft_consensus.cc:3060] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:02.829409 20459 raft_consensus.cc:515] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bfb78537fefc491bb004c1db11ef0f3a" member_type: VOTER last_known_addr { host: "127.19.198.129" port: 39599 } }
I20260812 06:20:02.829551 20459 leader_election.cc:304] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a [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: bfb78537fefc491bb004c1db11ef0f3a; no voters: 
I20260812 06:20:02.829813 20459 leader_election.cc:290] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:02.829913 20461 raft_consensus.cc:2804] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:02.830127 20461 raft_consensus.cc:697] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a [term 1 LEADER]: Becoming Leader. State: Replica: bfb78537fefc491bb004c1db11ef0f3a, State: Running, Role: LEADER
I20260812 06:20:02.830267 20459 ts_tablet_manager.cc:1434] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:02.830334 20461 consensus_queue.cc:237] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a [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: "bfb78537fefc491bb004c1db11ef0f3a" member_type: VOTER last_known_addr { host: "127.19.198.129" port: 39599 } }
I20260812 06:20:02.830551 20446 heartbeater.cc:499] Master 127.19.198.190:36901 was elected leader, sending a full tablet report...
I20260812 06:20:02.833425 20290 catalog_manager.cc:5719] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a reported cstate change: term changed from 0 to 1, leader changed from <none> to bfb78537fefc491bb004c1db11ef0f3a (127.19.198.129). New cstate: current_term: 1 leader_uuid: "bfb78537fefc491bb004c1db11ef0f3a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bfb78537fefc491bb004c1db11ef0f3a" member_type: VOTER last_known_addr { host: "127.19.198.129" port: 39599 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:02.902052 20250 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.017s	sys 0.011s
I20260812 06:20:03.027606 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushMRSOp(ab7736981a894bc1b0fee96685efc3d0): perf score=15.086190
I20260812 06:20:03.191305 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushMRSOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.163s	user 0.120s	sys 0.041s Metrics: {"bytes_written":11897250,"cfile_init":1,"compiler_manager_pool.queue_time_us":266,"delete_count":0,"dirs.queue_time_us":93,"dirs.run_cpu_time_us":299,"dirs.run_wall_time_us":1149,"drs_written":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40283,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":175,"threads_started":1,"update_count":1450}
I20260812 06:20:03.192724 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling LogGCOp(ab7736981a894bc1b0fee96685efc3d0): free 20743880 bytes of WAL
I20260812 06:20:03.193286 20374 log_reader.cc:385] T ab7736981a894bc1b0fee96685efc3d0: removed 2 log segments from log reader
I20260812 06:20:03.193468 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000001 (ops 1-6)
I20260812 06:20:03.193617 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000002 (ops 7-11)
I20260812 06:20:03.199633 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: LogGCOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.007s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:20:03.200052 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling UndoDeltaBlockGCOp(ab7736981a894bc1b0fee96685efc3d0): 12719216 bytes on disk
I20260812 06:20:03.200757 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: UndoDeltaBlockGCOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:20:03.201262 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=3.181125
I20260812 06:20:03.221825 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.020s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7173,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:03.222337 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=2.188937
I20260812 06:20:03.235893 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5035,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:03.236430 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.000000
I20260812 06:20:03.433648 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.197s	user 0.130s	sys 0.048s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24364555,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":520,"lbm_read_time_us":12146,"lbm_reads_lt_1ms":559,"lbm_write_time_us":30905,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"thread_start_us":332,"threads_started":5,"update_count":2450}
I20260812 06:20:03.434332 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=10.126437
I20260812 06:20:03.476699 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.042s	user 0.012s	sys 0.025s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17494,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:03.477248 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.000000
I20260812 06:20:03.589924 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.112s	user 0.076s	sys 0.036s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569747,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":165,"lbm_read_time_us":6501,"lbm_reads_lt_1ms":363,"lbm_write_time_us":21190,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":342,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1500}
I20260812 06:20:03.590574 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=6.157687
I20260812 06:20:03.652916 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.062s	user 0.014s	sys 0.019s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":15870,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":202,"reinsert_count":0,"update_count":1000}
I20260812 06:20:03.653414 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=2.188937
I20260812 06:20:03.669126 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5993,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.669720 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.000000
I20260812 06:20:03.794276 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.124s	user 0.098s	sys 0.023s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569865,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1541,"lbm_read_time_us":8896,"lbm_reads_lt_1ms":372,"lbm_write_time_us":18058,"lbm_writes_lt_1ms":343,"mutex_wait_us":260,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:20:03.795184 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=6.157687
I20260812 06:20:03.838950 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.044s	user 0.024s	sys 0.009s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":14143,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:03.839591 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=2.188937
I20260812 06:20:03.850569 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4100,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.851279 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.000000
I20260812 06:20:03.951581 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.100s	user 0.083s	sys 0.016s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569865,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1285,"lbm_read_time_us":7252,"lbm_reads_lt_1ms":372,"lbm_write_time_us":17971,"lbm_writes_lt_1ms":343,"mutex_wait_us":330,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":1500}
I20260812 06:20:03.952350 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=7.149875
I20260812 06:20:03.987453 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.035s	user 0.014s	sys 0.019s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":13742,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":212,"reinsert_count":0,"update_count":1050}
I20260812 06:20:03.988055 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=2.188937
I20260812 06:20:04.004786 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.017s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5785,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:04.005354 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.000000
I20260812 06:20:04.111847 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.106s	user 0.079s	sys 0.027s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569856,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":938,"lbm_read_time_us":6331,"lbm_reads_lt_1ms":364,"lbm_write_time_us":19759,"lbm_writes_lt_1ms":343,"mutex_wait_us":24,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":1500}
I20260812 06:20:04.112597 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=10.126437
I20260812 06:20:04.155005 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.042s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16025,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:04.155542 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=2.188937
I20260812 06:20:04.171772 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5831,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.172395 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.000000
I20260812 06:20:04.301342 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.129s	user 0.092s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":354,"lbm_read_time_us":10296,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23143,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2000}
I20260812 06:20:04.302130 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=10.126437
I20260812 06:20:04.342609 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.040s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16258,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:04.343202 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=2.188937
I20260812 06:20:04.359774 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.016s	user 0.009s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5914,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.360383 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.000000
I20260812 06:20:04.486935 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.126s	user 0.098s	sys 0.028s 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":606,"lbm_read_time_us":10020,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23636,"lbm_writes_lt_1ms":443,"mutex_wait_us":291,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2000}
I20260812 06:20:04.487632 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=10.126437
I20260812 06:20:04.533545 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.046s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16384,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:04.534173 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=2.188937
I20260812 06:20:04.544855 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4066,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.545419 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushMRSOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.000000
I20260812 06:20:04.577852 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushMRSOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.032s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":287,"dirs.run_wall_time_us":1667,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1919,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:04.578769 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling LogGCOp(ab7736981a894bc1b0fee96685efc3d0): free 115943186 bytes of WAL
I20260812 06:20:04.579033 20374 log_reader.cc:385] T ab7736981a894bc1b0fee96685efc3d0: removed 11 log segments from log reader
I20260812 06:20:04.579078 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000003 (ops 12-16)
I20260812 06:20:04.579135 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000004 (ops 17-21)
I20260812 06:20:04.579180 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000005 (ops 22-26)
I20260812 06:20:04.579212 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000006 (ops 27-31)
I20260812 06:20:04.579252 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000007 (ops 32-36)
I20260812 06:20:04.579295 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000008 (ops 37-41)
I20260812 06:20:04.579330 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000009 (ops 42-46)
I20260812 06:20:04.579375 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000010 (ops 47-51)
I20260812 06:20:04.579413 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000011 (ops 52-56)
I20260812 06:20:04.579452 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000012 (ops 57-61)
I20260812 06:20:04.579492 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000013 (ops 62-66)
I20260812 06:20:04.607409 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: LogGCOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.028s	user 0.004s	sys 0.023s Metrics: {}
I20260812 06:20:04.607842 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling UndoDeltaBlockGCOp(ab7736981a894bc1b0fee96685efc3d0): 447 bytes on disk
I20260812 06:20:04.608466 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: UndoDeltaBlockGCOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:20:04.608955 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=3.181125
I20260812 06:20:04.627096 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.018s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7121,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:04.627562 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=2.188937
I20260812 06:20:04.637393 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.010s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3628,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:04.637960 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.000000
I20260812 06:20:04.833292 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.195s	user 0.136s	sys 0.050s 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":996,"lbm_read_time_us":14068,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37179,"lbm_writes_lt_1ms":643,"mutex_wait_us":151,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20736,"thread_start_us":97,"threads_started":1,"update_count":3000}
I20260812 06:20:04.834131 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=14.095187
I20260812 06:20:04.886581 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.052s	user 0.024s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21915,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.887104 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=2.188937
I20260812 06:20:04.903367 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5866,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.904088 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.000000
I20260812 06:20:05.060297 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.156s	user 0.116s	sys 0.036s 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":219,"lbm_read_time_us":9572,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30697,"lbm_writes_lt_1ms":543,"mutex_wait_us":89,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2500}
I20260812 06:20:05.061072 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=12.110812
I20260812 06:20:05.110386 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.049s	user 0.025s	sys 0.023s Metrics: {"bytes_written":14194597,"delete_count":0,"lbm_write_time_us":23376,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":346,"reinsert_count":0,"update_count":1730}
I20260812 06:20:05.110898 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.196750
I20260812 06:20:05.123052 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.012s	user 0.006s	sys 0.000s Metrics: {"bytes_written":2625758,"delete_count":0,"lbm_write_time_us":2703,"lbm_writes_lt_1ms":67,"reinsert_count":0,"update_count":320}
I20260812 06:20:05.123545 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=2.188937
I20260812 06:20:05.133155 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3523,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:05.133663 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.000000
I20260812 06:20:05.311735 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.178s	user 0.134s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774760,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":189,"lbm_read_time_us":12813,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31703,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2500}
I20260812 06:20:05.312265 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=14.095187
I20260812 06:20:05.378383 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.066s	user 0.033s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24152,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.378989 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=2.188937
I20260812 06:20:05.390386 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.011s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4414,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.391083 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.000000
I20260812 06:20:05.571009 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.179s	user 0.124s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":289,"lbm_read_time_us":14708,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28936,"lbm_writes_lt_1ms":543,"mutex_wait_us":103,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:05.571734 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=14.095187
I20260812 06:20:05.632637 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.061s	user 0.030s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20308,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.633265 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=2.188937
I20260812 06:20:05.644371 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4166,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.644886 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.000000
I20260812 06:20:05.818884 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.174s	user 0.122s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":280,"lbm_read_time_us":14038,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27933,"lbm_writes_lt_1ms":543,"mutex_wait_us":75,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:05.819674 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=11.118625
I20260812 06:20:05.866808 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.047s	user 0.030s	sys 0.003s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":14944,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:05.867336 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=2.188937
I20260812 06:20:05.893399 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.026s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4022,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:05.894008 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=2.188937
I20260812 06:20:05.911473 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.017s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6463,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.912205 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.000000
I20260812 06:20:06.118695 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.206s	user 0.151s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":356,"lbm_read_time_us":13718,"lbm_reads_lt_1ms":573,"lbm_write_time_us":37778,"lbm_writes_lt_1ms":543,"mutex_wait_us":139,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:20:06.119366 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=14.095187
I20260812 06:20:06.173578 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.054s	user 0.020s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23310,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:06.174247 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=2.188937
I20260812 06:20:06.196036 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.022s	user 0.008s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4473,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.196681 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushMRSOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.000000
I20260812 06:20:06.229919 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushMRSOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.033s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":193,"dirs.run_wall_time_us":1553,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1741,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32,"spinlock_wait_cycles":2304}
I20260812 06:20:06.230885 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling LogGCOp(ab7736981a894bc1b0fee96685efc3d0): free 129320510 bytes of WAL
I20260812 06:20:06.231159 20374 log_reader.cc:385] T ab7736981a894bc1b0fee96685efc3d0: removed 13 log segments from log reader
I20260812 06:20:06.231230 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000014 (ops 67-71)
I20260812 06:20:06.231289 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000015 (ops 72-76)
I20260812 06:20:06.231348 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000016 (ops 77-81)
I20260812 06:20:06.231391 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000017 (ops 82-86)
I20260812 06:20:06.231429 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000018 (ops 87-91)
I20260812 06:20:06.231468 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000019 (ops 92-96)
I20260812 06:20:06.231506 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000020 (ops 97-100)
I20260812 06:20:06.231549 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000021 (ops 101-105)
I20260812 06:20:06.231587 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000022 (ops 106-110)
I20260812 06:20:06.231626 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000023 (ops 111-114)
I20260812 06:20:06.231665 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000024 (ops 115-119)
I20260812 06:20:06.231703 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000025 (ops 120-124)
I20260812 06:20:06.231743 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000026 (ops 125-129)
I20260812 06:20:06.262112 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: LogGCOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.031s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:06.262634 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling UndoDeltaBlockGCOp(ab7736981a894bc1b0fee96685efc3d0): 493 bytes on disk
I20260812 06:20:06.263190 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: UndoDeltaBlockGCOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4}
I20260812 06:20:06.263937 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=3.181125
I20260812 06:20:06.276273 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4676999,"delete_count":0,"lbm_write_time_us":4569,"lbm_writes_lt_1ms":117,"reinsert_count":0,"update_count":570}
I20260812 06:20:06.276770 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=2.188937
I20260812 06:20:06.286463 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":3528305,"delete_count":0,"lbm_write_time_us":3458,"lbm_writes_lt_1ms":89,"reinsert_count":0,"update_count":430}
I20260812 06:20:06.286970 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.000000
I20260812 06:20:06.543135 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.256s	user 0.168s	sys 0.079s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979738,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1287,"lbm_read_time_us":16170,"lbm_reads_lt_1ms":774,"lbm_write_time_us":43132,"lbm_writes_lt_1ms":743,"mutex_wait_us":408,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":18304,"thread_start_us":153,"threads_started":1,"update_count":3500}
I20260812 06:20:06.544405 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=18.063937
I20260812 06:20:06.604051 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.059s	user 0.030s	sys 0.027s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":26656,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:06.604692 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.000000
I20260812 06:20:06.772294 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.167s	user 0.111s	sys 0.056s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24774571,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1170,"lbm_read_time_us":12676,"lbm_reads_lt_1ms":563,"lbm_write_time_us":28011,"lbm_writes_lt_1ms":543,"mutex_wait_us":398,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":52608,"update_count":2500}
I20260812 06:20:06.773120 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=14.095187
I20260812 06:20:06.837541 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.064s	user 0.026s	sys 0.034s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23342,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:06.838446 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=2.188937
I20260812 06:20:06.860522 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.022s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6750,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.861106 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.000000
I20260812 06:20:07.031562 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.170s	user 0.104s	sys 0.066s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":858,"lbm_read_time_us":12962,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27691,"lbm_writes_lt_1ms":543,"mutex_wait_us":292,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2500}
I20260812 06:20:07.032423 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=14.095187
I20260812 06:20:07.097919 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.065s	user 0.013s	sys 0.048s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25225,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:07.098658 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=2.188937
I20260812 06:20:07.110196 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.011s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4486,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.110720 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.000000
I20260812 06:20:07.295405 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.184s	user 0.120s	sys 0.060s 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":943,"lbm_read_time_us":14958,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30473,"lbm_writes_lt_1ms":543,"mutex_wait_us":305,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2500}
I20260812 06:20:07.296149 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=11.118625
I20260812 06:20:07.342233 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.046s	user 0.017s	sys 0.024s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18792,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:20:07.342737 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=2.188937
I20260812 06:20:07.358632 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6000,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.359166 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=2.188937
I20260812 06:20:07.373111 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.014s	user 0.004s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5203,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:07.373778 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.000000
I20260812 06:20:07.568614 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.195s	user 0.123s	sys 0.058s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1338,"lbm_read_time_us":11157,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29635,"lbm_writes_lt_1ms":543,"mutex_wait_us":342,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:20:07.569191 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=14.095187
I20260812 06:20:07.623396 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.054s	user 0.026s	sys 0.023s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22770,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:07.623917 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=2.188937
I20260812 06:20:07.636315 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.012s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4622,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.637001 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.000000
I20260812 06:20:07.792796 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.156s	user 0.102s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":139,"lbm_read_time_us":9407,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32269,"lbm_writes_lt_1ms":543,"mutex_wait_us":69,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:07.793463 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=11.118625
I20260812 06:20:07.835860 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.042s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17904,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:07.836666 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=2.188937
I20260812 06:20:07.863647 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.027s	user 0.007s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5908,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:07.864158 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=2.188937
I20260812 06:20:07.875161 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4186,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.875723 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushMRSOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.000000
I20260812 06:20:07.912662 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushMRSOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.037s	user 0.032s	sys 0.003s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":189,"dirs.run_wall_time_us":1505,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2273,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:07.913594 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling LogGCOp(ab7736981a894bc1b0fee96685efc3d0): free 132571598 bytes of WAL
I20260812 06:20:07.913910 20374 log_reader.cc:385] T ab7736981a894bc1b0fee96685efc3d0: removed 13 log segments from log reader
I20260812 06:20:07.914002 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000027 (ops 130-134)
I20260812 06:20:07.914067 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000028 (ops 135-139)
I20260812 06:20:07.914186 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000029 (ops 140-144)
I20260812 06:20:07.914237 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000030 (ops 145-149)
I20260812 06:20:07.914278 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000031 (ops 150-154)
I20260812 06:20:07.914324 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000032 (ops 155-159)
I20260812 06:20:07.914364 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000033 (ops 160-164)
I20260812 06:20:07.914405 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000034 (ops 165-168)
I20260812 06:20:07.914446 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000035 (ops 169-173)
I20260812 06:20:07.914498 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000036 (ops 174-178)
I20260812 06:20:07.914548 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000037 (ops 179-183)
I20260812 06:20:07.914589 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000038 (ops 184-188)
I20260812 06:20:07.914630 20374 log.cc:1079] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/ab7736981a894bc1b0fee96685efc3d0/wal-000000039 (ops 189-192)
I20260812 06:20:07.951313 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: LogGCOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.037s	user 0.002s	sys 0.035s Metrics: {}
I20260812 06:20:07.951834 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling UndoDeltaBlockGCOp(ab7736981a894bc1b0fee96685efc3d0): 493 bytes on disk
I20260812 06:20:07.952564 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: UndoDeltaBlockGCOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:20:07.953258 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=5.165500
I20260812 06:20:07.988065 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.035s	user 0.014s	sys 0.019s Metrics: {"bytes_written":6687182,"delete_count":0,"lbm_write_time_us":9564,"lbm_writes_lt_1ms":166,"reinsert_count":0,"update_count":815}
I20260812 06:20:07.988791 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.000000
I20260812 06:20:07.995337 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: FlushDeltaMemStoresOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.006s	user 0.001s	sys 0.004s Metrics: {"bytes_written":1518077,"delete_count":0,"lbm_write_time_us":1896,"lbm_writes_lt_1ms":40,"reinsert_count":0,"update_count":185}
I20260812 06:20:07.996058 20447 maintenance_manager.cc:419] P bfb78537fefc491bb004c1db11ef0f3a: Scheduling MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0): perf score=1.000000
I20260812 06:20:08.098068 20250 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.196s	user 1.893s	sys 0.140s
I20260812 06:20:08.233345 20250 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.135s	user 0.002s	sys 0.000s
I20260812 06:20:08.234061 20250 tablet_server.cc:179] TabletServer@127.19.198.129:0 shutting down...
I20260812 06:20:08.244360 20374 maintenance_manager.cc:643] P bfb78537fefc491bb004c1db11ef0f3a: MajorDeltaCompactionOp(ab7736981a894bc1b0fee96685efc3d0) complete. Timing: real 0.248s	user 0.175s	sys 0.072s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979798,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1276,"lbm_read_time_us":16487,"lbm_reads_lt_1ms":771,"lbm_write_time_us":45490,"lbm_writes_lt_1ms":743,"mutex_wait_us":550,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":7296,"thread_start_us":74,"threads_started":1,"update_count":3500}
I20260812 06:20:08.245081 20250 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:08.245577 20250 tablet_replica.cc:333] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a: stopping tablet replica
I20260812 06:20:08.245909 20250 raft_consensus.cc:2243] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:08.246204 20250 raft_consensus.cc:2272] T ab7736981a894bc1b0fee96685efc3d0 P bfb78537fefc491bb004c1db11ef0f3a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:08.265044 20250 tablet_server.cc:196] TabletServer@127.19.198.129:0 shutdown complete.
I20260812 06:20:08.303936 20250 master.cc:562] Master@127.19.198.190:36901 shutting down...
I20260812 06:20:08.308512 20250 raft_consensus.cc:2243] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:08.308729 20250 raft_consensus.cc:2272] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:08.308832 20250 tablet_replica.cc:333] T 00000000000000000000000000000000 P be382e8da28047458c14dfe40888dfd6: stopping tablet replica
I20260812 06:20:08.321308 20250 master.cc:584] Master@127.19.198.190:36901 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5822 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:08.436735 20250 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.19.198.190:43411
I20260812 06:20:08.437325 20250 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:08.439623 20485 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:08.439708 20482 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:08.439623 20483 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:08.439800 20250 server_base.cc:1061] running on GCE node
I20260812 06:20:08.440133 20250 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:08.440176 20250 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:08.440191 20250 hybrid_clock.cc:648] HybridClock initialized: now 1786515608440191 us; error 0 us; skew 500 ppm
I20260812 06:20:08.441076 20250 webserver.cc:533] Webserver started at http://127.19.198.190:38705/ using document root <none> and password file <none>
I20260812 06:20:08.441267 20250 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:08.441315 20250 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:08.441421 20250 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:08.441859 20250 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/master-0-root/instance:
uuid: "995adc89e40c473f9868a970d81dded3"
format_stamp: "Formatted at 2026-08-12 06:20:08 on dist-test-slave-mn4r"
I20260812 06:20:08.443501 20250 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:08.444460 20491 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:08.444756 20250 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:08.444823 20250 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/master-0-root
uuid: "995adc89e40c473f9868a970d81dded3"
format_stamp: "Formatted at 2026-08-12 06:20:08 on dist-test-slave-mn4r"
I20260812 06:20:08.444923 20250 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:08.459605 20250 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:08.460094 20250 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:08.464890 20250 rpc_server.cc:307] RPC server started. Bound to: 127.19.198.190:43411
I20260812 06:20:08.470436 20554 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.198.190:43411 every 8 connection(s)
I20260812 06:20:08.470634 20555 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:08.472631 20555 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3: Bootstrap starting.
I20260812 06:20:08.473551 20555 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:08.474781 20555 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3: No bootstrap required, opened a new log
I20260812 06:20:08.475251 20555 raft_consensus.cc:359] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "995adc89e40c473f9868a970d81dded3" member_type: VOTER }
I20260812 06:20:08.475343 20555 raft_consensus.cc:385] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:08.475404 20555 raft_consensus.cc:740] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 995adc89e40c473f9868a970d81dded3, State: Initialized, Role: FOLLOWER
I20260812 06:20:08.475598 20555 consensus_queue.cc:260] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3 [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: "995adc89e40c473f9868a970d81dded3" member_type: VOTER }
I20260812 06:20:08.475692 20555 raft_consensus.cc:399] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:08.475765 20555 raft_consensus.cc:493] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:08.475833 20555 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:08.476568 20555 raft_consensus.cc:515] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "995adc89e40c473f9868a970d81dded3" member_type: VOTER }
I20260812 06:20:08.476725 20555 leader_election.cc:304] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3 [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: 995adc89e40c473f9868a970d81dded3; no voters: 
I20260812 06:20:08.476958 20555 leader_election.cc:290] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:08.477129 20558 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:08.477385 20558 raft_consensus.cc:697] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3 [term 1 LEADER]: Becoming Leader. State: Replica: 995adc89e40c473f9868a970d81dded3, State: Running, Role: LEADER
I20260812 06:20:08.477502 20555 sys_catalog.cc:565] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:08.477577 20558 consensus_queue.cc:237] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3 [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: "995adc89e40c473f9868a970d81dded3" member_type: VOTER }
I20260812 06:20:08.478111 20559 sys_catalog.cc:455] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "995adc89e40c473f9868a970d81dded3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "995adc89e40c473f9868a970d81dded3" member_type: VOTER } }
I20260812 06:20:08.478230 20559 sys_catalog.cc:458] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:08.478128 20560 sys_catalog.cc:455] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 995adc89e40c473f9868a970d81dded3. Latest consensus state: current_term: 1 leader_uuid: "995adc89e40c473f9868a970d81dded3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "995adc89e40c473f9868a970d81dded3" member_type: VOTER } }
I20260812 06:20:08.478302 20560 sys_catalog.cc:458] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:08.478523 20567 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:08.479473 20567 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:08.479681 20250 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:08.481523 20567 catalog_manager.cc:1383] Generated new cluster ID: 142fa070c4234b159e3c469a01ffb876
I20260812 06:20:08.481593 20567 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:08.496802 20567 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:08.497417 20567 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:08.501961 20567 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3: Generated new TSK 0
I20260812 06:20:08.502205 20567 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:08.512148 20250 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:08.514343 20582 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:08.514357 20585 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:08.514451 20250 server_base.cc:1061] running on GCE node
W20260812 06:20:08.514358 20583 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:08.514792 20250 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:08.514839 20250 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:08.514855 20250 hybrid_clock.cc:648] HybridClock initialized: now 1786515608514855 us; error 0 us; skew 500 ppm
I20260812 06:20:08.515798 20250 webserver.cc:533] Webserver started at http://127.19.198.129:43687/ using document root <none> and password file <none>
I20260812 06:20:08.515995 20250 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:08.516048 20250 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:08.516177 20250 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:08.516619 20250 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/instance:
uuid: "72c93805a12c408fa49c05f5d37d7a09"
format_stamp: "Formatted at 2026-08-12 06:20:08 on dist-test-slave-mn4r"
I20260812 06:20:08.518293 20250 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:08.519294 20590 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:08.519580 20250 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:08.519676 20250 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root
uuid: "72c93805a12c408fa49c05f5d37d7a09"
format_stamp: "Formatted at 2026-08-12 06:20:08 on dist-test-slave-mn4r"
I20260812 06:20:08.519770 20250 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:08.532593 20250 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:08.533062 20250 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:08.533434 20250 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:08.533970 20250 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:08.534039 20250 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:08.534178 20250 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:08.534224 20250 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:08.538918 20250 rpc_server.cc:307] RPC server started. Bound to: 127.19.198.129:38245
I20260812 06:20:08.541215 20667 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.198.129:38245 every 8 connection(s)
I20260812 06:20:08.546485 20668 heartbeater.cc:344] Connected to a master server at 127.19.198.190:43411
I20260812 06:20:08.546609 20668 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:08.546816 20668 heartbeater.cc:507] Master 127.19.198.190:43411 requested a full tablet report, sending...
I20260812 06:20:08.547581 20513 ts_manager.cc:194] Registered new tserver with Master: 72c93805a12c408fa49c05f5d37d7a09 (127.19.198.129:38245)
I20260812 06:20:08.548314 20513 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:35144
I20260812 06:20:08.548553 20250 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.00889544s
I20260812 06:20:08.556275 20513 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:35150:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:08.565548 20623 tablet_service.cc:1511] Processing CreateTablet for tablet 6295b4d81e8241148e7cfdce957362f6 (DEFAULT_TABLE table=heavy-update-compaction-test [id=7a91c7fd7cf244d290a082364570e797]), partition=
I20260812 06:20:08.565867 20623 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 6295b4d81e8241148e7cfdce957362f6. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:08.567981 20682 tablet_bootstrap.cc:492] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Bootstrap starting.
I20260812 06:20:08.568933 20682 tablet_bootstrap.cc:654] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:08.570071 20682 tablet_bootstrap.cc:492] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: No bootstrap required, opened a new log
I20260812 06:20:08.570246 20682 ts_tablet_manager.cc:1403] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:08.570748 20682 raft_consensus.cc:359] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "72c93805a12c408fa49c05f5d37d7a09" member_type: VOTER last_known_addr { host: "127.19.198.129" port: 38245 } }
I20260812 06:20:08.570871 20682 raft_consensus.cc:385] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:08.570897 20682 raft_consensus.cc:740] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 72c93805a12c408fa49c05f5d37d7a09, State: Initialized, Role: FOLLOWER
I20260812 06:20:08.571072 20682 consensus_queue.cc:260] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09 [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: "72c93805a12c408fa49c05f5d37d7a09" member_type: VOTER last_known_addr { host: "127.19.198.129" port: 38245 } }
I20260812 06:20:08.571188 20682 raft_consensus.cc:399] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:08.571240 20682 raft_consensus.cc:493] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:08.571328 20682 raft_consensus.cc:3060] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:08.572198 20682 raft_consensus.cc:515] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "72c93805a12c408fa49c05f5d37d7a09" member_type: VOTER last_known_addr { host: "127.19.198.129" port: 38245 } }
I20260812 06:20:08.572364 20682 leader_election.cc:304] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09 [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: 72c93805a12c408fa49c05f5d37d7a09; no voters: 
I20260812 06:20:08.572615 20682 leader_election.cc:290] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:08.572757 20684 raft_consensus.cc:2804] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:08.573002 20682 ts_tablet_manager.cc:1434] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:08.573083 20668 heartbeater.cc:499] Master 127.19.198.190:43411 was elected leader, sending a full tablet report...
I20260812 06:20:08.573096 20684 raft_consensus.cc:697] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09 [term 1 LEADER]: Becoming Leader. State: Replica: 72c93805a12c408fa49c05f5d37d7a09, State: Running, Role: LEADER
I20260812 06:20:08.573258 20684 consensus_queue.cc:237] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09 [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: "72c93805a12c408fa49c05f5d37d7a09" member_type: VOTER last_known_addr { host: "127.19.198.129" port: 38245 } }
I20260812 06:20:08.574716 20513 catalog_manager.cc:5719] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09 reported cstate change: term changed from 0 to 1, leader changed from <none> to 72c93805a12c408fa49c05f5d37d7a09 (127.19.198.129). New cstate: current_term: 1 leader_uuid: "72c93805a12c408fa49c05f5d37d7a09" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "72c93805a12c408fa49c05f5d37d7a09" member_type: VOTER last_known_addr { host: "127.19.198.129" port: 38245 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:08.636325 20250 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.019s	sys 0.004s
I20260812 06:20:08.791719 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushMRSOp(6295b4d81e8241148e7cfdce957362f6): perf score=19.054940
I20260812 06:20:08.957993 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushMRSOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.166s	user 0.125s	sys 0.036s Metrics: {"bytes_written":13251054,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":91,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":929,"drs_written":1,"lbm_read_time_us":88,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41202,"lbm_writes_lt_1ms":780,"mutex_wait_us":964,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1615}
I20260812 06:20:08.959034 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling LogGCOp(6295b4d81e8241148e7cfdce957362f6): free 20290830 bytes of WAL
I20260812 06:20:08.959354 20597 log_reader.cc:385] T 6295b4d81e8241148e7cfdce957362f6: removed 2 log segments from log reader
I20260812 06:20:08.959458 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000001 (ops 1-6)
I20260812 06:20:08.959547 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000002 (ops 7-10)
I20260812 06:20:08.965510 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: LogGCOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:08.965881 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling UndoDeltaBlockGCOp(6295b4d81e8241148e7cfdce957362f6): 16411391 bytes on disk
I20260812 06:20:08.966490 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: UndoDeltaBlockGCOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:20:08.967041 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=2.188937
I20260812 06:20:08.987246 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.020s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3569334,"delete_count":0,"lbm_write_time_us":6134,"lbm_writes_lt_1ms":90,"reinsert_count":0,"update_count":435}
I20260812 06:20:08.987790 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=2.188937
I20260812 06:20:08.998694 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4025,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:08.999260 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6): perf score=1.000000
I20260812 06:20:09.184578 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.185s	user 0.107s	sys 0.073s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774793,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":544,"lbm_read_time_us":13151,"lbm_reads_lt_1ms":569,"lbm_write_time_us":32029,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":339,"threads_started":5,"update_count":2500}
I20260812 06:20:09.185220 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=14.095187
I20260812 06:20:09.242158 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.057s	user 0.043s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23252,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:09.242686 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=2.188937
I20260812 06:20:09.254755 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4100,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.255898 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6): perf score=1.000000
I20260812 06:20:09.446012 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.190s	user 0.137s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":789,"lbm_read_time_us":12256,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29880,"lbm_writes_lt_1ms":543,"mutex_wait_us":374,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":42368,"update_count":2500}
I20260812 06:20:09.446918 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=14.095187
I20260812 06:20:09.500336 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.053s	user 0.031s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22409,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:09.500864 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6): perf score=1.000000
I20260812 06:20:09.662303 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.161s	user 0.118s	sys 0.036s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":735,"lbm_read_time_us":10350,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26956,"lbm_writes_lt_1ms":443,"mutex_wait_us":58,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":2000}
I20260812 06:20:09.662997 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=14.095187
I20260812 06:20:09.721275 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.058s	user 0.037s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25041,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:09.721757 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=2.188937
I20260812 06:20:09.733234 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4140,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.733783 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6): perf score=1.000000
I20260812 06:20:09.931022 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.197s	user 0.132s	sys 0.053s 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":742,"lbm_read_time_us":11877,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33118,"lbm_writes_lt_1ms":543,"mutex_wait_us":260,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2500}
I20260812 06:20:09.931700 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=14.095187
I20260812 06:20:09.983242 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.051s	user 0.035s	sys 0.012s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":21209,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:09.983774 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=2.188937
I20260812 06:20:09.996433 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4537,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.997189 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6): perf score=1.000000
I20260812 06:20:10.155966 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.159s	user 0.126s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1905,"lbm_read_time_us":10065,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31883,"lbm_writes_lt_1ms":543,"mutex_wait_us":742,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2500}
I20260812 06:20:10.156827 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=10.126437
I20260812 06:20:10.201762 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.045s	user 0.025s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19564,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:10.202701 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=2.188937
I20260812 06:20:10.230314 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.027s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5647,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.230829 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=2.188937
I20260812 06:20:10.242205 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4085,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.242935 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushMRSOp(6295b4d81e8241148e7cfdce957362f6): perf score=1.000000
I20260812 06:20:10.277014 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushMRSOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.034s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":298,"dirs.run_wall_time_us":1646,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2157,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:10.277712 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling LogGCOp(6295b4d81e8241148e7cfdce957362f6): free 121006430 bytes of WAL
I20260812 06:20:10.277961 20597 log_reader.cc:385] T 6295b4d81e8241148e7cfdce957362f6: removed 12 log segments from log reader
I20260812 06:20:10.278007 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000003 (ops 11-15)
I20260812 06:20:10.278069 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000004 (ops 16-20)
I20260812 06:20:10.278131 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000005 (ops 21-24)
I20260812 06:20:10.278177 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000006 (ops 25-29)
I20260812 06:20:10.278220 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000007 (ops 30-34)
I20260812 06:20:10.278263 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000008 (ops 35-39)
I20260812 06:20:10.278302 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000009 (ops 40-44)
I20260812 06:20:10.278343 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000010 (ops 45-49)
I20260812 06:20:10.278383 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000011 (ops 50-54)
I20260812 06:20:10.278421 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000012 (ops 55-59)
I20260812 06:20:10.278460 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000013 (ops 60-64)
I20260812 06:20:10.278497 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000014 (ops 65-69)
I20260812 06:20:10.307107 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: LogGCOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:20:10.307617 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling UndoDeltaBlockGCOp(6295b4d81e8241148e7cfdce957362f6): 463 bytes on disk
I20260812 06:20:10.308122 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: UndoDeltaBlockGCOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4}
I20260812 06:20:10.308660 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=3.181125
I20260812 06:20:10.339758 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.031s	user 0.003s	sys 0.024s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7439,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:10.340466 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=2.188937
I20260812 06:20:10.351305 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3923,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:10.352010 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6): perf score=1.000000
I20260812 06:20:10.602850 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.251s	user 0.192s	sys 0.056s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979857,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1177,"lbm_read_time_us":17592,"lbm_reads_lt_1ms":775,"lbm_write_time_us":43383,"lbm_writes_lt_1ms":743,"mutex_wait_us":533,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":21120,"thread_start_us":122,"threads_started":1,"update_count":3500}
I20260812 06:20:10.603467 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=14.095187
I20260812 06:20:10.667843 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.063s	user 0.034s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27078,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:10.668650 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=2.188937
I20260812 06:20:10.690285 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.021s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5643,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.690873 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6): perf score=1.000000
I20260812 06:20:10.889467 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.198s	user 0.119s	sys 0.071s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1510,"lbm_read_time_us":14553,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31497,"lbm_writes_lt_1ms":543,"mutex_wait_us":80,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2500}
I20260812 06:20:10.890146 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=15.087375
I20260812 06:20:10.950979 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.061s	user 0.040s	sys 0.020s Metrics: {"bytes_written":16820145,"delete_count":0,"lbm_write_time_us":22665,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:10.951606 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=2.188937
I20260812 06:20:10.969434 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":7100,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":39296,"update_count":500}
I20260812 06:20:10.969949 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=2.188937
I20260812 06:20:10.980706 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4099,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:10.981287 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6): perf score=1.000000
I20260812 06:20:11.211874 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.230s	user 0.131s	sys 0.098s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877210,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":386,"lbm_read_time_us":15966,"lbm_reads_lt_1ms":673,"lbm_write_time_us":37822,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":3000}
I20260812 06:20:11.212574 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=14.095187
I20260812 06:20:11.272233 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.059s	user 0.049s	sys 0.004s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25053,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:11.272770 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6): perf score=1.000000
I20260812 06:20:11.430552 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.158s	user 0.114s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":212,"lbm_read_time_us":9770,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24474,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:20:11.431263 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=14.095187
I20260812 06:20:11.483120 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.052s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":20161,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:11.483654 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=2.188937
I20260812 06:20:11.497413 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.014s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4751,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.497903 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6): perf score=1.000000
I20260812 06:20:11.690973 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.193s	user 0.125s	sys 0.055s 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":218,"lbm_read_time_us":14245,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30374,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":2500}
I20260812 06:20:11.691723 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=14.095187
I20260812 06:20:11.745734 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.054s	user 0.017s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20693,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:11.746321 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=2.188937
I20260812 06:20:11.759177 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4464,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.759961 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6): perf score=1.000000
I20260812 06:20:11.925657 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.165s	user 0.126s	sys 0.037s 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":592,"lbm_read_time_us":10994,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32581,"lbm_writes_lt_1ms":543,"mutex_wait_us":299,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":2500}
I20260812 06:20:11.926443 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=11.118625
I20260812 06:20:11.964871 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.038s	user 0.025s	sys 0.010s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16246,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:11.965528 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=2.188937
I20260812 06:20:11.980229 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.015s	user 0.003s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4794,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:11.980798 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushMRSOp(6295b4d81e8241148e7cfdce957362f6): perf score=1.000000
I20260812 06:20:12.019109 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushMRSOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.038s	user 0.027s	sys 0.001s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":262,"dirs.run_wall_time_us":1439,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1712,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:12.019981 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling UndoDeltaBlockGCOp(6295b4d81e8241148e7cfdce957362f6): 491 bytes on disk
I20260812 06:20:12.020478 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: UndoDeltaBlockGCOp(6295b4d81e8241148e7cfdce957362f6) 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:20:12.021070 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=3.181125
I20260812 06:20:12.039130 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.018s	user 0.008s	sys 0.009s Metrics: {"bytes_written":4512901,"delete_count":0,"lbm_write_time_us":7137,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:12.039642 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling LogGCOp(6295b4d81e8241148e7cfdce957362f6): free 132571329 bytes of WAL
I20260812 06:20:12.039891 20597 log_reader.cc:385] T 6295b4d81e8241148e7cfdce957362f6: removed 13 log segments from log reader
I20260812 06:20:12.039934 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000015 (ops 70-74)
I20260812 06:20:12.039964 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000016 (ops 75-78)
I20260812 06:20:12.040043 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000017 (ops 79-83)
I20260812 06:20:12.040102 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000018 (ops 84-88)
I20260812 06:20:12.040144 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000019 (ops 89-93)
I20260812 06:20:12.040207 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000020 (ops 94-98)
I20260812 06:20:12.040247 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000021 (ops 99-103)
I20260812 06:20:12.040287 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000022 (ops 104-108)
I20260812 06:20:12.040328 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000023 (ops 109-113)
I20260812 06:20:12.040367 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000024 (ops 114-118)
I20260812 06:20:12.040407 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000025 (ops 119-122)
I20260812 06:20:12.040447 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000026 (ops 123-127)
I20260812 06:20:12.040486 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000027 (ops 128-132)
I20260812 06:20:12.071026 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: LogGCOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:20:12.071554 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=2.188937
I20260812 06:20:12.101018 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.029s	user 0.019s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6809,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.101631 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=2.188937
I20260812 06:20:12.113066 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.011s	user 0.007s	sys 0.002s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4247,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:12.113852 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6): perf score=1.000000
I20260812 06:20:12.368768 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.254s	user 0.165s	sys 0.088s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979849,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":295,"lbm_read_time_us":16755,"lbm_reads_lt_1ms":775,"lbm_write_time_us":44525,"lbm_writes_lt_1ms":743,"mutex_wait_us":3,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":87,"threads_started":1,"update_count":3500}
I20260812 06:20:12.369702 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=18.063937
I20260812 06:20:12.430004 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.060s	user 0.033s	sys 0.020s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":26311,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:12.430605 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6): perf score=1.000000
I20260812 06:20:12.618350 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.188s	user 0.147s	sys 0.035s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24774573,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":94,"lbm_read_time_us":12371,"lbm_reads_lt_1ms":563,"lbm_write_time_us":32156,"lbm_writes_lt_1ms":543,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2500}
I20260812 06:20:12.619673 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=15.087375
I20260812 06:20:12.678541 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.059s	user 0.026s	sys 0.028s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":19921,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:12.679267 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=3.181125
I20260812 06:20:12.692834 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.013s	user 0.004s	sys 0.008s Metrics: {"bytes_written":5005190,"delete_count":0,"lbm_write_time_us":5591,"lbm_writes_lt_1ms":125,"reinsert_count":0,"update_count":610}
I20260812 06:20:12.693320 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=1.196750
I20260812 06:20:12.701617 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.008s	user 0.003s	sys 0.004s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":3015,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:20:12.702364 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6): perf score=1.000000
I20260812 06:20:12.913910 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.211s	user 0.118s	sys 0.092s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877187,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":880,"lbm_read_time_us":15237,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36052,"lbm_writes_lt_1ms":643,"mutex_wait_us":385,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":3000}
I20260812 06:20:12.914889 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=14.095187
I20260812 06:20:12.967322 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.052s	user 0.035s	sys 0.012s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":21039,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:12.967972 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6): perf score=1.000000
I20260812 06:20:13.141248 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.173s	user 0.097s	sys 0.064s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672161,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":188,"lbm_read_time_us":11212,"lbm_reads_lt_1ms":463,"lbm_write_time_us":28085,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2000}
I20260812 06:20:13.141826 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=14.095187
I20260812 06:20:13.194175 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.052s	user 0.021s	sys 0.021s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19033,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:13.194739 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=2.188937
I20260812 06:20:13.207463 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4372,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.208246 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6): perf score=1.000000
I20260812 06:20:13.406183 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.198s	user 0.151s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":320,"lbm_read_time_us":13078,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34103,"lbm_writes_lt_1ms":543,"mutex_wait_us":76,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2500}
I20260812 06:20:13.406960 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=14.095187
I20260812 06:20:13.464329 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.057s	user 0.031s	sys 0.014s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20976,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:13.465031 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=2.188937
I20260812 06:20:13.478229 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.013s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5199,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.478963 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6): perf score=1.000000
I20260812 06:20:13.645785 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.167s	user 0.109s	sys 0.053s 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":151,"lbm_read_time_us":11666,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32206,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:20:13.646658 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=11.118625
I20260812 06:20:13.683547 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.037s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":15186,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:13.684232 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=2.188937
I20260812 06:20:13.711534 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.027s	user 0.001s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5104,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:13.712103 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=2.188937
I20260812 06:20:13.724143 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4180,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.724799 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushMRSOp(6295b4d81e8241148e7cfdce957362f6): perf score=1.000000
I20260812 06:20:13.755173 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushMRSOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.030s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":103,"dirs.run_cpu_time_us":273,"dirs.run_wall_time_us":1707,"drs_written":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2020,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:13.756011 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling LogGCOp(6295b4d81e8241148e7cfdce957362f6): free 133024653 bytes of WAL
I20260812 06:20:13.756283 20597 log_reader.cc:385] T 6295b4d81e8241148e7cfdce957362f6: removed 13 log segments from log reader
I20260812 06:20:13.756328 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000028 (ops 133-137)
I20260812 06:20:13.756361 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000029 (ops 138-142)
I20260812 06:20:13.756436 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000030 (ops 143-147)
I20260812 06:20:13.756505 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000031 (ops 148-152)
I20260812 06:20:13.756575 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000032 (ops 153-156)
I20260812 06:20:13.756614 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000033 (ops 157-161)
I20260812 06:20:13.756675 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000034 (ops 162-166)
I20260812 06:20:13.756713 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000035 (ops 167-171)
I20260812 06:20:13.756752 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000036 (ops 172-176)
I20260812 06:20:13.756793 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000037 (ops 177-181)
I20260812 06:20:13.756832 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000038 (ops 182-186)
I20260812 06:20:13.756870 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000039 (ops 187-191)
I20260812 06:20:13.756908 20597 log.cc:1079] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: Deleting log segment in path: /tmp/dist-test-taskn5fn8E/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515602589543-20250-0/minicluster-data/ts-0-root/wals/6295b4d81e8241148e7cfdce957362f6/wal-000000040 (ops 192-196)
I20260812 06:20:13.788396 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: LogGCOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.032s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:20:13.788892 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling UndoDeltaBlockGCOp(6295b4d81e8241148e7cfdce957362f6): 492 bytes on disk
I20260812 06:20:13.789608 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: UndoDeltaBlockGCOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":103,"lbm_reads_lt_1ms":4}
I20260812 06:20:13.790356 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=5.165500
I20260812 06:20:13.827282 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.037s	user 0.012s	sys 0.023s Metrics: {"bytes_written":6851279,"delete_count":0,"lbm_write_time_us":10047,"lbm_writes_lt_1ms":170,"reinsert_count":0,"update_count":835}
I20260812 06:20:13.827945 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6): perf score=1.000000
I20260812 06:20:13.836512 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: FlushDeltaMemStoresOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.008s	user 0.003s	sys 0.003s Metrics: {"bytes_written":1353977,"delete_count":0,"lbm_write_time_us":2195,"lbm_writes_lt_1ms":36,"reinsert_count":0,"update_count":165}
I20260812 06:20:13.837162 20669 maintenance_manager.cc:419] P 72c93805a12c408fa49c05f5d37d7a09: Scheduling MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6): perf score=1.000000
I20260812 06:20:13.886425 20250 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.250s	user 1.829s	sys 0.245s
I20260812 06:20:13.994673 20250 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.108s	user 0.002s	sys 0.000s
I20260812 06:20:13.995291 20250 tablet_server.cc:179] TabletServer@127.19.198.129:0 shutting down...
I20260812 06:20:14.045353 20597 maintenance_manager.cc:643] P 72c93805a12c408fa49c05f5d37d7a09: MajorDeltaCompactionOp(6295b4d81e8241148e7cfdce957362f6) complete. Timing: real 0.208s	user 0.132s	sys 0.076s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979796,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":719,"lbm_read_time_us":18314,"lbm_reads_lt_1ms":771,"lbm_write_time_us":34760,"lbm_writes_lt_1ms":743,"mutex_wait_us":131,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:20:14.046362 20250 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:14.046753 20250 tablet_replica.cc:333] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09: stopping tablet replica
I20260812 06:20:14.046947 20250 raft_consensus.cc:2243] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:14.047148 20250 raft_consensus.cc:2272] T 6295b4d81e8241148e7cfdce957362f6 P 72c93805a12c408fa49c05f5d37d7a09 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:14.053159 20250 tablet_server.cc:196] TabletServer@127.19.198.129:0 shutdown complete.
I20260812 06:20:14.104806 20250 master.cc:562] Master@127.19.198.190:43411 shutting down...
I20260812 06:20:14.108484 20250 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:14.108733 20250 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:14.108827 20250 tablet_replica.cc:333] T 00000000000000000000000000000000 P 995adc89e40c473f9868a970d81dded3: stopping tablet replica
I20260812 06:20:14.121745 20250 master.cc:584] Master@127.19.198.190:43411 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5788 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11612 ms total)

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