[==========] 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:17:05.838932 27954 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.27.76.190:44779
I20260812 06:17:05.839846 27954 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:17:05.840399 27954 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:05.846968 27960 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:17:05.847119 27954 server_base.cc:1061] running on GCE node
W20260812 06:17:05.846959 27967 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:17:05.847537 27963 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:17:05.847961 27954 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:05.848059 27954 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:17:05.848101 27954 hybrid_clock.cc:648] HybridClock initialized: now 1786515425848099 us; error 0 us; skew 500 ppm
I20260812 06:17:05.849879 27954 webserver.cc:533] Webserver started at http://127.27.76.190:46409/ using document root <none> and password file <none>
I20260812 06:17:05.850409 27954 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:05.850469 27954 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:05.850679 27954 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:05.852219 27954 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/master-0-root/instance:
uuid: "e4c5aac68cfd4ceabcd4772ea434153a"
format_stamp: "Formatted at 2026-08-12 06:17:05 on dist-test-slave-266d"
I20260812 06:17:05.855410 27954 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.001s	sys 0.003s
I20260812 06:17:05.857537 27973 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:17:05.858448 27954 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:17:05.858551 27954 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/master-0-root
uuid: "e4c5aac68cfd4ceabcd4772ea434153a"
format_stamp: "Formatted at 2026-08-12 06:17:05 on dist-test-slave-266d"
I20260812 06:17:05.858629 27954 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-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:17:05.885457 27954 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:05.886058 27954 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:17:05.886214 27954 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:05.893512 27954 rpc_server.cc:307] RPC server started. Bound to: 127.27.76.190:44779
I20260812 06:17:05.893508 28056 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.76.190:44779 every 8 connection(s)
I20260812 06:17:05.895687 28058 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:17:05.900872 28058 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a: Bootstrap starting.
I20260812 06:17:05.903082 28058 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:05.903918 28058 log.cc:826] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:05.905452 28058 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a: No bootstrap required, opened a new log
I20260812 06:17:05.908004 28058 raft_consensus.cc:359] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e4c5aac68cfd4ceabcd4772ea434153a" member_type: VOTER }
I20260812 06:17:05.908155 28058 raft_consensus.cc:385] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:05.908222 28058 raft_consensus.cc:740] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e4c5aac68cfd4ceabcd4772ea434153a, State: Initialized, Role: FOLLOWER
I20260812 06:17:05.908751 28058 consensus_queue.cc:260] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a [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: "e4c5aac68cfd4ceabcd4772ea434153a" member_type: VOTER }
I20260812 06:17:05.908896 28058 raft_consensus.cc:399] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:05.908959 28058 raft_consensus.cc:493] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:05.909075 28058 raft_consensus.cc:3060] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:05.909782 28058 raft_consensus.cc:515] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e4c5aac68cfd4ceabcd4772ea434153a" member_type: VOTER }
I20260812 06:17:05.910181 28058 leader_election.cc:304] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a [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: e4c5aac68cfd4ceabcd4772ea434153a; no voters: 
I20260812 06:17:05.910445 28058 leader_election.cc:290] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:05.910565 28066 raft_consensus.cc:2804] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:05.910768 28066 raft_consensus.cc:697] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a [term 1 LEADER]: Becoming Leader. State: Replica: e4c5aac68cfd4ceabcd4772ea434153a, State: Running, Role: LEADER
I20260812 06:17:05.911155 28066 consensus_queue.cc:237] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a [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: "e4c5aac68cfd4ceabcd4772ea434153a" member_type: VOTER }
I20260812 06:17:05.911327 28058 sys_catalog.cc:565] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:05.912851 28069 sys_catalog.cc:455] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a [sys.catalog]: SysCatalogTable state changed. Reason: New leader e4c5aac68cfd4ceabcd4772ea434153a. Latest consensus state: current_term: 1 leader_uuid: "e4c5aac68cfd4ceabcd4772ea434153a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e4c5aac68cfd4ceabcd4772ea434153a" member_type: VOTER } }
I20260812 06:17:05.912849 28068 sys_catalog.cc:455] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "e4c5aac68cfd4ceabcd4772ea434153a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e4c5aac68cfd4ceabcd4772ea434153a" member_type: VOTER } }
I20260812 06:17:05.912987 28068 sys_catalog.cc:458] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:05.912987 28069 sys_catalog.cc:458] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:05.913467 27954 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:17:05.915380 28089 catalog_manager.cc:1594] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:17:05.915454 28089 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:17:05.915518 28087 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:05.916182 28087 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:05.920394 28087 catalog_manager.cc:1383] Generated new cluster ID: ad7e9e364e2445539e2eaccf048c1879
I20260812 06:17:05.920455 28087 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:05.936705 28087 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:05.937737 28087 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:05.945540 28087 catalog_manager.cc:6092] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a: Generated new TSK 0
I20260812 06:17:05.946040 28087 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:05.978040 27954 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:05.980742 28099 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:17:05.980715 28095 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:17:05.980901 27954 server_base.cc:1061] running on GCE node
W20260812 06:17:05.980760 28096 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:17:05.981241 27954 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:05.981285 27954 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:17:05.981319 27954 hybrid_clock.cc:648] HybridClock initialized: now 1786515425981319 us; error 0 us; skew 500 ppm
I20260812 06:17:05.982170 27954 webserver.cc:533] Webserver started at http://127.27.76.129:35175/ using document root <none> and password file <none>
I20260812 06:17:05.982338 27954 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:05.982384 27954 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:05.982460 27954 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:05.982801 27954 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/instance:
uuid: "9f0e8c1b1d94474a834efa91a2fa8529"
format_stamp: "Formatted at 2026-08-12 06:17:05 on dist-test-slave-266d"
I20260812 06:17:05.984184 27954 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:05.985066 28109 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:17:05.985348 27954 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:05.985430 27954 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root
uuid: "9f0e8c1b1d94474a834efa91a2fa8529"
format_stamp: "Formatted at 2026-08-12 06:17:05 on dist-test-slave-266d"
I20260812 06:17:05.985498 27954 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-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:17:05.993407 27954 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:05.993805 27954 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:05.994264 27954 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:05.995177 27954 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:05.995242 27954 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:05.995311 27954 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:05.995342 27954 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:06.001875 27954 rpc_server.cc:307] RPC server started. Bound to: 127.27.76.129:37629
I20260812 06:17:06.001909 28213 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.76.129:37629 every 8 connection(s)
I20260812 06:17:06.010973 28214 heartbeater.cc:344] Connected to a master server at 127.27.76.190:44779
I20260812 06:17:06.011197 28214 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:06.011679 28214 heartbeater.cc:507] Master 127.27.76.190:44779 requested a full tablet report, sending...
I20260812 06:17:06.013042 27999 ts_manager.cc:194] Registered new tserver with Master: 9f0e8c1b1d94474a834efa91a2fa8529 (127.27.76.129:37629)
I20260812 06:17:06.013654 27954 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011129308s
I20260812 06:17:06.014199 27999 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:41304
I20260812 06:17:06.021953 27999 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:41306:
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:17:06.034282 28158 tablet_service.cc:1511] Processing CreateTablet for tablet e0ed81a4838f41ccabd958136420779d (DEFAULT_TABLE table=heavy-update-compaction-test [id=cdfbae53f41247ca91544976f75b4abb]), partition=
I20260812 06:17:06.034715 28158 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet e0ed81a4838f41ccabd958136420779d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:06.037416 28229 tablet_bootstrap.cc:492] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Bootstrap starting.
I20260812 06:17:06.038343 28229 tablet_bootstrap.cc:654] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:06.039592 28229 tablet_bootstrap.cc:492] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: No bootstrap required, opened a new log
I20260812 06:17:06.039676 28229 ts_tablet_manager.cc:1403] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:06.040064 28229 raft_consensus.cc:359] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9f0e8c1b1d94474a834efa91a2fa8529" member_type: VOTER last_known_addr { host: "127.27.76.129" port: 37629 } }
I20260812 06:17:06.040156 28229 raft_consensus.cc:385] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:06.040191 28229 raft_consensus.cc:740] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9f0e8c1b1d94474a834efa91a2fa8529, State: Initialized, Role: FOLLOWER
I20260812 06:17:06.040326 28229 consensus_queue.cc:260] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529 [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: "9f0e8c1b1d94474a834efa91a2fa8529" member_type: VOTER last_known_addr { host: "127.27.76.129" port: 37629 } }
I20260812 06:17:06.040400 28229 raft_consensus.cc:399] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:06.040436 28229 raft_consensus.cc:493] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:06.040484 28229 raft_consensus.cc:3060] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:06.041175 28229 raft_consensus.cc:515] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9f0e8c1b1d94474a834efa91a2fa8529" member_type: VOTER last_known_addr { host: "127.27.76.129" port: 37629 } }
I20260812 06:17:06.041296 28229 leader_election.cc:304] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529 [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: 9f0e8c1b1d94474a834efa91a2fa8529; no voters: 
I20260812 06:17:06.041487 28229 leader_election.cc:290] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:06.041625 28231 raft_consensus.cc:2804] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:06.041839 28229 ts_tablet_manager.cc:1434] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:06.041869 28231 raft_consensus.cc:697] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529 [term 1 LEADER]: Becoming Leader. State: Replica: 9f0e8c1b1d94474a834efa91a2fa8529, State: Running, Role: LEADER
I20260812 06:17:06.042043 28231 consensus_queue.cc:237] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529 [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: "9f0e8c1b1d94474a834efa91a2fa8529" member_type: VOTER last_known_addr { host: "127.27.76.129" port: 37629 } }
I20260812 06:17:06.042178 28214 heartbeater.cc:499] Master 127.27.76.190:44779 was elected leader, sending a full tablet report...
I20260812 06:17:06.044757 27999 catalog_manager.cc:5719] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529 reported cstate change: term changed from 0 to 1, leader changed from <none> to 9f0e8c1b1d94474a834efa91a2fa8529 (127.27.76.129). New cstate: current_term: 1 leader_uuid: "9f0e8c1b1d94474a834efa91a2fa8529" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9f0e8c1b1d94474a834efa91a2fa8529" member_type: VOTER last_known_addr { host: "127.27.76.129" port: 37629 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:06.108901 27954 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.026s	sys 0.007s
I20260812 06:17:06.253252 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushMRSOp(e0ed81a4838f41ccabd958136420779d): perf score=21.039315
I20260812 06:17:06.456060 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushMRSOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.202s	user 0.163s	sys 0.036s Metrics: {"bytes_written":16409904,"cfile_init":1,"compiler_manager_pool.queue_time_us":201,"delete_count":0,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":211,"dirs.run_wall_time_us":783,"drs_written":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4,"lbm_write_time_us":51627,"lbm_writes_lt_1ms":957,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"thread_start_us":124,"threads_started":1,"update_count":2000}
I20260812 06:17:06.457294 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling LogGCOp(e0ed81a4838f41ccabd958136420779d): free 20743880 bytes of WAL
I20260812 06:17:06.457607 28115 log_reader.cc:385] T e0ed81a4838f41ccabd958136420779d: removed 2 log segments from log reader
I20260812 06:17:06.457687 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000001 (ops 1-6)
I20260812 06:17:06.457751 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000002 (ops 7-11)
I20260812 06:17:06.462771 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: LogGCOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:17:06.463073 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling UndoDeltaBlockGCOp(e0ed81a4838f41ccabd958136420779d): 20513813 bytes on disk
I20260812 06:17:06.463680 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: UndoDeltaBlockGCOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:17:06.464051 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=3.181125
I20260812 06:17:06.479372 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5552,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:06.479777 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=2.188937
I20260812 06:17:06.489459 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3709,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:06.489801 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d): perf score=1.000000
I20260812 06:17:06.679790 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.190s	user 0.114s	sys 0.069s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918207,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":424,"lbm_read_time_us":12929,"lbm_reads_lt_1ms":669,"lbm_write_time_us":31579,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":216,"threads_started":5,"update_count":3000}
I20260812 06:17:06.680222 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=14.095187
I20260812 06:17:06.723800 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.043s	user 0.025s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":17519,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:06.724300 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d): perf score=1.000000
I20260812 06:17:06.868511 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.144s	user 0.072s	sys 0.062s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713151,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":94,"lbm_read_time_us":8209,"lbm_reads_lt_1ms":463,"lbm_write_time_us":20771,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":41216,"update_count":2000}
I20260812 06:17:06.869014 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=14.095187
I20260812 06:17:06.918537 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.049s	user 0.035s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21394,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:06.919000 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=2.188937
I20260812 06:17:06.939864 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.021s	user 0.010s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4643,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:06.940290 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d): perf score=1.000000
I20260812 06:17:07.101711 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.161s	user 0.090s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":545,"lbm_read_time_us":10135,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26423,"lbm_writes_lt_1ms":543,"mutex_wait_us":262,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:07.102180 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=14.095187
I20260812 06:17:07.142910 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.041s	user 0.030s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16656,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:07.143340 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=2.188937
I20260812 06:17:07.157922 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5378,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.158404 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d): perf score=1.000000
I20260812 06:17:07.300383 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.142s	user 0.093s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":263,"lbm_read_time_us":9402,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28265,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:17:07.301527 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=10.126437
I20260812 06:17:07.335372 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.034s	user 0.011s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13033,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:07.335858 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=2.188937
I20260812 06:17:07.345418 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.009s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3491,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.345957 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d): perf score=1.000000
I20260812 06:17:07.463038 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.117s	user 0.093s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1079,"lbm_read_time_us":9813,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20627,"lbm_writes_lt_1ms":443,"mutex_wait_us":278,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:07.463546 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=10.126437
I20260812 06:17:07.509366 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.046s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13176,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:07.509905 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=2.188937
I20260812 06:17:07.519588 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3629,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.520040 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushMRSOp(e0ed81a4838f41ccabd958136420779d): perf score=1.000000
I20260812 06:17:07.548130 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushMRSOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.028s	user 0.020s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":249,"dirs.run_wall_time_us":1287,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1352,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:07.548933 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling LogGCOp(e0ed81a4838f41ccabd958136420779d): free 120553317 bytes of WAL
I20260812 06:17:07.549194 28115 log_reader.cc:385] T e0ed81a4838f41ccabd958136420779d: removed 12 log segments from log reader
I20260812 06:17:07.549254 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000003 (ops 12-16)
I20260812 06:17:07.549300 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000004 (ops 17-21)
I20260812 06:17:07.549329 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000005 (ops 22-26)
I20260812 06:17:07.549357 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000006 (ops 27-31)
I20260812 06:17:07.549388 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000007 (ops 32-36)
I20260812 06:17:07.549419 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000008 (ops 37-40)
I20260812 06:17:07.549448 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000009 (ops 41-45)
I20260812 06:17:07.549474 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000010 (ops 46-50)
I20260812 06:17:07.549502 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000011 (ops 51-55)
I20260812 06:17:07.549535 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000012 (ops 56-60)
I20260812 06:17:07.549564 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000013 (ops 61-64)
I20260812 06:17:07.549592 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000014 (ops 65-69)
I20260812 06:17:07.574956 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: LogGCOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.026s	user 0.004s	sys 0.019s Metrics: {}
I20260812 06:17:07.575361 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=3.181125
I20260812 06:17:07.589507 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.014s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4509,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:07.589938 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=2.188937
I20260812 06:17:07.603169 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4848,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:07.603624 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling UndoDeltaBlockGCOp(e0ed81a4838f41ccabd958136420779d): 448 bytes on disk
I20260812 06:17:07.604195 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: UndoDeltaBlockGCOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4}
I20260812 06:17:07.604667 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d): perf score=1.000000
I20260812 06:17:07.767046 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.162s	user 0.126s	sys 0.036s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":116,"lbm_read_time_us":12857,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32298,"lbm_writes_lt_1ms":643,"mutex_wait_us":25,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":56704,"thread_start_us":72,"threads_started":1,"update_count":3000}
I20260812 06:17:07.767525 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=14.095187
I20260812 06:17:07.810401 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.043s	user 0.031s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17400,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:07.810964 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=2.188937
I20260812 06:17:07.823302 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4259,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.823814 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d): perf score=1.000000
I20260812 06:17:07.984256 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.160s	user 0.117s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":870,"lbm_read_time_us":11041,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31063,"lbm_writes_lt_1ms":543,"mutex_wait_us":279,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:07.984730 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=14.095187
I20260812 06:17:08.026543 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.042s	user 0.033s	sys 0.007s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":17899,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:08.027024 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d): perf score=1.000000
I20260812 06:17:08.153260 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.126s	user 0.094s	sys 0.032s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713151,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":64,"lbm_read_time_us":8323,"lbm_reads_lt_1ms":467,"lbm_write_time_us":21471,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2000}
I20260812 06:17:08.153726 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=10.126437
I20260812 06:17:08.182951 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.029s	user 0.015s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12350,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:08.183413 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=2.188937
I20260812 06:17:08.197885 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5293,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:08.198405 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d): perf score=1.000000
I20260812 06:17:08.332211 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.134s	user 0.077s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":137,"lbm_read_time_us":8932,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24249,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:17:08.332752 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=10.126437
I20260812 06:17:08.375031 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.042s	user 0.016s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13089,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:08.375559 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=2.188937
I20260812 06:17:08.385756 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3564,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:08.386348 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d): perf score=1.000000
I20260812 06:17:08.494910 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.108s	user 0.084s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1171,"lbm_read_time_us":7379,"lbm_reads_lt_1ms":472,"lbm_write_time_us":19583,"lbm_writes_lt_1ms":443,"mutex_wait_us":365,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2000}
I20260812 06:17:08.495425 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=10.126437
I20260812 06:17:08.531172 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.036s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16194,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1500}
I20260812 06:17:08.531663 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=2.188937
I20260812 06:17:08.547049 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5884,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:08.547802 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d): perf score=1.000000
I20260812 06:17:08.669458 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.121s	user 0.091s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":820,"lbm_read_time_us":9370,"lbm_reads_lt_1ms":468,"lbm_write_time_us":21150,"lbm_writes_lt_1ms":443,"mutex_wait_us":335,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":63104,"update_count":2000}
I20260812 06:17:08.670109 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=10.126437
I20260812 06:17:08.720031 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.050s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12941,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:08.720575 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=2.188937
I20260812 06:17:08.735239 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5520,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:08.735679 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d): perf score=1.000000
I20260812 06:17:08.886863 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.151s	user 0.094s	sys 0.057s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":203,"lbm_read_time_us":9757,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26033,"lbm_writes_lt_1ms":443,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18688,"update_count":2000}
I20260812 06:17:08.887465 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=10.126437
I20260812 06:17:08.919462 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.032s	user 0.002s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13806,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:08.920013 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushMRSOp(e0ed81a4838f41ccabd958136420779d): perf score=1.000000
I20260812 06:17:08.970934 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushMRSOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.051s	user 0.030s	sys 0.003s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":1270,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1506,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:08.971731 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling LogGCOp(e0ed81a4838f41ccabd958136420779d): free 120553380 bytes of WAL
I20260812 06:17:08.971971 28115 log_reader.cc:385] T e0ed81a4838f41ccabd958136420779d: removed 12 log segments from log reader
I20260812 06:17:08.972018 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000015 (ops 70-74)
I20260812 06:17:08.972046 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000016 (ops 75-78)
I20260812 06:17:08.972064 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000017 (ops 79-83)
I20260812 06:17:08.972090 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000018 (ops 84-88)
I20260812 06:17:08.972121 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000019 (ops 89-93)
I20260812 06:17:08.972151 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000020 (ops 94-98)
I20260812 06:17:08.972182 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000021 (ops 99-102)
I20260812 06:17:08.972213 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000022 (ops 103-107)
I20260812 06:17:08.972244 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000023 (ops 108-112)
I20260812 06:17:08.972275 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000024 (ops 113-117)
I20260812 06:17:08.972306 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000025 (ops 118-122)
I20260812 06:17:08.972335 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000026 (ops 123-127)
I20260812 06:17:08.994094 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: LogGCOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.022s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:17:08.994503 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=6.157687
I20260812 06:17:09.020443 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.026s	user 0.014s	sys 0.009s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":7610,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:09.020977 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=2.188937
I20260812 06:17:09.030701 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3656,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:09.031164 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d): perf score=1.000000
I20260812 06:17:09.224697 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.193s	user 0.136s	sys 0.052s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918215,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":459,"lbm_read_time_us":12688,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31766,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":626304,"thread_start_us":77,"threads_started":1,"update_count":3000}
I20260812 06:17:09.225288 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=14.095187
I20260812 06:17:09.282747 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.057s	user 0.024s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22086,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:09.283331 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling UndoDeltaBlockGCOp(e0ed81a4838f41ccabd958136420779d): 482 bytes on disk
I20260812 06:17:09.283788 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: UndoDeltaBlockGCOp(e0ed81a4838f41ccabd958136420779d) 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:17:09.284339 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=2.188937
I20260812 06:17:09.299486 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.015s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5795,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:09.300094 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d): perf score=1.000000
I20260812 06:17:09.469873 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.170s	user 0.129s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":126,"lbm_read_time_us":11272,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25405,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2500}
I20260812 06:17:09.470379 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=14.095187
I20260812 06:17:09.518618 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.048s	user 0.023s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22827,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:09.519146 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=2.188937
I20260812 06:17:09.538942 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.020s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6123,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:09.539492 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d): perf score=1.000000
I20260812 06:17:09.716833 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.177s	user 0.107s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":233,"lbm_read_time_us":11748,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31247,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2500}
I20260812 06:17:09.717309 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=14.095187
I20260812 06:17:09.760463 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.043s	user 0.022s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17358,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:09.760958 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=2.188937
I20260812 06:17:09.772768 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4216,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:09.773284 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d): perf score=1.000000
I20260812 06:17:09.937500 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.164s	user 0.111s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":175,"lbm_read_time_us":10693,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24778,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2500}
I20260812 06:17:09.938062 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=14.095187
I20260812 06:17:09.984295 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.046s	user 0.033s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18688,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:09.984844 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=2.188937
I20260812 06:17:09.995013 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3631,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:09.995612 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d): perf score=1.000000
I20260812 06:17:10.137969 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.142s	user 0.110s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":830,"lbm_read_time_us":10601,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27860,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":68608,"update_count":2500}
I20260812 06:17:10.138624 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=10.126437
I20260812 06:17:10.165460 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.027s	user 0.023s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":11228,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:10.165958 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=2.188937
I20260812 06:17:10.180183 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.014s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5055,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:10.180740 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d): perf score=1.000000
I20260812 06:17:10.297897 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.117s	user 0.099s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":665,"lbm_read_time_us":8644,"lbm_reads_lt_1ms":468,"lbm_write_time_us":21896,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":304,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:10.298400 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=10.126437
I20260812 06:17:10.336427 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.038s	user 0.020s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13011,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1500}
I20260812 06:17:10.336987 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=2.188937
I20260812 06:17:10.346454 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3465,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:10.347103 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushMRSOp(e0ed81a4838f41ccabd958136420779d): perf score=1.000000
I20260812 06:17:10.379942 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushMRSOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.033s	user 0.025s	sys 0.003s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":305,"dirs.run_wall_time_us":1383,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1599,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:10.380690 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling LogGCOp(e0ed81a4838f41ccabd958136420779d): free 133024692 bytes of WAL
I20260812 06:17:10.380926 28115 log_reader.cc:385] T e0ed81a4838f41ccabd958136420779d: removed 13 log segments from log reader
I20260812 06:17:10.380973 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000027 (ops 128-132)
I20260812 06:17:10.381003 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000028 (ops 133-137)
I20260812 06:17:10.381035 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000029 (ops 138-142)
I20260812 06:17:10.381060 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000030 (ops 143-147)
I20260812 06:17:10.381112 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000031 (ops 148-152)
I20260812 06:17:10.381146 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000032 (ops 153-157)
I20260812 06:17:10.381178 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000033 (ops 158-162)
I20260812 06:17:10.381209 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000034 (ops 163-166)
I20260812 06:17:10.381242 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000035 (ops 167-171)
I20260812 06:17:10.381273 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000036 (ops 172-176)
I20260812 06:17:10.381304 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000037 (ops 177-181)
I20260812 06:17:10.381345 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000038 (ops 182-186)
I20260812 06:17:10.381377 28115 log.cc:1079] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/e0ed81a4838f41ccabd958136420779d/wal-000000039 (ops 187-191)
I20260812 06:17:10.405076 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: LogGCOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.024s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:17:10.405534 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling UndoDeltaBlockGCOp(e0ed81a4838f41ccabd958136420779d): 472 bytes on disk
I20260812 06:17:10.405973 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: UndoDeltaBlockGCOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:17:10.406642 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=3.181125
I20260812 06:17:10.421895 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.015s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4140,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:10.422320 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=2.188937
I20260812 06:17:10.435819 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5094,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:10.436352 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d): perf score=1.000000
I20260812 06:17:10.603432 27954 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.494s	user 1.661s	sys 0.114s
I20260812 06:17:10.606227 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: MajorDeltaCompactionOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.170s	user 0.111s	sys 0.052s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918324,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1397,"lbm_read_time_us":13465,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33099,"lbm_writes_lt_1ms":643,"mutex_wait_us":609,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":75,"threads_started":1,"update_count":3000}
I20260812 06:17:10.606746 28215 maintenance_manager.cc:419] P 9f0e8c1b1d94474a834efa91a2fa8529: Scheduling FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d): perf score=14.095187
I20260812 06:17:10.634804 27954 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.031s	user 0.003s	sys 0.000s
I20260812 06:17:10.635403 27954 tablet_server.cc:179] TabletServer@127.27.76.129:0 shutting down...
I20260812 06:17:10.651630 28115 maintenance_manager.cc:643] P 9f0e8c1b1d94474a834efa91a2fa8529: FlushDeltaMemStoresOp(e0ed81a4838f41ccabd958136420779d) complete. Timing: real 0.045s	user 0.026s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19719,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:10.652146 27954 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:10.652824 27954 tablet_replica.cc:333] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529: stopping tablet replica
I20260812 06:17:10.653047 27954 raft_consensus.cc:2243] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:10.653286 27954 raft_consensus.cc:2272] T e0ed81a4838f41ccabd958136420779d P 9f0e8c1b1d94474a834efa91a2fa8529 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:10.667624 27954 tablet_server.cc:196] TabletServer@127.27.76.129:0 shutdown complete.
I20260812 06:17:10.671797 27954 master.cc:562] Master@127.27.76.190:44779 shutting down...
I20260812 06:17:10.674853 27954 raft_consensus.cc:2243] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:10.674981 27954 raft_consensus.cc:2272] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:10.675030 27954 tablet_replica.cc:333] T 00000000000000000000000000000000 P e4c5aac68cfd4ceabcd4772ea434153a: stopping tablet replica
I20260812 06:17:10.686739 27954 master.cc:584] Master@127.27.76.190:44779 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (4919 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:10.757632 27954 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.27.76.190:36723
I20260812 06:17:10.757994 27954 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:10.759747 28273 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:17:10.759824 28275 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:17:10.759865 27954 server_base.cc:1061] running on GCE node
W20260812 06:17:10.759994 28271 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:17:10.760272 27954 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:10.760322 27954 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:17:10.760344 27954 hybrid_clock.cc:648] HybridClock initialized: now 1786515430760344 us; error 0 us; skew 500 ppm
I20260812 06:17:10.761188 27954 webserver.cc:533] Webserver started at http://127.27.76.190:45983/ using document root <none> and password file <none>
I20260812 06:17:10.761337 27954 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:10.761382 27954 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:10.761454 27954 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:10.761814 27954 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/master-0-root/instance:
uuid: "a0ef3a56ac68489fbef26782e09223f5"
format_stamp: "Formatted at 2026-08-12 06:17:10 on dist-test-slave-266d"
I20260812 06:17:10.763168 27954 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:10.763976 28283 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:17:10.764169 27954 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:10.764236 27954 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/master-0-root
uuid: "a0ef3a56ac68489fbef26782e09223f5"
format_stamp: "Formatted at 2026-08-12 06:17:10 on dist-test-slave-266d"
I20260812 06:17:10.764299 27954 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-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:17:10.784912 27954 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:10.785288 27954 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:10.788980 27954 rpc_server.cc:307] RPC server started. Bound to: 127.27.76.190:36723
I20260812 06:17:10.803403 28369 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.76.190:36723 every 8 connection(s)
I20260812 06:17:10.803411 28370 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:17:10.805259 28370 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5: Bootstrap starting.
I20260812 06:17:10.806015 28370 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:10.806945 28370 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5: No bootstrap required, opened a new log
I20260812 06:17:10.807317 28370 raft_consensus.cc:359] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a0ef3a56ac68489fbef26782e09223f5" member_type: VOTER }
I20260812 06:17:10.807400 28370 raft_consensus.cc:385] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:10.807430 28370 raft_consensus.cc:740] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a0ef3a56ac68489fbef26782e09223f5, State: Initialized, Role: FOLLOWER
I20260812 06:17:10.807572 28370 consensus_queue.cc:260] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5 [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: "a0ef3a56ac68489fbef26782e09223f5" member_type: VOTER }
I20260812 06:17:10.807657 28370 raft_consensus.cc:399] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:10.807693 28370 raft_consensus.cc:493] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:10.807741 28370 raft_consensus.cc:3060] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:10.808394 28370 raft_consensus.cc:515] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a0ef3a56ac68489fbef26782e09223f5" member_type: VOTER }
I20260812 06:17:10.808516 28370 leader_election.cc:304] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5 [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: a0ef3a56ac68489fbef26782e09223f5; no voters: 
I20260812 06:17:10.808687 28370 leader_election.cc:290] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:10.808776 28375 raft_consensus.cc:2804] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:10.808966 28375 raft_consensus.cc:697] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5 [term 1 LEADER]: Becoming Leader. State: Replica: a0ef3a56ac68489fbef26782e09223f5, State: Running, Role: LEADER
I20260812 06:17:10.809129 28370 sys_catalog.cc:565] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:10.809155 28375 consensus_queue.cc:237] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5 [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: "a0ef3a56ac68489fbef26782e09223f5" member_type: VOTER }
I20260812 06:17:10.809574 28377 sys_catalog.cc:455] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5 [sys.catalog]: SysCatalogTable state changed. Reason: New leader a0ef3a56ac68489fbef26782e09223f5. Latest consensus state: current_term: 1 leader_uuid: "a0ef3a56ac68489fbef26782e09223f5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a0ef3a56ac68489fbef26782e09223f5" member_type: VOTER } }
I20260812 06:17:10.809556 28376 sys_catalog.cc:455] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "a0ef3a56ac68489fbef26782e09223f5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a0ef3a56ac68489fbef26782e09223f5" member_type: VOTER } }
I20260812 06:17:10.809660 28377 sys_catalog.cc:458] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:10.809675 28376 sys_catalog.cc:458] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:10.809924 28385 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:10.810645 28385 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:10.810964 27954 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:10.812287 28385 catalog_manager.cc:1383] Generated new cluster ID: afed5c9d034c4c199ca27e9671e16293
I20260812 06:17:10.812346 28385 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:10.828956 28385 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:10.829489 28385 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:10.836962 28385 catalog_manager.cc:6092] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5: Generated new TSK 0
I20260812 06:17:10.837137 28385 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:10.843014 27954 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:10.844753 28415 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:17:10.844851 28414 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:17:10.844901 27954 server_base.cc:1061] running on GCE node
W20260812 06:17:10.844995 28422 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:17:10.845222 27954 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:10.845268 27954 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:17:10.845283 27954 hybrid_clock.cc:648] HybridClock initialized: now 1786515430845283 us; error 0 us; skew 500 ppm
I20260812 06:17:10.846035 27954 webserver.cc:533] Webserver started at http://127.27.76.129:43495/ using document root <none> and password file <none>
I20260812 06:17:10.846161 27954 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:10.846200 27954 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:10.846253 27954 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:10.846578 27954 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/instance:
uuid: "10486e477d2a4460ae1715fdb75ddf09"
format_stamp: "Formatted at 2026-08-12 06:17:10 on dist-test-slave-266d"
I20260812 06:17:10.847875 27954 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:10.848666 28428 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:17:10.848867 27954 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:10.848928 27954 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root
uuid: "10486e477d2a4460ae1715fdb75ddf09"
format_stamp: "Formatted at 2026-08-12 06:17:10 on dist-test-slave-266d"
I20260812 06:17:10.848992 27954 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-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:17:10.868351 27954 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:10.868673 27954 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:10.868959 27954 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:10.869442 27954 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:10.869480 27954 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:10.869513 27954 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:10.869539 27954 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:10.873494 27954 rpc_server.cc:307] RPC server started. Bound to: 127.27.76.129:40175
I20260812 06:17:10.873538 28529 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.76.129:40175 every 8 connection(s)
I20260812 06:17:10.881170 28532 heartbeater.cc:344] Connected to a master server at 127.27.76.190:36723
I20260812 06:17:10.881273 28532 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:10.881488 28532 heartbeater.cc:507] Master 127.27.76.190:36723 requested a full tablet report, sending...
I20260812 06:17:10.882098 28319 ts_manager.cc:194] Registered new tserver with Master: 10486e477d2a4460ae1715fdb75ddf09 (127.27.76.129:40175)
I20260812 06:17:10.882614 27954 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008725208s
I20260812 06:17:10.882829 28319 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:43536
I20260812 06:17:10.888814 28319 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:43540:
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:17:10.896708 28473 tablet_service.cc:1511] Processing CreateTablet for tablet 9fee926a0dc840efbd8600bb59809836 (DEFAULT_TABLE table=heavy-update-compaction-test [id=2b1908f25b93442fba77eca8d9642a8f]), partition=
I20260812 06:17:10.896935 28473 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 9fee926a0dc840efbd8600bb59809836. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:10.898849 28554 tablet_bootstrap.cc:492] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Bootstrap starting.
I20260812 06:17:10.899725 28554 tablet_bootstrap.cc:654] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:10.900640 28554 tablet_bootstrap.cc:492] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: No bootstrap required, opened a new log
I20260812 06:17:10.900710 28554 ts_tablet_manager.cc:1403] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:10.901049 28554 raft_consensus.cc:359] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "10486e477d2a4460ae1715fdb75ddf09" member_type: VOTER last_known_addr { host: "127.27.76.129" port: 40175 } }
I20260812 06:17:10.901168 28554 raft_consensus.cc:385] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:10.901202 28554 raft_consensus.cc:740] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 10486e477d2a4460ae1715fdb75ddf09, State: Initialized, Role: FOLLOWER
I20260812 06:17:10.901319 28554 consensus_queue.cc:260] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09 [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: "10486e477d2a4460ae1715fdb75ddf09" member_type: VOTER last_known_addr { host: "127.27.76.129" port: 40175 } }
I20260812 06:17:10.901400 28554 raft_consensus.cc:399] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:10.901428 28554 raft_consensus.cc:493] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:10.901461 28554 raft_consensus.cc:3060] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:10.902119 28554 raft_consensus.cc:515] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "10486e477d2a4460ae1715fdb75ddf09" member_type: VOTER last_known_addr { host: "127.27.76.129" port: 40175 } }
I20260812 06:17:10.902257 28554 leader_election.cc:304] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09 [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: 10486e477d2a4460ae1715fdb75ddf09; no voters: 
I20260812 06:17:10.902452 28554 leader_election.cc:290] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:10.902522 28559 raft_consensus.cc:2804] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:10.902681 28559 raft_consensus.cc:697] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09 [term 1 LEADER]: Becoming Leader. State: Replica: 10486e477d2a4460ae1715fdb75ddf09, State: Running, Role: LEADER
I20260812 06:17:10.902877 28532 heartbeater.cc:499] Master 127.27.76.190:36723 was elected leader, sending a full tablet report...
I20260812 06:17:10.902874 28559 consensus_queue.cc:237] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09 [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: "10486e477d2a4460ae1715fdb75ddf09" member_type: VOTER last_known_addr { host: "127.27.76.129" port: 40175 } }
I20260812 06:17:10.903029 28554 ts_tablet_manager.cc:1434] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:10.904119 28319 catalog_manager.cc:5719] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09 reported cstate change: term changed from 0 to 1, leader changed from <none> to 10486e477d2a4460ae1715fdb75ddf09 (127.27.76.129). New cstate: current_term: 1 leader_uuid: "10486e477d2a4460ae1715fdb75ddf09" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "10486e477d2a4460ae1715fdb75ddf09" member_type: VOTER last_known_addr { host: "127.27.76.129" port: 40175 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:10.956344 27954 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.049s	user 0.017s	sys 0.004s
I20260812 06:17:11.124459 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushMRSOp(9fee926a0dc840efbd8600bb59809836): perf score=23.023690
I20260812 06:17:11.276173 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushMRSOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.151s	user 0.093s	sys 0.055s Metrics: {"bytes_written":13333096,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":178,"dirs.run_wall_time_us":837,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40217,"lbm_writes_lt_1ms":882,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":896,"update_count":1625}
I20260812 06:17:11.276789 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling LogGCOp(9fee926a0dc840efbd8600bb59809836): free 20743880 bytes of WAL
I20260812 06:17:11.276983 28439 log_reader.cc:385] T 9fee926a0dc840efbd8600bb59809836: removed 2 log segments from log reader
I20260812 06:17:11.277027 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000001 (ops 1-6)
I20260812 06:17:11.277065 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000002 (ops 7-11)
I20260812 06:17:11.280683 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: LogGCOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.004s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:11.281054 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=2.188937
I20260812 06:17:11.291186 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.010s	user 0.006s	sys 0.001s Metrics: {"bytes_written":3487284,"delete_count":0,"lbm_write_time_us":2912,"lbm_writes_lt_1ms":88,"reinsert_count":0,"update_count":425}
I20260812 06:17:11.291538 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling UndoDeltaBlockGCOp(9fee926a0dc840efbd8600bb59809836): 20513810 bytes on disk
I20260812 06:17:11.291916 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: UndoDeltaBlockGCOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:17:11.292289 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=2.188937
I20260812 06:17:11.304921 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4655,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:11.305378 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836): perf score=1.000000
I20260812 06:17:11.449045 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.144s	user 0.109s	sys 0.034s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815780,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":446,"lbm_read_time_us":11010,"lbm_reads_lt_1ms":569,"lbm_write_time_us":24645,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":292,"threads_started":5,"update_count":2500}
I20260812 06:17:11.449594 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=14.095187
I20260812 06:17:11.494915 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.045s	user 0.021s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":16716,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:11.495340 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=2.188937
I20260812 06:17:11.504806 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3614,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:11.505285 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836): perf score=1.000000
I20260812 06:17:11.664517 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.159s	user 0.125s	sys 0.023s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":545,"lbm_read_time_us":10594,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29828,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:17:11.665161 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=14.095187
I20260812 06:17:11.716619 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.051s	user 0.017s	sys 0.025s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20627,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:11.717078 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=2.188937
I20260812 06:17:11.726480 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3499,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:11.726854 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836): perf score=1.000000
I20260812 06:17:11.897272 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.170s	user 0.127s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":631,"lbm_read_time_us":10346,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27496,"lbm_writes_lt_1ms":543,"mutex_wait_us":309,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2500}
I20260812 06:17:11.897810 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=14.095187
I20260812 06:17:11.942570 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.045s	user 0.029s	sys 0.010s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":17790,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:11.943077 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836): perf score=1.000000
I20260812 06:17:12.085676 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.142s	user 0.094s	sys 0.045s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713150,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":974,"lbm_read_time_us":10308,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22149,"lbm_writes_lt_1ms":443,"mutex_wait_us":299,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:12.086105 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=14.095187
I20260812 06:17:12.134919 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.049s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20689,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:12.135375 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=2.188937
I20260812 06:17:12.146961 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4214,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.147459 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836): perf score=1.000000
I20260812 06:17:12.328189 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.181s	user 0.117s	sys 0.058s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":583,"dirs.run_cpu_time_us":461,"dirs.run_wall_time_us":2417,"lbm_read_time_us":10582,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27940,"lbm_writes_lt_1ms":543,"mutex_wait_us":233,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2500}
I20260812 06:17:12.328754 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=14.095187
I20260812 06:17:12.375603 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.047s	user 0.041s	sys 0.003s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19983,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:12.376142 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=2.188937
I20260812 06:17:12.386343 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3715,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.386860 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushMRSOp(9fee926a0dc840efbd8600bb59809836): perf score=1.000000
I20260812 06:17:12.413535 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushMRSOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.026s	user 0.020s	sys 0.006s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":218,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":1189,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1544,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:12.414171 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling LogGCOp(9fee926a0dc840efbd8600bb59809836): free 120553317 bytes of WAL
I20260812 06:17:12.414417 28439 log_reader.cc:385] T 9fee926a0dc840efbd8600bb59809836: removed 12 log segments from log reader
I20260812 06:17:12.414467 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000003 (ops 12-16)
I20260812 06:17:12.414494 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000004 (ops 17-21)
I20260812 06:17:12.414513 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000005 (ops 22-26)
I20260812 06:17:12.414544 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000006 (ops 27-30)
I20260812 06:17:12.414577 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000007 (ops 31-35)
I20260812 06:17:12.414594 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000008 (ops 36-40)
I20260812 06:17:12.414625 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000009 (ops 41-45)
I20260812 06:17:12.414657 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000010 (ops 46-50)
I20260812 06:17:12.414688 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000011 (ops 51-55)
I20260812 06:17:12.414721 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000012 (ops 56-60)
I20260812 06:17:12.414752 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000013 (ops 61-64)
I20260812 06:17:12.414781 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000014 (ops 65-69)
I20260812 06:17:12.434890 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: LogGCOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.021s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:17:12.440795 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling UndoDeltaBlockGCOp(9fee926a0dc840efbd8600bb59809836): 462 bytes on disk
I20260812 06:17:12.441350 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: UndoDeltaBlockGCOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:17:12.441962 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=2.188937
I20260812 06:17:12.462634 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.021s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6045,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.463008 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=2.188937
I20260812 06:17:12.472597 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.009s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3630,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.472949 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836): perf score=1.000000
I20260812 06:17:12.703685 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.231s	user 0.144s	sys 0.076s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020747,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":681,"lbm_read_time_us":14508,"lbm_reads_lt_1ms":774,"lbm_write_time_us":34783,"lbm_writes_lt_1ms":743,"mutex_wait_us":296,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":20736,"thread_start_us":115,"threads_started":2,"update_count":3500}
I20260812 06:17:12.704249 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=18.063937
I20260812 06:17:12.771104 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.067s	user 0.045s	sys 0.019s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":32965,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":500,"reinsert_count":0,"update_count":2500}
I20260812 06:17:12.771567 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=2.188937
I20260812 06:17:12.787166 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5770,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.787801 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836): perf score=1.000000
I20260812 06:17:12.989140 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.201s	user 0.134s	sys 0.066s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2091,"lbm_read_time_us":13287,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34379,"lbm_writes_lt_1ms":643,"mutex_wait_us":536,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15232,"update_count":3000}
I20260812 06:17:12.989753 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=14.095187
I20260812 06:17:13.036106 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.046s	user 0.038s	sys 0.005s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20269,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:13.036579 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=2.188937
I20260812 06:17:13.046734 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3953,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.047200 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836): perf score=1.000000
I20260812 06:17:13.217860 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.170s	user 0.111s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":268,"lbm_read_time_us":12385,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26447,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:17:13.218382 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=14.095187
I20260812 06:17:13.265973 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.047s	user 0.039s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19928,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:13.266500 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=2.188937
I20260812 06:17:13.276968 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3684,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.281416 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836): perf score=1.000000
I20260812 06:17:13.446117 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.165s	user 0.123s	sys 0.042s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":232,"lbm_read_time_us":12236,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27145,"lbm_writes_lt_1ms":543,"mutex_wait_us":19,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17280,"update_count":2500}
I20260812 06:17:13.446614 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=14.095187
I20260812 06:17:13.500859 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.054s	user 0.031s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19542,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:13.501545 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=2.188937
I20260812 06:17:13.518735 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.017s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6973,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.519156 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836): perf score=1.000000
I20260812 06:17:13.678251 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.159s	user 0.118s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":596,"lbm_read_time_us":11067,"lbm_reads_lt_1ms":564,"lbm_write_time_us":24524,"lbm_writes_lt_1ms":543,"mutex_wait_us":289,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20096,"update_count":2500}
I20260812 06:17:13.678711 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=14.095187
I20260812 06:17:13.720520 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.042s	user 0.038s	sys 0.000s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18042,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:13.721050 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=2.188937
I20260812 06:17:13.737617 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.016s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3589,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.738049 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushMRSOp(9fee926a0dc840efbd8600bb59809836): perf score=1.000000
I20260812 06:17:13.770216 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushMRSOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.032s	user 0.022s	sys 0.005s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":189,"dirs.run_wall_time_us":1206,"drs_written":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1307,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:13.770921 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling LogGCOp(9fee926a0dc840efbd8600bb59809836): free 112692422 bytes of WAL
I20260812 06:17:13.771139 28439 log_reader.cc:385] T 9fee926a0dc840efbd8600bb59809836: removed 11 log segments from log reader
I20260812 06:17:13.771190 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000015 (ops 70-74)
I20260812 06:17:13.771229 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000016 (ops 75-79)
I20260812 06:17:13.771261 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000017 (ops 80-84)
I20260812 06:17:13.771294 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000018 (ops 85-89)
I20260812 06:17:13.771334 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000019 (ops 90-94)
I20260812 06:17:13.771366 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000020 (ops 95-99)
I20260812 06:17:13.771397 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000021 (ops 100-104)
I20260812 06:17:13.771428 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000022 (ops 105-109)
I20260812 06:17:13.771458 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000023 (ops 110-114)
I20260812 06:17:13.771488 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000024 (ops 115-119)
I20260812 06:17:13.771518 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000025 (ops 120-124)
I20260812 06:17:13.791373 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: LogGCOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.020s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:17:13.791754 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling UndoDeltaBlockGCOp(9fee926a0dc840efbd8600bb59809836): 447 bytes on disk
I20260812 06:17:13.792256 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: UndoDeltaBlockGCOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:17:13.792853 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=3.181125
I20260812 06:17:13.814903 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.022s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4856,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:13.815270 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling LogGCOp(9fee926a0dc840efbd8600bb59809836): free 11564877 bytes of WAL
I20260812 06:17:13.815454 28439 log_reader.cc:385] T 9fee926a0dc840efbd8600bb59809836: removed 1 log segments from log reader
I20260812 06:17:13.815498 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000026 (ops 125-128)
I20260812 06:17:13.817345 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: LogGCOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.002s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:13.817641 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=2.188937
I20260812 06:17:13.826217 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.008s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3109,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:13.826632 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836): perf score=1.000000
I20260812 06:17:14.052028 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.225s	user 0.145s	sys 0.071s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020733,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":198,"lbm_read_time_us":15446,"lbm_reads_lt_1ms":774,"lbm_write_time_us":33377,"lbm_writes_lt_1ms":743,"mutex_wait_us":35,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":21120,"thread_start_us":71,"threads_started":1,"update_count":3500}
I20260812 06:17:14.052578 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=18.063937
I20260812 06:17:14.116546 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.064s	user 0.023s	sys 0.023s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":22262,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:14.117022 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=2.188937
I20260812 06:17:14.126718 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3498,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.127341 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836): perf score=1.000000
I20260812 06:17:14.321256 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.194s	user 0.128s	sys 0.064s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":508,"lbm_read_time_us":12829,"lbm_reads_lt_1ms":672,"lbm_write_time_us":30808,"lbm_writes_lt_1ms":643,"mutex_wait_us":958,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":3000}
I20260812 06:17:14.321800 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=15.087375
I20260812 06:17:14.366242 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.044s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":18786,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:14.366767 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=2.188937
I20260812 06:17:14.378392 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.011s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4442,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:14.378801 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836): perf score=1.000000
I20260812 06:17:14.534667 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.156s	user 0.128s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815671,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":211,"lbm_read_time_us":10925,"lbm_reads_lt_1ms":564,"lbm_write_time_us":25575,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2500}
I20260812 06:17:14.535234 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=14.095187
I20260812 06:17:14.585222 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.050s	user 0.035s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17663,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:14.585760 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=2.188937
I20260812 06:17:14.595445 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3679,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.595927 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836): perf score=1.000000
I20260812 06:17:14.759186 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.163s	user 0.094s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":219,"lbm_read_time_us":11103,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25344,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:17:14.759779 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=14.095187
I20260812 06:17:14.823382 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.063s	user 0.041s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24805,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:14.823928 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=2.188937
I20260812 06:17:14.833506 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.009s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3640,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.833971 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836): perf score=1.000000
I20260812 06:17:15.005261 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.170s	user 0.099s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":361,"lbm_read_time_us":11853,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27209,"lbm_writes_lt_1ms":543,"mutex_wait_us":67,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:17:15.005728 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=14.095187
I20260812 06:17:15.059126 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.053s	user 0.021s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17214,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:15.059603 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=2.188937
I20260812 06:17:15.081636 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.022s	user 0.014s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5477,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.082140 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushMRSOp(9fee926a0dc840efbd8600bb59809836): perf score=1.000000
I20260812 06:17:15.118101 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushMRSOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.036s	user 0.022s	sys 0.005s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":224,"dirs.run_wall_time_us":1371,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1579,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:15.118893 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling LogGCOp(9fee926a0dc840efbd8600bb59809836): free 112692608 bytes of WAL
I20260812 06:17:15.119149 28439 log_reader.cc:385] T 9fee926a0dc840efbd8600bb59809836: removed 11 log segments from log reader
I20260812 06:17:15.119208 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000027 (ops 129-133)
I20260812 06:17:15.119251 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000028 (ops 134-138)
I20260812 06:17:15.119290 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000029 (ops 139-143)
I20260812 06:17:15.119328 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000030 (ops 144-148)
I20260812 06:17:15.119364 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000031 (ops 149-153)
I20260812 06:17:15.119400 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000032 (ops 154-158)
I20260812 06:17:15.119436 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000033 (ops 159-163)
I20260812 06:17:15.119470 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000034 (ops 164-168)
I20260812 06:17:15.119508 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000035 (ops 169-173)
I20260812 06:17:15.119542 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000036 (ops 174-178)
I20260812 06:17:15.119577 28439 log.cc:1079] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: Deleting log segment in path: /tmp/dist-test-taskaaCpo9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515425828737-27954-0/minicluster-data/ts-0-root/wals/9fee926a0dc840efbd8600bb59809836/wal-000000037 (ops 179-183)
I20260812 06:17:15.139587 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: LogGCOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.020s	user 0.003s	sys 0.015s Metrics: {}
I20260812 06:17:15.140012 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling UndoDeltaBlockGCOp(9fee926a0dc840efbd8600bb59809836): 447 bytes on disk
I20260812 06:17:15.140527 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: UndoDeltaBlockGCOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:17:15.141149 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=3.181125
I20260812 06:17:15.159166 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.018s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4559,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:15.159560 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=2.188937
I20260812 06:17:15.169304 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3683,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:15.169755 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836): perf score=1.000000
I20260812 06:17:15.387300 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.217s	user 0.142s	sys 0.076s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020735,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":280,"lbm_read_time_us":16337,"lbm_reads_lt_1ms":774,"lbm_write_time_us":35410,"lbm_writes_lt_1ms":743,"mutex_wait_us":27,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6400,"thread_start_us":72,"threads_started":1,"update_count":3500}
I20260812 06:17:15.388207 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=18.063937
I20260812 06:17:15.448104 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.060s	user 0.032s	sys 0.015s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":22397,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:15.448570 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836): perf score=2.188937
I20260812 06:17:15.458926 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: FlushDeltaMemStoresOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3697,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.459470 28533 maintenance_manager.cc:419] P 10486e477d2a4460ae1715fdb75ddf09: Scheduling MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836): perf score=1.000000
I20260812 06:17:15.545230 27954 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.589s	user 1.647s	sys 0.149s
I20260812 06:17:15.605692 27954 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.060s	user 0.002s	sys 0.000s
I20260812 06:17:15.606171 27954 tablet_server.cc:179] TabletServer@127.27.76.129:0 shutting down...
I20260812 06:17:15.631743 28439 maintenance_manager.cc:643] P 10486e477d2a4460ae1715fdb75ddf09: MajorDeltaCompactionOp(9fee926a0dc840efbd8600bb59809836) complete. Timing: real 0.172s	user 0.104s	sys 0.067s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":193,"lbm_read_time_us":12292,"lbm_reads_lt_1ms":668,"lbm_write_time_us":28150,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":3000}
I20260812 06:17:15.632251 27954 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:15.632508 27954 tablet_replica.cc:333] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09: stopping tablet replica
I20260812 06:17:15.632620 27954 raft_consensus.cc:2243] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:15.632809 27954 raft_consensus.cc:2272] T 9fee926a0dc840efbd8600bb59809836 P 10486e477d2a4460ae1715fdb75ddf09 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:15.655958 27954 tablet_server.cc:196] TabletServer@127.27.76.129:0 shutdown complete.
I20260812 06:17:15.683279 27954 master.cc:562] Master@127.27.76.190:36723 shutting down...
I20260812 06:17:15.685983 27954 raft_consensus.cc:2243] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:15.686139 27954 raft_consensus.cc:2272] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:15.686213 27954 tablet_replica.cc:333] T 00000000000000000000000000000000 P a0ef3a56ac68489fbef26782e09223f5: stopping tablet replica
I20260812 06:17:15.698006 27954 master.cc:584] Master@127.27.76.190:36723 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5010 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (9931 ms total)

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