[==========] 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:18:11.048965  3062 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.2.253.190:40193
I20260812 06:18:11.049950  3062 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:18:11.050541  3062 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:11.058122  3077 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:18:11.058225  3062 server_base.cc:1061] running on GCE node
W20260812 06:18:11.058120  3074 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:18:11.058466  3073 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:18:11.059037  3062 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:11.059128  3062 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:18:11.059154  3062 hybrid_clock.cc:648] HybridClock initialized: now 1786515491059153 us; error 0 us; skew 500 ppm
I20260812 06:18:11.060966  3062 webserver.cc:533] Webserver started at http://127.2.253.190:46613/ using document root <none> and password file <none>
I20260812 06:18:11.061462  3062 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:11.061518  3062 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:11.061749  3062 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:11.063441  3062 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/master-0-root/instance:
uuid: "802a151032d64724ba664d0c1f5a5bcd"
format_stamp: "Formatted at 2026-08-12 06:18:11 on dist-test-slave-s11t"
I20260812 06:18:11.066901  3062 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:18:11.068943  3093 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:18:11.069952  3062 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:11.070046  3062 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/master-0-root
uuid: "802a151032d64724ba664d0c1f5a5bcd"
format_stamp: "Formatted at 2026-08-12 06:18:11 on dist-test-slave-s11t"
I20260812 06:18:11.070123  3062 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-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:18:11.097020  3062 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:11.097642  3062 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:18:11.097786  3062 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:11.105759  3062 rpc_server.cc:307] RPC server started. Bound to: 127.2.253.190:40193
I20260812 06:18:11.105794  3182 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.253.190:40193 every 8 connection(s)
I20260812 06:18:11.108146  3185 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:18:11.113822  3185 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd: Bootstrap starting.
I20260812 06:18:11.116202  3185 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:11.117187  3185 log.cc:826] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:11.118794  3185 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd: No bootstrap required, opened a new log
I20260812 06:18:11.121522  3185 raft_consensus.cc:359] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "802a151032d64724ba664d0c1f5a5bcd" member_type: VOTER }
I20260812 06:18:11.121678  3185 raft_consensus.cc:385] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:11.121719  3185 raft_consensus.cc:740] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 802a151032d64724ba664d0c1f5a5bcd, State: Initialized, Role: FOLLOWER
I20260812 06:18:11.122217  3185 consensus_queue.cc:260] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd [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: "802a151032d64724ba664d0c1f5a5bcd" member_type: VOTER }
I20260812 06:18:11.122344  3185 raft_consensus.cc:399] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:11.122390  3185 raft_consensus.cc:493] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:11.122475  3185 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:11.123219  3185 raft_consensus.cc:515] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "802a151032d64724ba664d0c1f5a5bcd" member_type: VOTER }
I20260812 06:18:11.123584  3185 leader_election.cc:304] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd [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: 802a151032d64724ba664d0c1f5a5bcd; no voters: 
I20260812 06:18:11.123838  3185 leader_election.cc:290] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:11.123967  3188 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:11.124261  3188 raft_consensus.cc:697] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd [term 1 LEADER]: Becoming Leader. State: Replica: 802a151032d64724ba664d0c1f5a5bcd, State: Running, Role: LEADER
I20260812 06:18:11.124656  3188 consensus_queue.cc:237] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd [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: "802a151032d64724ba664d0c1f5a5bcd" member_type: VOTER }
I20260812 06:18:11.125036  3185 sys_catalog.cc:565] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:11.126703  3189 sys_catalog.cc:455] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd [sys.catalog]: SysCatalogTable state changed. Reason: New leader 802a151032d64724ba664d0c1f5a5bcd. Latest consensus state: current_term: 1 leader_uuid: "802a151032d64724ba664d0c1f5a5bcd" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "802a151032d64724ba664d0c1f5a5bcd" member_type: VOTER } }
I20260812 06:18:11.126700  3191 sys_catalog.cc:455] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "802a151032d64724ba664d0c1f5a5bcd" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "802a151032d64724ba664d0c1f5a5bcd" member_type: VOTER } }
I20260812 06:18:11.126863  3189 sys_catalog.cc:458] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:11.126863  3191 sys_catalog.cc:458] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:11.127312  3062 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:11.127321  3210 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:11.129447  3210 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:11.134163  3210 catalog_manager.cc:1383] Generated new cluster ID: 140b04bb29f74acfa0d7a65d012328cb
I20260812 06:18:11.134235  3210 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:11.153398  3210 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:11.154295  3210 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:11.159484  3210 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd: Generated new TSK 0
I20260812 06:18:11.160085  3210 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:11.192205  3062 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:11.195164  3218 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:11.195273  3219 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:18:11.195417  3062 server_base.cc:1061] running on GCE node
W20260812 06:18:11.195286  3221 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:18:11.195760  3062 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:11.195803  3062 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:18:11.195820  3062 hybrid_clock.cc:648] HybridClock initialized: now 1786515491195820 us; error 0 us; skew 500 ppm
I20260812 06:18:11.196970  3062 webserver.cc:533] Webserver started at http://127.2.253.129:38617/ using document root <none> and password file <none>
I20260812 06:18:11.197162  3062 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:11.197214  3062 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:11.197312  3062 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:11.197742  3062 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/instance:
uuid: "e3cf7f8822a94ce8a749755b17057a1b"
format_stamp: "Formatted at 2026-08-12 06:18:11 on dist-test-slave-s11t"
I20260812 06:18:11.199282  3062 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:11.200322  3236 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:18:11.200583  3062 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:11.200657  3062 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root
uuid: "e3cf7f8822a94ce8a749755b17057a1b"
format_stamp: "Formatted at 2026-08-12 06:18:11 on dist-test-slave-s11t"
I20260812 06:18:11.200775  3062 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-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:18:11.214116  3062 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:11.214619  3062 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:11.215173  3062 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:11.216437  3062 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:11.216495  3062 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:11.216571  3062 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:11.216614  3062 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:11.223807  3062 rpc_server.cc:307] RPC server started. Bound to: 127.2.253.129:43895
I20260812 06:18:11.223845  3346 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.253.129:43895 every 8 connection(s)
I20260812 06:18:11.234300  3347 heartbeater.cc:344] Connected to a master server at 127.2.253.190:40193
I20260812 06:18:11.234577  3347 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:11.235054  3347 heartbeater.cc:507] Master 127.2.253.190:40193 requested a full tablet report, sending...
I20260812 06:18:11.236562  3114 ts_manager.cc:194] Registered new tserver with Master: e3cf7f8822a94ce8a749755b17057a1b (127.2.253.129:43895)
I20260812 06:18:11.236824  3062 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012358682s
I20260812 06:18:11.237926  3114 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60070
I20260812 06:18:11.247282  3114 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60078:
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:18:11.263339  3287 tablet_service.cc:1511] Processing CreateTablet for tablet ef1d4d63739347459d00089063e9086b (DEFAULT_TABLE table=heavy-update-compaction-test [id=c027f7b0aa49423aa8d4c05cde92a73c]), partition=
I20260812 06:18:11.263809  3287 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ef1d4d63739347459d00089063e9086b. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:11.266562  3368 tablet_bootstrap.cc:492] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Bootstrap starting.
I20260812 06:18:11.267760  3368 tablet_bootstrap.cc:654] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:11.269608  3368 tablet_bootstrap.cc:492] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: No bootstrap required, opened a new log
I20260812 06:18:11.269732  3368 ts_tablet_manager.cc:1403] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:11.270330  3368 raft_consensus.cc:359] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e3cf7f8822a94ce8a749755b17057a1b" member_type: VOTER last_known_addr { host: "127.2.253.129" port: 43895 } }
I20260812 06:18:11.270519  3368 raft_consensus.cc:385] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:11.270581  3368 raft_consensus.cc:740] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e3cf7f8822a94ce8a749755b17057a1b, State: Initialized, Role: FOLLOWER
I20260812 06:18:11.270725  3368 consensus_queue.cc:260] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b [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: "e3cf7f8822a94ce8a749755b17057a1b" member_type: VOTER last_known_addr { host: "127.2.253.129" port: 43895 } }
I20260812 06:18:11.270838  3368 raft_consensus.cc:399] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:11.270943  3368 raft_consensus.cc:493] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:11.271061  3368 raft_consensus.cc:3060] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:11.272131  3368 raft_consensus.cc:515] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e3cf7f8822a94ce8a749755b17057a1b" member_type: VOTER last_known_addr { host: "127.2.253.129" port: 43895 } }
I20260812 06:18:11.272289  3368 leader_election.cc:304] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b [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: e3cf7f8822a94ce8a749755b17057a1b; no voters: 
I20260812 06:18:11.272521  3368 leader_election.cc:290] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:11.272675  3372 raft_consensus.cc:2804] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:11.272966  3372 raft_consensus.cc:697] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b [term 1 LEADER]: Becoming Leader. State: Replica: e3cf7f8822a94ce8a749755b17057a1b, State: Running, Role: LEADER
I20260812 06:18:11.272971  3368 ts_tablet_manager.cc:1434] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Time spent starting tablet: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:18:11.273358  3347 heartbeater.cc:499] Master 127.2.253.190:40193 was elected leader, sending a full tablet report...
I20260812 06:18:11.273459  3372 consensus_queue.cc:237] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b [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: "e3cf7f8822a94ce8a749755b17057a1b" member_type: VOTER last_known_addr { host: "127.2.253.129" port: 43895 } }
I20260812 06:18:11.276194  3114 catalog_manager.cc:5719] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b reported cstate change: term changed from 0 to 1, leader changed from <none> to e3cf7f8822a94ce8a749755b17057a1b (127.2.253.129). New cstate: current_term: 1 leader_uuid: "e3cf7f8822a94ce8a749755b17057a1b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e3cf7f8822a94ce8a749755b17057a1b" member_type: VOTER last_known_addr { host: "127.2.253.129" port: 43895 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:11.339841  3062 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.017s	sys 0.009s
I20260812 06:18:11.474990  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushMRSOp(ef1d4d63739347459d00089063e9086b): perf score=19.054940
I20260812 06:18:11.635861  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushMRSOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.160s	user 0.124s	sys 0.032s Metrics: {"bytes_written":9846041,"cfile_init":1,"compiler_manager_pool.queue_time_us":242,"delete_count":0,"dirs.queue_time_us":85,"dirs.run_cpu_time_us":212,"dirs.run_wall_time_us":808,"drs_written":1,"lbm_read_time_us":116,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38100,"lbm_writes_lt_1ms":697,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":26880,"thread_start_us":136,"threads_started":1,"update_count":1200}
I20260812 06:18:11.637300  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling LogGCOp(ef1d4d63739347459d00089063e9086b): free 20743880 bytes of WAL
I20260812 06:18:11.637707  3247 log_reader.cc:385] T ef1d4d63739347459d00089063e9086b: removed 2 log segments from log reader
I20260812 06:18:11.637778  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000001 (ops 1-6)
I20260812 06:18:11.637836  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000002 (ops 7-11)
I20260812 06:18:11.644014  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: LogGCOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:11.644491  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=1.196750
I20260812 06:18:11.666522  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.022s	user 0.007s	sys 0.000s Metrics: {"bytes_written":2461654,"delete_count":0,"lbm_write_time_us":2940,"lbm_writes_lt_1ms":63,"reinsert_count":0,"update_count":300}
I20260812 06:18:11.667063  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling UndoDeltaBlockGCOp(ef1d4d63739347459d00089063e9086b): 16411394 bytes on disk
I20260812 06:18:11.667676  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: UndoDeltaBlockGCOp(ef1d4d63739347459d00089063e9086b) 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:18:11.668087  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=2.188937
I20260812 06:18:11.683279  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5618,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.683878  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b): perf score=1.000000
I20260812 06:18:11.824374  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.140s	user 0.126s	sys 0.011s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20672353,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1783,"lbm_read_time_us":8477,"lbm_reads_lt_1ms":469,"lbm_write_time_us":25771,"lbm_writes_lt_1ms":443,"mutex_wait_us":332,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"thread_start_us":379,"threads_started":5,"update_count":2000}
I20260812 06:18:11.824971  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=10.126437
I20260812 06:18:11.869649  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.044s	user 0.033s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16888,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:11.870082  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=2.188937
I20260812 06:18:11.882895  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4578,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.883340  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b): perf score=1.000000
I20260812 06:18:12.017040  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.134s	user 0.105s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":722,"lbm_read_time_us":9220,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25943,"lbm_writes_lt_1ms":443,"mutex_wait_us":400,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20608,"update_count":2000}
I20260812 06:18:12.017810  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=10.126437
I20260812 06:18:12.058704  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.041s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17572,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:12.059342  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=2.188937
I20260812 06:18:12.074226  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5224,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.075066  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b): perf score=1.000000
I20260812 06:18:12.193466  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.118s	user 0.098s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":858,"lbm_read_time_us":8011,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22947,"lbm_writes_lt_1ms":443,"mutex_wait_us":92,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2000}
I20260812 06:18:12.194099  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=10.126437
I20260812 06:18:12.242326  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.048s	user 0.015s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15586,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:12.242952  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=2.188937
I20260812 06:18:12.258039  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5883,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.258661  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b): perf score=1.000000
I20260812 06:18:12.406661  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.148s	user 0.103s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":368,"lbm_read_time_us":11920,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24810,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":2000}
I20260812 06:18:12.407253  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=10.126437
I20260812 06:18:12.455247  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.048s	user 0.021s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13777,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:12.455771  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=2.188937
I20260812 06:18:12.466370  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4035,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.467041  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b): perf score=1.000000
I20260812 06:18:12.586066  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.119s	user 0.097s	sys 0.022s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":163,"lbm_read_time_us":10177,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21918,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2000}
I20260812 06:18:12.586809  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=10.126437
I20260812 06:18:12.633208  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.046s	user 0.022s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16004,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:12.633786  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=2.188937
I20260812 06:18:12.645406  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4367,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.645988  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b): perf score=1.000000
I20260812 06:18:12.770437  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.124s	user 0.100s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":356,"lbm_read_time_us":8231,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24879,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:18:12.771082  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=10.126437
I20260812 06:18:12.821705  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.050s	user 0.031s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16140,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:12.822239  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=2.188937
I20260812 06:18:12.833230  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4448,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.833652  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushMRSOp(ef1d4d63739347459d00089063e9086b): perf score=1.000000
I20260812 06:18:12.873124  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushMRSOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.039s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":43,"dirs.run_cpu_time_us":262,"dirs.run_wall_time_us":1232,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1396,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:12.874060  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling LogGCOp(ef1d4d63739347459d00089063e9086b): free 112239311 bytes of WAL
I20260812 06:18:12.874336  3247 log_reader.cc:385] T ef1d4d63739347459d00089063e9086b: removed 11 log segments from log reader
I20260812 06:18:12.874403  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000003 (ops 12-16)
I20260812 06:18:12.874457  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000004 (ops 17-21)
I20260812 06:18:12.874495  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000005 (ops 22-26)
I20260812 06:18:12.874531  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000006 (ops 27-31)
I20260812 06:18:12.874568  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000007 (ops 32-36)
I20260812 06:18:12.874607  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000008 (ops 37-40)
I20260812 06:18:12.874646  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000009 (ops 41-45)
I20260812 06:18:12.874686  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000010 (ops 46-50)
I20260812 06:18:12.874725  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000011 (ops 51-55)
I20260812 06:18:12.874764  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000012 (ops 56-60)
I20260812 06:18:12.874804  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000013 (ops 61-65)
I20260812 06:18:12.901247  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: LogGCOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:12.901698  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=2.188937
I20260812 06:18:12.923491  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.022s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4402,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.923904  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=2.188937
I20260812 06:18:12.933904  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3884,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.934297  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling UndoDeltaBlockGCOp(ef1d4d63739347459d00089063e9086b): 447 bytes on disk
I20260812 06:18:12.934705  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: UndoDeltaBlockGCOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:18:12.935134  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b): perf score=1.000000
I20260812 06:18:13.120193  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.185s	user 0.131s	sys 0.051s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877340,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":399,"lbm_read_time_us":12856,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30367,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":86,"threads_started":1,"update_count":3000}
I20260812 06:18:13.120765  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=14.095187
I20260812 06:18:13.193341  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.072s	user 0.044s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":28466,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.193887  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=2.188937
I20260812 06:18:13.204639  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3878,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.205271  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b): perf score=1.000000
I20260812 06:18:13.383121  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.178s	user 0.126s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":990,"lbm_read_time_us":11979,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30635,"lbm_writes_lt_1ms":543,"mutex_wait_us":278,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2500}
I20260812 06:18:13.383791  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=14.095187
I20260812 06:18:13.460585  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.076s	user 0.024s	sys 0.036s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25937,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.461203  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=2.188937
I20260812 06:18:13.478641  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.017s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7094,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.479336  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b): perf score=1.000000
I20260812 06:18:13.652644  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.173s	user 0.117s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1015,"lbm_read_time_us":12447,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27477,"lbm_writes_lt_1ms":543,"mutex_wait_us":344,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19840,"update_count":2500}
I20260812 06:18:13.653399  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=14.095187
I20260812 06:18:13.720942  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.067s	user 0.032s	sys 0.034s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":25559,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.721611  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=2.188937
I20260812 06:18:13.733953  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4988,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.734447  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b): perf score=1.000000
I20260812 06:18:13.924042  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.189s	user 0.118s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":661,"lbm_read_time_us":15277,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33187,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2500}
I20260812 06:18:13.924789  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=11.118625
I20260812 06:18:13.955811  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.031s	user 0.019s	sys 0.009s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13253,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:13.956813  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=2.188937
I20260812 06:18:13.971921  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.015s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5123,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:13.972457  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b): perf score=1.000000
I20260812 06:18:14.137410  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.165s	user 0.097s	sys 0.053s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":290,"lbm_read_time_us":9939,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24073,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17536,"update_count":2000}
I20260812 06:18:14.138096  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=14.095187
I20260812 06:18:14.192512  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.054s	user 0.020s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25105,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":399,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.193090  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=2.188937
I20260812 06:18:14.208472  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.015s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5562,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.209096  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b): perf score=1.000000
I20260812 06:18:14.364296  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.155s	user 0.120s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2629,"lbm_read_time_us":9146,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33119,"lbm_writes_lt_1ms":543,"mutex_wait_us":648,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:14.365131  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=10.126437
I20260812 06:18:14.400143  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.035s	user 0.006s	sys 0.025s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14514,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:14.400869  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=2.188937
I20260812 06:18:14.415719  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5501,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.416208  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushMRSOp(ef1d4d63739347459d00089063e9086b): perf score=1.000000
I20260812 06:18:14.442545  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushMRSOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.026s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":167,"dirs.run_wall_time_us":1418,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1714,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:14.443243  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling LogGCOp(ef1d4d63739347459d00089063e9086b): free 124257248 bytes of WAL
I20260812 06:18:14.443466  3247 log_reader.cc:385] T ef1d4d63739347459d00089063e9086b: removed 12 log segments from log reader
I20260812 06:18:14.443511  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000014 (ops 66-70)
I20260812 06:18:14.443543  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000015 (ops 71-75)
I20260812 06:18:14.443619  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000016 (ops 76-80)
I20260812 06:18:14.443652  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000017 (ops 81-85)
I20260812 06:18:14.443709  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000018 (ops 86-90)
I20260812 06:18:14.443749  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000019 (ops 91-94)
I20260812 06:18:14.443791  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000020 (ops 95-99)
I20260812 06:18:14.443830  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000021 (ops 100-104)
I20260812 06:18:14.443878  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000022 (ops 105-109)
I20260812 06:18:14.443917  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000023 (ops 110-114)
I20260812 06:18:14.443955  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000024 (ops 115-119)
I20260812 06:18:14.443993  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000025 (ops 120-124)
I20260812 06:18:14.472585  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: LogGCOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.029s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:14.473052  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=4.173312
I20260812 06:18:14.487465  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.014s	user 0.011s	sys 0.001s Metrics: {"bytes_written":5620561,"delete_count":0,"lbm_write_time_us":5937,"lbm_writes_lt_1ms":140,"reinsert_count":0,"update_count":685}
I20260812 06:18:14.487907  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling UndoDeltaBlockGCOp(ef1d4d63739347459d00089063e9086b): 472 bytes on disk
I20260812 06:18:14.488317  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: UndoDeltaBlockGCOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:18:14.488873  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=1.196750
I20260812 06:18:14.500080  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":2584729,"delete_count":0,"lbm_write_time_us":3587,"lbm_writes_lt_1ms":66,"reinsert_count":0,"update_count":315}
I20260812 06:18:14.500526  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b): perf score=1.000000
I20260812 06:18:14.679010  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.178s	user 0.134s	sys 0.042s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877304,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2544,"lbm_read_time_us":12492,"lbm_reads_lt_1ms":666,"lbm_write_time_us":36970,"lbm_writes_lt_1ms":643,"mutex_wait_us":1894,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":91,"threads_started":1,"update_count":3000}
I20260812 06:18:14.679711  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=14.095187
I20260812 06:18:14.731843  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.052s	user 0.032s	sys 0.017s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22857,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.732556  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=2.188937
I20260812 06:18:14.749850  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.017s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6221,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.750308  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b): perf score=1.000000
I20260812 06:18:14.904091  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.154s	user 0.092s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":437,"lbm_read_time_us":8919,"lbm_reads_lt_1ms":568,"lbm_write_time_us":28716,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":56320,"update_count":2500}
I20260812 06:18:14.904796  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=14.095187
I20260812 06:18:14.963311  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.058s	user 0.027s	sys 0.025s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":24181,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.963949  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b): perf score=1.000000
I20260812 06:18:15.130218  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.166s	user 0.102s	sys 0.052s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672160,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1059,"lbm_read_time_us":10678,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25266,"lbm_writes_lt_1ms":443,"mutex_wait_us":305,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:15.130859  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=14.095187
I20260812 06:18:15.179737  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.049s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20727,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:15.180249  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=2.188937
I20260812 06:18:15.196280  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6249,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.196887  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b): perf score=1.000000
I20260812 06:18:15.399410  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.202s	user 0.114s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":644,"lbm_read_time_us":12513,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32454,"lbm_writes_lt_1ms":543,"mutex_wait_us":304,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2500}
I20260812 06:18:15.400005  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=14.095187
I20260812 06:18:15.451969  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.052s	user 0.027s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20172,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:15.452486  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=2.188937
I20260812 06:18:15.465252  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4403,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.465878  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b): perf score=1.000000
I20260812 06:18:15.625062  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.159s	user 0.133s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":313,"lbm_read_time_us":11615,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32524,"lbm_writes_lt_1ms":543,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":2500}
I20260812 06:18:15.625797  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=11.118625
I20260812 06:18:15.663673  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.038s	user 0.026s	sys 0.009s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16665,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:15.664239  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=2.188937
I20260812 06:18:15.682683  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.018s	user 0.010s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6166,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:15.683164  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b): perf score=1.000000
I20260812 06:18:15.807713  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.124s	user 0.096s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":262,"lbm_read_time_us":7399,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25551,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2000}
I20260812 06:18:15.810602  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=11.118625
I20260812 06:18:15.845418  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.035s	user 0.018s	sys 0.015s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14514,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:15.846190  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=2.188937
I20260812 06:18:15.860343  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4651,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:15.860930  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushMRSOp(ef1d4d63739347459d00089063e9086b): perf score=1.000000
I20260812 06:18:15.892108  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushMRSOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.031s	user 0.024s	sys 0.004s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":179,"dirs.run_wall_time_us":1174,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2067,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:15.892967  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling LogGCOp(ef1d4d63739347459d00089063e9086b): free 117302816 bytes of WAL
I20260812 06:18:15.893327  3247 log_reader.cc:385] T ef1d4d63739347459d00089063e9086b: removed 12 log segments from log reader
I20260812 06:18:15.893437  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000026 (ops 125-129)
I20260812 06:18:15.893498  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000027 (ops 130-134)
I20260812 06:18:15.893537  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000028 (ops 135-139)
I20260812 06:18:15.893582  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000029 (ops 140-144)
I20260812 06:18:15.893635  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000030 (ops 145-148)
I20260812 06:18:15.893656  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000031 (ops 149-153)
I20260812 06:18:15.893678  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000032 (ops 154-158)
I20260812 06:18:15.893699  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000033 (ops 159-163)
I20260812 06:18:15.893726  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000034 (ops 164-168)
I20260812 06:18:15.893764  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000035 (ops 169-172)
I20260812 06:18:15.893846  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000036 (ops 173-177)
I20260812 06:18:15.893886  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000037 (ops 178-182)
I20260812 06:18:15.921537  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: LogGCOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:15.922014  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling UndoDeltaBlockGCOp(ef1d4d63739347459d00089063e9086b): 472 bytes on disk
I20260812 06:18:15.922684  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: UndoDeltaBlockGCOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4}
I20260812 06:18:15.923381  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=5.165500
I20260812 06:18:15.942540  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.019s	user 0.017s	sys 0.000s Metrics: {"bytes_written":6646162,"delete_count":0,"lbm_write_time_us":8270,"lbm_writes_lt_1ms":165,"reinsert_count":0,"update_count":810}
I20260812 06:18:15.943024  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling LogGCOp(ef1d4d63739347459d00089063e9086b): free 12017949 bytes of WAL
I20260812 06:18:15.943311  3247 log_reader.cc:385] T ef1d4d63739347459d00089063e9086b: removed 1 log segments from log reader
I20260812 06:18:15.943459  3247 log.cc:1079] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/ef1d4d63739347459d00089063e9086b/wal-000000038 (ops 183-187)
I20260812 06:18:15.946506  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: LogGCOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:15.946914  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=1.000000
I20260812 06:18:15.957508  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.010s	user 0.004s	sys 0.002s Metrics: {"bytes_written":1559102,"delete_count":0,"lbm_write_time_us":1514,"lbm_writes_lt_1ms":41,"reinsert_count":0,"update_count":190}
I20260812 06:18:15.958050  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b): perf score=1.000000
I20260812 06:18:16.127490  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.169s	user 0.127s	sys 0.042s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":582,"lbm_read_time_us":11200,"lbm_reads_lt_1ms":666,"lbm_write_time_us":35328,"lbm_writes_lt_1ms":643,"mutex_wait_us":86,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8448,"thread_start_us":82,"threads_started":1,"update_count":3000}
I20260812 06:18:16.128275  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=14.095187
I20260812 06:18:16.177717  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.049s	user 0.017s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22033,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:16.178318  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b): perf score=2.188937
I20260812 06:18:16.194876  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: FlushDeltaMemStoresOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6565,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.195313  3349 maintenance_manager.cc:419] P e3cf7f8822a94ce8a749755b17057a1b: Scheduling MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b): perf score=1.000000
I20260812 06:18:16.271562  3062 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.932s	user 1.827s	sys 0.149s
I20260812 06:18:16.331440  3062 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.059s	user 0.002s	sys 0.000s
I20260812 06:18:16.332090  3062 tablet_server.cc:179] TabletServer@127.2.253.129:0 shutting down...
I20260812 06:18:16.347632  3247 maintenance_manager.cc:643] P e3cf7f8822a94ce8a749755b17057a1b: MajorDeltaCompactionOp(ef1d4d63739347459d00089063e9086b) complete. Timing: real 0.152s	user 0.116s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":203,"lbm_read_time_us":11191,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30502,"lbm_writes_lt_1ms":543,"mutex_wait_us":64,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:18:16.348611  3062 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:16.349067  3062 tablet_replica.cc:333] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b: stopping tablet replica
I20260812 06:18:16.349321  3062 raft_consensus.cc:2243] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:16.349567  3062 raft_consensus.cc:2272] T ef1d4d63739347459d00089063e9086b P e3cf7f8822a94ce8a749755b17057a1b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:16.367342  3062 tablet_server.cc:196] TabletServer@127.2.253.129:0 shutdown complete.
I20260812 06:18:16.394286  3062 master.cc:562] Master@127.2.253.190:40193 shutting down...
I20260812 06:18:16.397853  3062 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:16.398047  3062 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:16.398128  3062 tablet_replica.cc:333] T 00000000000000000000000000000000 P 802a151032d64724ba664d0c1f5a5bcd: stopping tablet replica
I20260812 06:18:16.410595  3062 master.cc:584] Master@127.2.253.190:40193 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5453 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:16.501910  3062 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.2.253.190:33037
I20260812 06:18:16.502343  3062 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:16.504427  3405 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:16.504472  3408 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:18:16.504544  3410 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:18:16.504673  3062 server_base.cc:1061] running on GCE node
I20260812 06:18:16.504875  3062 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:16.504909  3062 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:18:16.504925  3062 hybrid_clock.cc:648] HybridClock initialized: now 1786515496504924 us; error 0 us; skew 500 ppm
I20260812 06:18:16.505743  3062 webserver.cc:533] Webserver started at http://127.2.253.190:38095/ using document root <none> and password file <none>
I20260812 06:18:16.505908  3062 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:16.505955  3062 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:16.506008  3062 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:16.506343  3062 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/master-0-root/instance:
uuid: "13285ae088084ca8ab5499102002fba6"
format_stamp: "Formatted at 2026-08-12 06:18:16 on dist-test-slave-s11t"
I20260812 06:18:16.507776  3062 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:16.508663  3417 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:18:16.508952  3062 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:16.509018  3062 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/master-0-root
uuid: "13285ae088084ca8ab5499102002fba6"
format_stamp: "Formatted at 2026-08-12 06:18:16 on dist-test-slave-s11t"
I20260812 06:18:16.509120  3062 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-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:18:16.533838  3062 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:16.534281  3062 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:16.538870  3062 rpc_server.cc:307] RPC server started. Bound to: 127.2.253.190:33037
I20260812 06:18:16.544299  3492 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.253.190:33037 every 8 connection(s)
I20260812 06:18:16.550918  3493 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:18:16.552757  3493 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6: Bootstrap starting.
I20260812 06:18:16.553472  3493 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:16.554458  3493 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6: No bootstrap required, opened a new log
I20260812 06:18:16.554800  3493 raft_consensus.cc:359] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "13285ae088084ca8ab5499102002fba6" member_type: VOTER }
I20260812 06:18:16.554922  3493 raft_consensus.cc:385] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:16.554947  3493 raft_consensus.cc:740] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 13285ae088084ca8ab5499102002fba6, State: Initialized, Role: FOLLOWER
I20260812 06:18:16.555097  3493 consensus_queue.cc:260] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6 [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: "13285ae088084ca8ab5499102002fba6" member_type: VOTER }
I20260812 06:18:16.555189  3493 raft_consensus.cc:399] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:16.555215  3493 raft_consensus.cc:493] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:16.555251  3493 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:16.555893  3493 raft_consensus.cc:515] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "13285ae088084ca8ab5499102002fba6" member_type: VOTER }
I20260812 06:18:16.556005  3493 leader_election.cc:304] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6 [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: 13285ae088084ca8ab5499102002fba6; no voters: 
I20260812 06:18:16.556154  3493 leader_election.cc:290] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:16.556300  3502 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:16.556496  3502 raft_consensus.cc:697] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6 [term 1 LEADER]: Becoming Leader. State: Replica: 13285ae088084ca8ab5499102002fba6, State: Running, Role: LEADER
I20260812 06:18:16.556636  3493 sys_catalog.cc:565] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:16.556646  3502 consensus_queue.cc:237] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6 [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: "13285ae088084ca8ab5499102002fba6" member_type: VOTER }
I20260812 06:18:16.557180  3503 sys_catalog.cc:455] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "13285ae088084ca8ab5499102002fba6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "13285ae088084ca8ab5499102002fba6" member_type: VOTER } }
I20260812 06:18:16.557358  3503 sys_catalog.cc:458] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:16.557214  3504 sys_catalog.cc:455] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 13285ae088084ca8ab5499102002fba6. Latest consensus state: current_term: 1 leader_uuid: "13285ae088084ca8ab5499102002fba6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "13285ae088084ca8ab5499102002fba6" member_type: VOTER } }
I20260812 06:18:16.557585  3504 sys_catalog.cc:458] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:16.557904  3509 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:16.558887  3509 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:16.559103  3062 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:16.560781  3509 catalog_manager.cc:1383] Generated new cluster ID: cbfe9d0c4c5d4122922d49b9409f3202
I20260812 06:18:16.560847  3509 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:16.576345  3509 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:16.576962  3509 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:16.581694  3509 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6: Generated new TSK 0
I20260812 06:18:16.581923  3509 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:16.591611  3062 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:16.594023  3535 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:16.593973  3538 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:18:16.593988  3536 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:18:16.594218  3062 server_base.cc:1061] running on GCE node
I20260812 06:18:16.594468  3062 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:16.594503  3062 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:18:16.594519  3062 hybrid_clock.cc:648] HybridClock initialized: now 1786515496594519 us; error 0 us; skew 500 ppm
I20260812 06:18:16.595481  3062 webserver.cc:533] Webserver started at http://127.2.253.129:45119/ using document root <none> and password file <none>
I20260812 06:18:16.595672  3062 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:16.595734  3062 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:16.595814  3062 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:16.596262  3062 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/instance:
uuid: "23a2174db0de418f9975d73955b56820"
format_stamp: "Formatted at 2026-08-12 06:18:16 on dist-test-slave-s11t"
I20260812 06:18:16.598002  3062 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:16.599220  3546 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:18:16.599599  3062 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:16.599702  3062 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root
uuid: "23a2174db0de418f9975d73955b56820"
format_stamp: "Formatted at 2026-08-12 06:18:16 on dist-test-slave-s11t"
I20260812 06:18:16.599802  3062 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-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:18:16.618129  3062 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:16.618603  3062 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:16.618975  3062 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:16.619498  3062 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:16.619560  3062 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:16.619613  3062 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:16.619663  3062 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:16.624293  3062 rpc_server.cc:307] RPC server started. Bound to: 127.2.253.129:34275
I20260812 06:18:16.624886  3648 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.253.129:34275 every 8 connection(s)
I20260812 06:18:16.630059  3649 heartbeater.cc:344] Connected to a master server at 127.2.253.190:33037
I20260812 06:18:16.630165  3649 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:16.630359  3649 heartbeater.cc:507] Master 127.2.253.190:33037 requested a full tablet report, sending...
I20260812 06:18:16.631074  3445 ts_manager.cc:194] Registered new tserver with Master: 23a2174db0de418f9975d73955b56820 (127.2.253.129:34275)
I20260812 06:18:16.631827  3062 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.006805501s
I20260812 06:18:16.631987  3445 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:34022
I20260812 06:18:16.639731  3445 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:34028:
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:18:16.648231  3589 tablet_service.cc:1511] Processing CreateTablet for tablet 345929c1eac947e68ecc2cae4335ccaa (DEFAULT_TABLE table=heavy-update-compaction-test [id=1413c8a4bc2c411f901efb4f8729a795]), partition=
I20260812 06:18:16.648504  3589 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 345929c1eac947e68ecc2cae4335ccaa. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:16.650687  3668 tablet_bootstrap.cc:492] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Bootstrap starting.
I20260812 06:18:16.651423  3668 tablet_bootstrap.cc:654] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:16.652490  3668 tablet_bootstrap.cc:492] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: No bootstrap required, opened a new log
I20260812 06:18:16.652590  3668 ts_tablet_manager.cc:1403] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:16.653044  3668 raft_consensus.cc:359] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "23a2174db0de418f9975d73955b56820" member_type: VOTER last_known_addr { host: "127.2.253.129" port: 34275 } }
I20260812 06:18:16.653138  3668 raft_consensus.cc:385] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:16.653184  3668 raft_consensus.cc:740] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 23a2174db0de418f9975d73955b56820, State: Initialized, Role: FOLLOWER
I20260812 06:18:16.653366  3668 consensus_queue.cc:260] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820 [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: "23a2174db0de418f9975d73955b56820" member_type: VOTER last_known_addr { host: "127.2.253.129" port: 34275 } }
I20260812 06:18:16.653481  3668 raft_consensus.cc:399] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:16.653535  3668 raft_consensus.cc:493] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:16.653594  3668 raft_consensus.cc:3060] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:16.654439  3668 raft_consensus.cc:515] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "23a2174db0de418f9975d73955b56820" member_type: VOTER last_known_addr { host: "127.2.253.129" port: 34275 } }
I20260812 06:18:16.654592  3668 leader_election.cc:304] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820 [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: 23a2174db0de418f9975d73955b56820; no voters: 
I20260812 06:18:16.654824  3668 leader_election.cc:290] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:16.654989  3672 raft_consensus.cc:2804] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:16.655157  3649 heartbeater.cc:499] Master 127.2.253.190:33037 was elected leader, sending a full tablet report...
I20260812 06:18:16.655205  3672 raft_consensus.cc:697] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820 [term 1 LEADER]: Becoming Leader. State: Replica: 23a2174db0de418f9975d73955b56820, State: Running, Role: LEADER
I20260812 06:18:16.655364  3672 consensus_queue.cc:237] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820 [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: "23a2174db0de418f9975d73955b56820" member_type: VOTER last_known_addr { host: "127.2.253.129" port: 34275 } }
I20260812 06:18:16.655434  3668 ts_tablet_manager.cc:1434] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:16.656822  3445 catalog_manager.cc:5719] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820 reported cstate change: term changed from 0 to 1, leader changed from <none> to 23a2174db0de418f9975d73955b56820 (127.2.253.129). New cstate: current_term: 1 leader_uuid: "23a2174db0de418f9975d73955b56820" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "23a2174db0de418f9975d73955b56820" member_type: VOTER last_known_addr { host: "127.2.253.129" port: 34275 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:16.717799  3062 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.015s	sys 0.008s
I20260812 06:18:16.875556  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushMRSOp(345929c1eac947e68ecc2cae4335ccaa): perf score=19.054940
I20260812 06:18:17.039564  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushMRSOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.164s	user 0.129s	sys 0.032s Metrics: {"bytes_written":13374124,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":178,"dirs.run_wall_time_us":775,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44043,"lbm_writes_lt_1ms":783,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":15872,"update_count":1630}
I20260812 06:18:17.040159  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling LogGCOp(345929c1eac947e68ecc2cae4335ccaa): free 20743880 bytes of WAL
I20260812 06:18:17.040400  3553 log_reader.cc:385] T 345929c1eac947e68ecc2cae4335ccaa: removed 2 log segments from log reader
I20260812 06:18:17.040447  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000001 (ops 1-6)
I20260812 06:18:17.040498  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000002 (ops 7-11)
I20260812 06:18:17.045463  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: LogGCOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:18:17.045859  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=2.188937
I20260812 06:18:17.064220  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.018s	user 0.010s	sys 0.002s Metrics: {"bytes_written":3446259,"delete_count":0,"lbm_write_time_us":5364,"lbm_writes_lt_1ms":87,"reinsert_count":0,"update_count":420}
I20260812 06:18:17.064633  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling UndoDeltaBlockGCOp(345929c1eac947e68ecc2cae4335ccaa): 16411394 bytes on disk
I20260812 06:18:17.065116  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: UndoDeltaBlockGCOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:18:17.065546  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=2.188937
I20260812 06:18:17.079164  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5234,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:17.079741  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa): perf score=1.000000
I20260812 06:18:17.257047  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.177s	user 0.141s	sys 0.024s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774788,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1004,"lbm_read_time_us":12610,"lbm_reads_lt_1ms":569,"lbm_write_time_us":31133,"lbm_writes_lt_1ms":543,"mutex_wait_us":65,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"thread_start_us":390,"threads_started":5,"update_count":2500}
I20260812 06:18:17.257652  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=14.095187
I20260812 06:18:17.315860  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.058s	user 0.030s	sys 0.025s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":26698,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.316457  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=2.188937
I20260812 06:18:17.330176  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4772,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.330615  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa): perf score=1.000000
I20260812 06:18:17.489490  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.159s	user 0.106s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":195,"lbm_read_time_us":9681,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30275,"lbm_writes_lt_1ms":543,"mutex_wait_us":36,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14976,"update_count":2500}
I20260812 06:18:17.490042  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=14.095187
I20260812 06:18:17.547775  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.058s	user 0.029s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19419,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:17.548230  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=2.188937
I20260812 06:18:17.558736  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3970,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.559260  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa): perf score=1.000000
I20260812 06:18:17.742058  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.183s	user 0.100s	sys 0.080s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":342,"lbm_read_time_us":12526,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31307,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:18:17.742897  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=14.095187
I20260812 06:18:17.795049  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.052s	user 0.032s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22520,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.795668  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa): perf score=1.000000
I20260812 06:18:17.952844  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.157s	user 0.107s	sys 0.044s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1745,"lbm_read_time_us":10767,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23237,"lbm_writes_lt_1ms":443,"mutex_wait_us":281,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.953562  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=14.095187
I20260812 06:18:18.007697  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.054s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23946,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.008270  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=2.188937
I20260812 06:18:18.021332  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.013s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5024,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.021798  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa): perf score=1.000000
I20260812 06:18:18.207278  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.185s	user 0.125s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":190,"lbm_read_time_us":12764,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27670,"lbm_writes_lt_1ms":543,"mutex_wait_us":85,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":2500}
I20260812 06:18:18.208096  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=14.095187
I20260812 06:18:18.255564  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.047s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20836,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.256143  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=2.188937
I20260812 06:18:18.273581  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.017s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6762,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.274099  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushMRSOp(345929c1eac947e68ecc2cae4335ccaa): perf score=1.000000
I20260812 06:18:18.304154  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushMRSOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":1191,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1836,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:18.304900  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling LogGCOp(345929c1eac947e68ecc2cae4335ccaa): free 112239255 bytes of WAL
I20260812 06:18:18.305151  3553 log_reader.cc:385] T 345929c1eac947e68ecc2cae4335ccaa: removed 11 log segments from log reader
I20260812 06:18:18.305215  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000003 (ops 12-16)
I20260812 06:18:18.305256  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000004 (ops 17-21)
I20260812 06:18:18.305287  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000005 (ops 22-26)
I20260812 06:18:18.305317  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000006 (ops 27-31)
I20260812 06:18:18.305342  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000007 (ops 32-36)
I20260812 06:18:18.305368  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000008 (ops 37-40)
I20260812 06:18:18.305401  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000009 (ops 41-45)
I20260812 06:18:18.305425  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000010 (ops 46-50)
I20260812 06:18:18.305447  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000011 (ops 51-55)
I20260812 06:18:18.305476  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000012 (ops 56-60)
I20260812 06:18:18.305505  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000013 (ops 61-65)
I20260812 06:18:18.334636  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: LogGCOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.030s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:18:18.338955  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=2.188937
I20260812 06:18:18.357141  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.018s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4403,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":500}
I20260812 06:18:18.357654  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling LogGCOp(345929c1eac947e68ecc2cae4335ccaa): free 12017983 bytes of WAL
I20260812 06:18:18.357856  3553 log_reader.cc:385] T 345929c1eac947e68ecc2cae4335ccaa: removed 1 log segments from log reader
I20260812 06:18:18.357944  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000014 (ops 66-70)
I20260812 06:18:18.360463  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: LogGCOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:18.360821  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling UndoDeltaBlockGCOp(345929c1eac947e68ecc2cae4335ccaa): 462 bytes on disk
I20260812 06:18:18.361346  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: UndoDeltaBlockGCOp(345929c1eac947e68ecc2cae4335ccaa) 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:18:18.361948  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=2.188937
I20260812 06:18:18.382225  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.020s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6832,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.382881  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa): perf score=1.000000
I20260812 06:18:18.647222  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.262s	user 0.163s	sys 0.093s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979747,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":186,"lbm_read_time_us":20086,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41113,"lbm_writes_lt_1ms":743,"mutex_wait_us":44,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":9984,"thread_start_us":105,"threads_started":1,"update_count":3500}
I20260812 06:18:18.647958  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=18.063937
I20260812 06:18:18.725131  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.077s	user 0.051s	sys 0.008s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":27114,"lbm_writes_lt_1ms":503,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:18:18.725597  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=2.188937
I20260812 06:18:18.736654  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4284,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.737355  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa): perf score=1.000000
I20260812 06:18:18.935477  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.198s	user 0.132s	sys 0.066s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":617,"lbm_read_time_us":14460,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31124,"lbm_writes_lt_1ms":643,"mutex_wait_us":358,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":3000}
I20260812 06:18:18.936184  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=14.095187
I20260812 06:18:18.996285  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.060s	user 0.040s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24882,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.996878  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=2.188937
I20260812 06:18:19.008443  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4466,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.008936  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa): perf score=1.000000
I20260812 06:18:19.196664  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.188s	user 0.107s	sys 0.074s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":934,"lbm_read_time_us":13426,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32084,"lbm_writes_lt_1ms":543,"mutex_wait_us":277,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:18:19.197407  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=14.095187
I20260812 06:18:19.261996  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.064s	user 0.035s	sys 0.018s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22830,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:19.262681  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=2.188937
I20260812 06:18:19.274627  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4420,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.275293  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa): perf score=1.000000
I20260812 06:18:19.446755  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.171s	user 0.095s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":197,"lbm_read_time_us":11790,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29701,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2500}
I20260812 06:18:19.447439  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=14.095187
I20260812 06:18:19.504839  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.057s	user 0.038s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20446,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:19.505430  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=2.188937
I20260812 06:18:19.516738  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.011s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4360,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.517184  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa): perf score=1.000000
I20260812 06:18:19.704325  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.187s	user 0.097s	sys 0.084s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1025,"lbm_read_time_us":13588,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30056,"lbm_writes_lt_1ms":543,"mutex_wait_us":70,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:18:19.704916  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=11.118625
I20260812 06:18:19.751106  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.046s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":19860,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:18:19.751683  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=2.188937
I20260812 06:18:19.774132  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.022s	user 0.009s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4079,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.774608  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=2.188937
I20260812 06:18:19.784440  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3718,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:19.784912  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushMRSOp(345929c1eac947e68ecc2cae4335ccaa): perf score=1.000000
I20260812 06:18:19.833037  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushMRSOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.048s	user 0.036s	sys 0.001s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":257,"dirs.run_wall_time_us":1377,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1383,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:19.833837  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling LogGCOp(345929c1eac947e68ecc2cae4335ccaa): free 108535399 bytes of WAL
I20260812 06:18:19.834097  3553 log_reader.cc:385] T 345929c1eac947e68ecc2cae4335ccaa: removed 11 log segments from log reader
I20260812 06:18:19.834167  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000015 (ops 71-75)
I20260812 06:18:19.834224  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000016 (ops 76-80)
I20260812 06:18:19.834282  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000017 (ops 81-85)
I20260812 06:18:19.834326  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000018 (ops 86-90)
I20260812 06:18:19.834368  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000019 (ops 91-94)
I20260812 06:18:19.834407  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000020 (ops 95-99)
I20260812 06:18:19.834446  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000021 (ops 100-104)
I20260812 06:18:19.834486  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000022 (ops 105-108)
I20260812 06:18:19.834527  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000023 (ops 109-113)
I20260812 06:18:19.834565  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000024 (ops 114-118)
I20260812 06:18:19.834604  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000025 (ops 119-123)
I20260812 06:18:19.859366  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: LogGCOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.025s	user 0.009s	sys 0.016s Metrics: {}
I20260812 06:18:19.859858  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling UndoDeltaBlockGCOp(345929c1eac947e68ecc2cae4335ccaa): 447 bytes on disk
I20260812 06:18:19.860541  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: UndoDeltaBlockGCOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":99,"lbm_reads_lt_1ms":4}
I20260812 06:18:19.861207  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=2.188937
I20260812 06:18:19.883908  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.022s	user 0.006s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5594,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.884537  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=2.188937
I20260812 06:18:19.895747  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.011s	user 0.004s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4392,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.896196  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa): perf score=1.000000
I20260812 06:18:20.153739  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.257s	user 0.196s	sys 0.060s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979861,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":280,"lbm_read_time_us":18059,"lbm_reads_lt_1ms":775,"lbm_write_time_us":43874,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":24832,"thread_start_us":87,"threads_started":1,"update_count":3500}
I20260812 06:18:20.154611  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=18.063937
I20260812 06:18:20.233701  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.079s	user 0.052s	sys 0.016s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":31295,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:20.234256  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=2.188937
I20260812 06:18:20.246932  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4274,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.247505  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa): perf score=1.000000
I20260812 06:18:20.452316  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.205s	user 0.131s	sys 0.070s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":242,"lbm_read_time_us":16513,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32651,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":3000}
I20260812 06:18:20.453336  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=14.095187
I20260812 06:18:20.510357  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.057s	user 0.046s	sys 0.009s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25080,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:20.510946  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=2.188937
I20260812 06:18:20.522568  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4561,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.523422  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa): perf score=1.000000
I20260812 06:18:20.697062  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.173s	user 0.108s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":200,"lbm_read_time_us":12652,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27694,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2500}
I20260812 06:18:20.697728  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=14.095187
I20260812 06:18:20.756340  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.058s	user 0.045s	sys 0.008s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23403,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:20.756920  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=2.188937
I20260812 06:18:20.767838  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4379,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.768584  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa): perf score=1.000000
I20260812 06:18:20.940292  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.171s	user 0.114s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":183,"lbm_read_time_us":13285,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28558,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22784,"update_count":2500}
I20260812 06:18:20.941200  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=14.095187
I20260812 06:18:21.001334  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.060s	user 0.040s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22051,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:21.002192  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=2.188937
I20260812 06:18:21.018458  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.016s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5200,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.019026  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa): perf score=1.000000
I20260812 06:18:21.194037  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.175s	user 0.117s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":751,"lbm_read_time_us":11129,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29857,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":2500}
I20260812 06:18:21.194535  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=14.095187
I20260812 06:18:21.256214  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.062s	user 0.022s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22500,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:21.256922  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=2.188937
I20260812 06:18:21.268361  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4566,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.268946  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushMRSOp(345929c1eac947e68ecc2cae4335ccaa): perf score=1.000000
I20260812 06:18:21.303133  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushMRSOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.034s	user 0.026s	sys 0.005s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":229,"dirs.run_wall_time_us":1341,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1512,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:21.303817  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling UndoDeltaBlockGCOp(345929c1eac947e68ecc2cae4335ccaa): 447 bytes on disk
I20260812 06:18:21.304349  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: UndoDeltaBlockGCOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:18:21.304929  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa): perf score=1.000000
I20260812 06:18:21.481516  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.176s	user 0.116s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":259,"lbm_read_time_us":11332,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28866,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2500}
I20260812 06:18:21.482092  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling LogGCOp(345929c1eac947e68ecc2cae4335ccaa): free 120553613 bytes of WAL
I20260812 06:18:21.482401  3553 log_reader.cc:385] T 345929c1eac947e68ecc2cae4335ccaa: removed 12 log segments from log reader
I20260812 06:18:21.482487  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000026 (ops 124-128)
I20260812 06:18:21.482555  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000027 (ops 129-133)
I20260812 06:18:21.482613  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000028 (ops 134-138)
I20260812 06:18:21.482697  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000029 (ops 139-142)
I20260812 06:18:21.482749  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000030 (ops 143-147)
I20260812 06:18:21.482806  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000031 (ops 148-152)
I20260812 06:18:21.482853  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000032 (ops 153-157)
I20260812 06:18:21.482928  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000033 (ops 158-162)
I20260812 06:18:21.482975  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000034 (ops 163-167)
I20260812 06:18:21.483021  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000035 (ops 168-172)
I20260812 06:18:21.483065  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000036 (ops 173-176)
I20260812 06:18:21.483112  3553 log.cc:1079] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: Deleting log segment in path: /tmp/dist-test-taskfBOAmj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491038190-3062-0/minicluster-data/ts-0-root/wals/345929c1eac947e68ecc2cae4335ccaa/wal-000000037 (ops 177-181)
I20260812 06:18:21.513734  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: LogGCOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:18:21.514250  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=16.079562
I20260812 06:18:21.582844  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.068s	user 0.040s	sys 0.015s Metrics: {"bytes_written":17599604,"delete_count":0,"lbm_write_time_us":21288,"lbm_writes_lt_1ms":432,"reinsert_count":0,"update_count":2145}
I20260812 06:18:21.583576  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=5.165500
I20260812 06:18:21.602535  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.019s	user 0.008s	sys 0.009s Metrics: {"bytes_written":7015384,"delete_count":0,"lbm_write_time_us":7944,"lbm_writes_lt_1ms":174,"reinsert_count":0,"update_count":855}
I20260812 06:18:21.603363  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa): perf score=1.000000
I20260812 06:18:21.820024  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: MajorDeltaCompactionOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.216s	user 0.142s	sys 0.072s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877110,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":330,"lbm_read_time_us":15592,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37499,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16000,"update_count":3000}
I20260812 06:18:21.820643  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=14.095187
I20260812 06:18:21.845561  3062 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.128s	user 1.856s	sys 0.248s
I20260812 06:18:21.877658  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.057s	user 0.023s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22350,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:18:21.878441  3651 maintenance_manager.cc:419] P 23a2174db0de418f9975d73955b56820: Scheduling FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa): perf score=2.188937
I20260812 06:18:21.884238  3062 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.038s	user 0.000s	sys 0.000s
I20260812 06:18:21.884778  3062 tablet_server.cc:179] TabletServer@127.2.253.129:0 shutting down...
I20260812 06:18:21.893388  3553 maintenance_manager.cc:643] P 23a2174db0de418f9975d73955b56820: FlushDeltaMemStoresOp(345929c1eac947e68ecc2cae4335ccaa) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5847,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.893985  3062 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:21.894218  3062 tablet_replica.cc:333] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820: stopping tablet replica
I20260812 06:18:21.894364  3062 raft_consensus.cc:2243] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:21.894507  3062 raft_consensus.cc:2272] T 345929c1eac947e68ecc2cae4335ccaa P 23a2174db0de418f9975d73955b56820 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:21.908242  3062 tablet_server.cc:196] TabletServer@127.2.253.129:0 shutdown complete.
I20260812 06:18:21.911756  3062 master.cc:562] Master@127.2.253.190:33037 shutting down...
I20260812 06:18:21.915541  3062 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:21.915736  3062 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:21.915848  3062 tablet_replica.cc:333] T 00000000000000000000000000000000 P 13285ae088084ca8ab5499102002fba6: stopping tablet replica
I20260812 06:18:21.928575  3062 master.cc:584] Master@127.2.253.190:33037 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5521 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10975 ms total)

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