[==========] 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:16:37.336804  2976 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.2.232.62:35635
I20260812 06:16:37.337859  2976 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:16:37.338501  2976 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:37.345024  2983 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:16:37.345049  2984 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:16:37.345235  2976 server_base.cc:1061] running on GCE node
W20260812 06:16:37.345458  2987 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:16:37.345968  2976 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:37.346099  2976 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:16:37.346144  2976 hybrid_clock.cc:648] HybridClock initialized: now 1786515397346141 us; error 0 us; skew 500 ppm
I20260812 06:16:37.348067  2976 webserver.cc:533] Webserver started at http://127.2.232.62:36547/ using document root <none> and password file <none>
I20260812 06:16:37.348701  2976 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:37.348791  2976 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:37.349045  2976 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:37.350749  2976 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/master-0-root/instance:
uuid: "e609300994684529b9f8a1124e062183"
format_stamp: "Formatted at 2026-08-12 06:16:37 on dist-test-slave-8n49"
I20260812 06:16:37.354444  2976 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:16:37.357095  2993 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:16:37.358153  2976 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.002s	sys 0.001s
I20260812 06:16:37.358287  2976 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/master-0-root
uuid: "e609300994684529b9f8a1124e062183"
format_stamp: "Formatted at 2026-08-12 06:16:37 on dist-test-slave-8n49"
I20260812 06:16:37.358404  2976 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-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:16:37.372318  2976 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:37.373299  2976 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:16:37.373489  2976 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:37.382843  2976 rpc_server.cc:307] RPC server started. Bound to: 127.2.232.62:35635
I20260812 06:16:37.382860  3058 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.232.62:35635 every 8 connection(s)
I20260812 06:16:37.385242  3059 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:16:37.390702  3059 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183: Bootstrap starting.
I20260812 06:16:37.393170  3059 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:37.394172  3059 log.cc:826] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:37.396034  3059 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183: No bootstrap required, opened a new log
I20260812 06:16:37.398979  3059 raft_consensus.cc:359] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e609300994684529b9f8a1124e062183" member_type: VOTER }
I20260812 06:16:37.399155  3059 raft_consensus.cc:385] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:37.399266  3059 raft_consensus.cc:740] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e609300994684529b9f8a1124e062183, State: Initialized, Role: FOLLOWER
I20260812 06:16:37.399911  3059 consensus_queue.cc:260] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183 [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: "e609300994684529b9f8a1124e062183" member_type: VOTER }
I20260812 06:16:37.400076  3059 raft_consensus.cc:399] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:37.400179  3059 raft_consensus.cc:493] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:37.400355  3059 raft_consensus.cc:3060] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:37.401244  3059 raft_consensus.cc:515] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e609300994684529b9f8a1124e062183" member_type: VOTER }
I20260812 06:16:37.401746  3059 leader_election.cc:304] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183 [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: e609300994684529b9f8a1124e062183; no voters: 
I20260812 06:16:37.402087  3059 leader_election.cc:290] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:37.402323  3063 raft_consensus.cc:2804] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:37.402607  3063 raft_consensus.cc:697] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183 [term 1 LEADER]: Becoming Leader. State: Replica: e609300994684529b9f8a1124e062183, State: Running, Role: LEADER
I20260812 06:16:37.403017  3063 consensus_queue.cc:237] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183 [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: "e609300994684529b9f8a1124e062183" member_type: VOTER }
I20260812 06:16:37.403231  3059 sys_catalog.cc:565] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:37.405282  3064 sys_catalog.cc:455] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "e609300994684529b9f8a1124e062183" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e609300994684529b9f8a1124e062183" member_type: VOTER } }
I20260812 06:16:37.405422  3064 sys_catalog.cc:458] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:37.405311  3065 sys_catalog.cc:455] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183 [sys.catalog]: SysCatalogTable state changed. Reason: New leader e609300994684529b9f8a1124e062183. Latest consensus state: current_term: 1 leader_uuid: "e609300994684529b9f8a1124e062183" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e609300994684529b9f8a1124e062183" member_type: VOTER } }
I20260812 06:16:37.405653  2976 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:37.405668  3065 sys_catalog.cc:458] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:37.405874  3077 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:37.408041  3077 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:37.412847  3077 catalog_manager.cc:1383] Generated new cluster ID: b3ea431a1b44483c94514d6da928ea51
I20260812 06:16:37.412921  3077 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:37.446810  3077 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:37.447773  3077 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:37.459167  3077 catalog_manager.cc:6092] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183: Generated new TSK 0
I20260812 06:16:37.459918  3077 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:37.470652  2976 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:37.473809  3086 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:16:37.473819  3083 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:16:37.474259  2976 server_base.cc:1061] running on GCE node
W20260812 06:16:37.474362  3084 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:16:37.474592  2976 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:37.474663  2976 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:16:37.474689  2976 hybrid_clock.cc:648] HybridClock initialized: now 1786515397474688 us; error 0 us; skew 500 ppm
I20260812 06:16:37.475693  2976 webserver.cc:533] Webserver started at http://127.2.232.1:37263/ using document root <none> and password file <none>
I20260812 06:16:37.475888  2976 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:37.475972  2976 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:37.476055  2976 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:37.476473  2976 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/instance:
uuid: "c798a8a192664a26a09fdc2270e00d86"
format_stamp: "Formatted at 2026-08-12 06:16:37 on dist-test-slave-8n49"
I20260812 06:16:37.478091  2976 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:37.479128  3092 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:16:37.479382  2976 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:37.479456  2976 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root
uuid: "c798a8a192664a26a09fdc2270e00d86"
format_stamp: "Formatted at 2026-08-12 06:16:37 on dist-test-slave-8n49"
I20260812 06:16:37.479547  2976 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-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:16:37.489229  2976 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:37.489673  2976 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:37.490209  2976 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:37.491187  2976 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:37.491240  2976 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:37.491310  2976 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:37.491350  2976 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:37.498800  2976 rpc_server.cc:307] RPC server started. Bound to: 127.2.232.1:46019
I20260812 06:16:37.498835  3168 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.232.1:46019 every 8 connection(s)
I20260812 06:16:37.512274  3169 heartbeater.cc:344] Connected to a master server at 127.2.232.62:35635
I20260812 06:16:37.512622  3169 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:37.513195  3169 heartbeater.cc:507] Master 127.2.232.62:35635 requested a full tablet report, sending...
I20260812 06:16:37.514786  3015 ts_manager.cc:194] Registered new tserver with Master: c798a8a192664a26a09fdc2270e00d86 (127.2.232.1:46019)
I20260812 06:16:37.515242  2976 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015774382s
I20260812 06:16:37.516350  3015 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:50108
I20260812 06:16:37.525504  3015 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:50122:
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:16:37.540997  3128 tablet_service.cc:1511] Processing CreateTablet for tablet 73cafb22abd644ccad975cf9a6a2ba50 (DEFAULT_TABLE table=heavy-update-compaction-test [id=557a680d4d2a4bb4b20e3fe3c99d5972]), partition=
I20260812 06:16:37.541507  3128 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 73cafb22abd644ccad975cf9a6a2ba50. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:37.543955  3181 tablet_bootstrap.cc:492] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Bootstrap starting.
I20260812 06:16:37.545414  3181 tablet_bootstrap.cc:654] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:37.546665  3181 tablet_bootstrap.cc:492] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: No bootstrap required, opened a new log
I20260812 06:16:37.546780  3181 ts_tablet_manager.cc:1403] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:37.547267  3181 raft_consensus.cc:359] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c798a8a192664a26a09fdc2270e00d86" member_type: VOTER last_known_addr { host: "127.2.232.1" port: 46019 } }
I20260812 06:16:37.547369  3181 raft_consensus.cc:385] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:37.547394  3181 raft_consensus.cc:740] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c798a8a192664a26a09fdc2270e00d86, State: Initialized, Role: FOLLOWER
I20260812 06:16:37.547561  3181 consensus_queue.cc:260] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86 [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: "c798a8a192664a26a09fdc2270e00d86" member_type: VOTER last_known_addr { host: "127.2.232.1" port: 46019 } }
I20260812 06:16:37.547646  3181 raft_consensus.cc:399] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:37.547694  3181 raft_consensus.cc:493] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:37.547751  3181 raft_consensus.cc:3060] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:37.548730  3181 raft_consensus.cc:515] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c798a8a192664a26a09fdc2270e00d86" member_type: VOTER last_known_addr { host: "127.2.232.1" port: 46019 } }
I20260812 06:16:37.548897  3181 leader_election.cc:304] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86 [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: c798a8a192664a26a09fdc2270e00d86; no voters: 
I20260812 06:16:37.549160  3181 leader_election.cc:290] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:37.549258  3184 raft_consensus.cc:2804] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:37.549449  3184 raft_consensus.cc:697] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86 [term 1 LEADER]: Becoming Leader. State: Replica: c798a8a192664a26a09fdc2270e00d86, State: Running, Role: LEADER
I20260812 06:16:37.549530  3181 ts_tablet_manager.cc:1434] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:16:37.549654  3184 consensus_queue.cc:237] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86 [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: "c798a8a192664a26a09fdc2270e00d86" member_type: VOTER last_known_addr { host: "127.2.232.1" port: 46019 } }
I20260812 06:16:37.549765  3169 heartbeater.cc:499] Master 127.2.232.62:35635 was elected leader, sending a full tablet report...
I20260812 06:16:37.552278  3015 catalog_manager.cc:5719] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86 reported cstate change: term changed from 0 to 1, leader changed from <none> to c798a8a192664a26a09fdc2270e00d86 (127.2.232.1). New cstate: current_term: 1 leader_uuid: "c798a8a192664a26a09fdc2270e00d86" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c798a8a192664a26a09fdc2270e00d86" member_type: VOTER last_known_addr { host: "127.2.232.1" port: 46019 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:37.634413  2976 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.072s	user 0.026s	sys 0.010s
I20260812 06:16:37.750142  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushMRSOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=15.086190
I20260812 06:16:37.889096  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushMRSOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.139s	user 0.110s	sys 0.028s Metrics: {"bytes_written":8697369,"cfile_init":1,"compiler_manager_pool.queue_time_us":250,"delete_count":0,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":207,"dirs.run_wall_time_us":1025,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":32386,"lbm_writes_lt_1ms":569,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"spinlock_wait_cycles":196352,"thread_start_us":113,"threads_started":1,"update_count":1060}
I20260812 06:16:37.890256  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling LogGCOp(73cafb22abd644ccad975cf9a6a2ba50): free 11976772 bytes of WAL
I20260812 06:16:37.890590  3097 log_reader.cc:385] T 73cafb22abd644ccad975cf9a6a2ba50: removed 1 log segments from log reader
I20260812 06:16:37.890676  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000001 (ops 1-6)
I20260812 06:16:37.893114  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: LogGCOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:16:37.893483  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling UndoDeltaBlockGCOp(73cafb22abd644ccad975cf9a6a2ba50): 12308959 bytes on disk
I20260812 06:16:37.894078  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: UndoDeltaBlockGCOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:16:37.894517  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=2.188937
I20260812 06:16:37.912118  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.017s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3610355,"delete_count":0,"lbm_write_time_us":4898,"lbm_writes_lt_1ms":91,"reinsert_count":0,"update_count":440}
I20260812 06:16:37.912878  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=1.000000
I20260812 06:16:38.034601  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.122s	user 0.089s	sys 0.025s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528887,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":463,"lbm_read_time_us":7321,"lbm_reads_lt_1ms":360,"lbm_write_time_us":19054,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":230,"threads_started":5,"update_count":1500}
I20260812 06:16:38.035097  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=10.126437
I20260812 06:16:38.086920  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.052s	user 0.028s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18373,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:38.087404  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=2.188937
I20260812 06:16:38.098228  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3927,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.098930  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=1.000000
I20260812 06:16:38.220774  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.122s	user 0.101s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":598,"lbm_read_time_us":8788,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22262,"lbm_writes_lt_1ms":443,"mutex_wait_us":148,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:16:38.221386  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=10.126437
I20260812 06:16:38.272938  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.051s	user 0.030s	sys 0.020s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":21385,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:38.273420  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=2.188937
I20260812 06:16:38.283881  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4049,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.284394  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=1.000000
I20260812 06:16:38.439208  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.155s	user 0.104s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1088,"lbm_read_time_us":10962,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25276,"lbm_writes_lt_1ms":443,"mutex_wait_us":305,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":2000}
I20260812 06:16:38.439759  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=10.126437
I20260812 06:16:38.484376  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.044s	user 0.019s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19629,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:16:38.484918  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=2.188937
I20260812 06:16:38.497146  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4498,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.497920  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=1.000000
I20260812 06:16:38.627485  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.129s	user 0.101s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":270,"lbm_read_time_us":8167,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26466,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2000}
I20260812 06:16:38.628108  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=10.126437
I20260812 06:16:38.666391  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.038s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15019,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:38.666906  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=2.188937
I20260812 06:16:38.679556  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4468,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.680078  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=1.000000
I20260812 06:16:38.806960  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.127s	user 0.099s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":299,"lbm_read_time_us":9211,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24727,"lbm_writes_lt_1ms":443,"mutex_wait_us":19,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":25728,"update_count":2000}
I20260812 06:16:38.807582  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=10.126437
I20260812 06:16:38.864923  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.057s	user 0.021s	sys 0.035s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":23416,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:16:38.865603  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=2.188937
I20260812 06:16:38.882201  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.016s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6192,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.882794  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=1.000000
I20260812 06:16:39.036890  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.154s	user 0.082s	sys 0.065s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":697,"lbm_read_time_us":12011,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24732,"lbm_writes_lt_1ms":443,"mutex_wait_us":307,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2000}
I20260812 06:16:39.037398  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=10.126437
I20260812 06:16:39.084237  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.047s	user 0.009s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15761,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:39.084884  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=2.188937
I20260812 06:16:39.096139  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4192,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:39.096796  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=1.000000
I20260812 06:16:39.225455  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.128s	user 0.104s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":235,"lbm_read_time_us":7804,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26524,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16128,"update_count":2000}
I20260812 06:16:39.226254  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=10.126437
I20260812 06:16:39.272769  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.046s	user 0.024s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16898,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:39.273319  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=2.188937
I20260812 06:16:39.284976  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.011s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4334,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:39.285648  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushMRSOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=1.000000
I20260812 06:16:39.317968  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushMRSOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.032s	user 0.025s	sys 0.006s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":268,"dirs.run_wall_time_us":1516,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1916,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31,"spinlock_wait_cycles":1792}
I20260812 06:16:39.318765  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling LogGCOp(73cafb22abd644ccad975cf9a6a2ba50): free 129320491 bytes of WAL
I20260812 06:16:39.319033  3097 log_reader.cc:385] T 73cafb22abd644ccad975cf9a6a2ba50: removed 13 log segments from log reader
I20260812 06:16:39.319103  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000002 (ops 7-11)
I20260812 06:16:39.319172  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000003 (ops 12-16)
I20260812 06:16:39.319216  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000004 (ops 17-21)
I20260812 06:16:39.319253  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000005 (ops 22-26)
I20260812 06:16:39.319291  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000006 (ops 27-30)
I20260812 06:16:39.319379  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000007 (ops 31-35)
I20260812 06:16:39.319428  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000008 (ops 36-40)
I20260812 06:16:39.319466  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000009 (ops 41-44)
I20260812 06:16:39.319502  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000010 (ops 45-49)
I20260812 06:16:39.319545  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000011 (ops 50-54)
I20260812 06:16:39.319587  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000012 (ops 55-59)
I20260812 06:16:39.319623  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000013 (ops 60-64)
I20260812 06:16:39.319660  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000014 (ops 65-69)
I20260812 06:16:39.347988  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: LogGCOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:16:39.348445  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling UndoDeltaBlockGCOp(73cafb22abd644ccad975cf9a6a2ba50): 483 bytes on disk
I20260812 06:16:39.349071  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: UndoDeltaBlockGCOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":96,"lbm_reads_lt_1ms":4}
I20260812 06:16:39.349638  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=3.181125
I20260812 06:16:39.367486  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.018s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4384,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:39.368034  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=2.188937
I20260812 06:16:39.383857  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5849,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:39.384476  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=1.000000
I20260812 06:16:39.556156  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.171s	user 0.159s	sys 0.004s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836365,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":837,"lbm_read_time_us":11189,"lbm_reads_lt_1ms":666,"lbm_write_time_us":31795,"lbm_writes_lt_1ms":643,"mutex_wait_us":48,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12416,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:16:39.556833  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=14.095187
I20260812 06:16:39.609643  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.053s	user 0.032s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20955,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:39.610209  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=2.188937
I20260812 06:16:39.626389  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.016s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6185,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:39.627074  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=1.000000
I20260812 06:16:39.781157  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.154s	user 0.120s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":304,"lbm_read_time_us":9810,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29473,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2500}
I20260812 06:16:39.781805  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=14.095187
I20260812 06:16:39.833751  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.052s	user 0.039s	sys 0.012s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":20722,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:39.834311  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=2.188937
I20260812 06:16:39.848155  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.014s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5033,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:39.848755  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=1.000000
I20260812 06:16:40.002892  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.154s	user 0.122s	sys 0.023s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733721,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":943,"lbm_read_time_us":9407,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31490,"lbm_writes_lt_1ms":543,"mutex_wait_us":576,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":798976,"update_count":2500}
I20260812 06:16:40.003463  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=14.095187
I20260812 06:16:40.056914  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.053s	user 0.032s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23809,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:40.057446  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=2.188937
I20260812 06:16:40.070202  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4738,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.070819  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=1.000000
I20260812 06:16:40.236887  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.166s	user 0.138s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":808,"lbm_read_time_us":9369,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32529,"lbm_writes_lt_1ms":543,"mutex_wait_us":96,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:40.237619  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=14.095187
I20260812 06:16:40.298154  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.060s	user 0.037s	sys 0.014s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23678,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:40.298635  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=2.188937
I20260812 06:16:40.310349  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4134,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.311012  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=1.000000
I20260812 06:16:40.486073  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.175s	user 0.130s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1121,"lbm_read_time_us":11556,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30737,"lbm_writes_lt_1ms":543,"mutex_wait_us":350,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18432,"update_count":2500}
I20260812 06:16:40.486788  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=14.095187
I20260812 06:16:40.544308  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.057s	user 0.039s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25844,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:16:40.544870  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=2.188937
I20260812 06:16:40.557437  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4717,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.557898  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=1.000000
I20260812 06:16:40.806492  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.248s	user 0.112s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":501,"lbm_read_time_us":10528,"lbm_reads_lt_1ms":568,"lbm_write_time_us":35668,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:16:40.807124  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=19.056125
I20260812 06:16:40.928784  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.121s	user 0.041s	sys 0.020s Metrics: {"bytes_written":20922554,"delete_count":0,"lbm_write_time_us":27209,"lbm_writes_lt_1ms":513,"reinsert_count":0,"update_count":2550}
I20260812 06:16:40.929451  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=10.126437
I20260812 06:16:41.022104  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.092s	user 0.014s	sys 0.012s Metrics: {"bytes_written":11897249,"delete_count":0,"lbm_write_time_us":12048,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:16:41.022668  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=6.157687
I20260812 06:16:41.121206  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.098s	user 0.018s	sys 0.007s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":10868,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:41.121970  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=7.149875
I20260812 06:16:41.226472  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.104s	user 0.017s	sys 0.004s Metrics: {"bytes_written":8615322,"delete_count":0,"lbm_write_time_us":8882,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:41.227246  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=10.126437
I20260812 06:16:41.329583  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.102s	user 0.024s	sys 0.008s Metrics: {"bytes_written":11897250,"delete_count":0,"lbm_write_time_us":14558,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":292,"reinsert_count":0,"update_count":1450}
I20260812 06:16:41.330457  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=6.157687
I20260812 06:16:41.436079  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.105s	user 0.020s	sys 0.004s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10653,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:41.436935  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=7.149875
I20260812 06:16:41.538913  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.102s	user 0.011s	sys 0.009s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":9000,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:41.539495  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=10.126437
I20260812 06:16:41.643391  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.104s	user 0.022s	sys 0.008s Metrics: {"bytes_written":11897250,"delete_count":0,"lbm_write_time_us":13675,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:16:41.644358  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=8.142062
I20260812 06:16:41.745867  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.101s	user 0.017s	sys 0.008s Metrics: {"bytes_written":9846041,"delete_count":0,"lbm_write_time_us":11090,"lbm_writes_lt_1ms":243,"reinsert_count":0,"update_count":1200}
I20260812 06:16:41.746505  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=9.134250
I20260812 06:16:41.849440  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.103s	user 0.024s	sys 0.011s Metrics: {"bytes_written":10666535,"delete_count":0,"lbm_write_time_us":14478,"lbm_writes_lt_1ms":263,"reinsert_count":0,"update_count":1300}
I20260812 06:16:41.850309  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=7.149875
I20260812 06:16:41.950479  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.100s	user 0.015s	sys 0.007s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":9379,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:41.951373  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=10.126437
I20260812 06:16:42.053092  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.102s	user 0.023s	sys 0.012s Metrics: {"bytes_written":11897249,"delete_count":0,"lbm_write_time_us":14665,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:16:42.054049  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=6.157687
I20260812 06:16:42.156512  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.102s	user 0.015s	sys 0.012s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":12456,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:42.157572  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=6.157687
I20260812 06:16:42.259894  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.102s	user 0.018s	sys 0.005s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11886,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":202,"reinsert_count":0,"update_count":1000}
I20260812 06:16:42.261085  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=7.149875
I20260812 06:16:42.275315  2976 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.641s	user 1.767s	sys 0.113s
I20260812 06:16:42.361080  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.100s	user 0.008s	sys 0.016s Metrics: {"bytes_written":8574299,"delete_count":0,"lbm_write_time_us":12046,"lbm_writes_lt_1ms":212,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":1045}
I20260812 06:16:42.361914  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=2.188937
I20260812 06:16:42.378818  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushDeltaMemStoresOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.017s	user 0.015s	sys 0.000s Metrics: {"bytes_written":3733433,"delete_count":0,"lbm_write_time_us":7081,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:16:42.379442  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling FlushMRSOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=1.195565
I20260812 06:16:42.436167  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: FlushMRSOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.056s	user 0.043s	sys 0.012s Metrics: {"bytes_written":2709936,"cfile_init":1,"dirs.queue_time_us":428,"dirs.run_cpu_time_us":226,"dirs.run_wall_time_us":1346,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":4818,"lbm_writes_lt_1ms":49,"peak_mem_usage":0,"rows_written":66,"thread_start_us":104,"threads_started":1}
I20260812 06:16:42.437115  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling LogGCOp(73cafb22abd644ccad975cf9a6a2ba50): free 257734955 bytes of WAL
I20260812 06:16:42.437477  3097 log_reader.cc:385] T 73cafb22abd644ccad975cf9a6a2ba50: removed 25 log segments from log reader
I20260812 06:16:42.437558  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000015 (ops 70-74)
I20260812 06:16:42.437613  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000016 (ops 75-79)
I20260812 06:16:42.437671  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000017 (ops 80-84)
I20260812 06:16:42.437714  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000018 (ops 85-89)
I20260812 06:16:42.437752  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000019 (ops 90-94)
I20260812 06:16:42.437783  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000020 (ops 95-99)
I20260812 06:16:42.437820  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000021 (ops 100-104)
I20260812 06:16:42.437860  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000022 (ops 105-109)
I20260812 06:16:42.437898  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000023 (ops 110-114)
I20260812 06:16:42.437927  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000024 (ops 115-119)
I20260812 06:16:42.437963  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000025 (ops 120-124)
I20260812 06:16:42.438009  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000026 (ops 125-129)
I20260812 06:16:42.438056  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000027 (ops 130-134)
I20260812 06:16:42.438097  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000028 (ops 135-139)
I20260812 06:16:42.438131  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000029 (ops 140-144)
I20260812 06:16:42.438170  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000030 (ops 145-149)
I20260812 06:16:42.438210  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000031 (ops 150-154)
I20260812 06:16:42.438249  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000032 (ops 155-159)
I20260812 06:16:42.438289  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000033 (ops 160-164)
I20260812 06:16:42.438328  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000034 (ops 165-169)
I20260812 06:16:42.438367  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000035 (ops 170-174)
I20260812 06:16:42.438413  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000036 (ops 175-178)
I20260812 06:16:42.438462  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000037 (ops 179-183)
I20260812 06:16:42.438494  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000038 (ops 184-188)
I20260812 06:16:42.438529  3097 log.cc:1079] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/73cafb22abd644ccad975cf9a6a2ba50/wal-000000039 (ops 189-193)
I20260812 06:16:42.485736  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: LogGCOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.048s	user 0.003s	sys 0.044s Metrics: {}
I20260812 06:16:42.486264  3170 maintenance_manager.cc:419] P c798a8a192664a26a09fdc2270e00d86: Scheduling MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50): perf score=1.000000
I20260812 06:16:42.687039  2976 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.411s	user 0.003s	sys 0.000s
I20260812 06:16:42.687865  2976 tablet_server.cc:179] TabletServer@127.2.232.1:0 shutting down...
I20260812 06:16:43.285328  3097 maintenance_manager.cc:643] P c798a8a192664a26a09fdc2270e00d86: MajorDeltaCompactionOp(73cafb22abd644ccad975cf9a6a2ba50) complete. Timing: real 0.799s	user 0.406s	sys 0.392s Metrics: {"cfile_cache_hit":3090,"cfile_cache_hit_bytes":126198766,"cfile_cache_miss":856,"cfile_cache_miss_bytes":38018659,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":16,"delta_iterators_relevant":16,"dirs.queue_time_us":1383,"lbm_read_time_us":15877,"lbm_reads_lt_1ms":892,"lbm_write_time_us":167082,"lbm_writes_lt_1ms":3946,"peak_mem_usage":485619348,"reinsert_count":0,"spinlock_wait_cycles":22400,"thread_start_us":408,"threads_started":6,"update_count":19500}
I20260812 06:16:43.286108  2976 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:43.286520  2976 tablet_replica.cc:333] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86: stopping tablet replica
I20260812 06:16:43.286800  2976 raft_consensus.cc:2243] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:43.287066  2976 raft_consensus.cc:2272] T 73cafb22abd644ccad975cf9a6a2ba50 P c798a8a192664a26a09fdc2270e00d86 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:43.302173  2976 tablet_server.cc:196] TabletServer@127.2.232.1:0 shutdown complete.
I20260812 06:16:43.886641  2976 master.cc:562] Master@127.2.232.62:35635 shutting down...
I20260812 06:16:43.890793  2976 raft_consensus.cc:2243] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:43.891062  2976 raft_consensus.cc:2272] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:43.891196  2976 tablet_replica.cc:333] T 00000000000000000000000000000000 P e609300994684529b9f8a1124e062183: stopping tablet replica
I20260812 06:16:43.904067  2976 master.cc:584] Master@127.2.232.62:35635 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6657 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:44.014744  2976 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.2.232.62:45069
I20260812 06:16:44.015228  2976 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:44.018253  3211 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:16:44.018239  3212 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:16:44.018309  2976 server_base.cc:1061] running on GCE node
W20260812 06:16:44.018239  3216 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:16:44.018739  2976 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:44.018785  2976 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:16:44.018801  2976 hybrid_clock.cc:648] HybridClock initialized: now 1786515404018802 us; error 0 us; skew 500 ppm
I20260812 06:16:44.019671  2976 webserver.cc:533] Webserver started at http://127.2.232.62:40407/ using document root <none> and password file <none>
I20260812 06:16:44.019811  2976 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:44.019855  2976 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:44.019912  2976 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:44.020282  2976 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/master-0-root/instance:
uuid: "b4751e2db8bb4fa5a82dfbf991a18817"
format_stamp: "Formatted at 2026-08-12 06:16:44 on dist-test-slave-8n49"
I20260812 06:16:44.022040  2976 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:16:44.023237  3222 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:16:44.023576  2976 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:44.023664  2976 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/master-0-root
uuid: "b4751e2db8bb4fa5a82dfbf991a18817"
format_stamp: "Formatted at 2026-08-12 06:16:44 on dist-test-slave-8n49"
I20260812 06:16:44.023721  2976 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-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:16:44.066324  2976 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:44.066758  2976 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:44.072897  2976 rpc_server.cc:307] RPC server started. Bound to: 127.2.232.62:45069
I20260812 06:16:44.074391  3283 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.232.62:45069 every 8 connection(s)
I20260812 06:16:44.088840  3284 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:16:44.090922  3284 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817: Bootstrap starting.
I20260812 06:16:44.091761  3284 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:44.093254  3284 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817: No bootstrap required, opened a new log
I20260812 06:16:44.093690  3284 raft_consensus.cc:359] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b4751e2db8bb4fa5a82dfbf991a18817" member_type: VOTER }
I20260812 06:16:44.093806  3284 raft_consensus.cc:385] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:44.093832  3284 raft_consensus.cc:740] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b4751e2db8bb4fa5a82dfbf991a18817, State: Initialized, Role: FOLLOWER
I20260812 06:16:44.093997  3284 consensus_queue.cc:260] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817 [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: "b4751e2db8bb4fa5a82dfbf991a18817" member_type: VOTER }
I20260812 06:16:44.094100  3284 raft_consensus.cc:399] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:44.094127  3284 raft_consensus.cc:493] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:44.094157  3284 raft_consensus.cc:3060] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:44.094898  3284 raft_consensus.cc:515] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b4751e2db8bb4fa5a82dfbf991a18817" member_type: VOTER }
I20260812 06:16:44.095018  3284 leader_election.cc:304] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817 [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: b4751e2db8bb4fa5a82dfbf991a18817; no voters: 
I20260812 06:16:44.095198  3284 leader_election.cc:290] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:44.095434  3288 raft_consensus.cc:2804] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:44.095666  3284 sys_catalog.cc:565] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:44.095664  3288 raft_consensus.cc:697] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817 [term 1 LEADER]: Becoming Leader. State: Replica: b4751e2db8bb4fa5a82dfbf991a18817, State: Running, Role: LEADER
I20260812 06:16:44.095855  3288 consensus_queue.cc:237] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817 [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: "b4751e2db8bb4fa5a82dfbf991a18817" member_type: VOTER }
I20260812 06:16:44.096442  3291 sys_catalog.cc:455] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817 [sys.catalog]: SysCatalogTable state changed. Reason: New leader b4751e2db8bb4fa5a82dfbf991a18817. Latest consensus state: current_term: 1 leader_uuid: "b4751e2db8bb4fa5a82dfbf991a18817" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b4751e2db8bb4fa5a82dfbf991a18817" member_type: VOTER } }
I20260812 06:16:44.096529  3291 sys_catalog.cc:458] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:44.096760  3289 sys_catalog.cc:455] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "b4751e2db8bb4fa5a82dfbf991a18817" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b4751e2db8bb4fa5a82dfbf991a18817" member_type: VOTER } }
I20260812 06:16:44.096987  3289 sys_catalog.cc:458] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:44.097580  3298 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:44.098425  3298 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:44.098786  2976 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:44.100499  3298 catalog_manager.cc:1383] Generated new cluster ID: 86433939b5534950b86d4b0cf0088b68
I20260812 06:16:44.100627  3298 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:44.118373  3298 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:44.119038  3298 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:44.123051  3298 catalog_manager.cc:6092] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817: Generated new TSK 0
I20260812 06:16:44.123238  3298 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:44.131168  2976 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:44.133836  3312 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:16:44.133849  3310 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:16:44.134120  2976 server_base.cc:1061] running on GCE node
W20260812 06:16:44.133849  3309 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:16:44.134654  2976 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:44.134711  2976 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:16:44.134728  2976 hybrid_clock.cc:648] HybridClock initialized: now 1786515404134728 us; error 0 us; skew 500 ppm
I20260812 06:16:44.135860  2976 webserver.cc:533] Webserver started at http://127.2.232.1:39697/ using document root <none> and password file <none>
I20260812 06:16:44.136083  2976 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:44.136149  2976 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:44.136234  2976 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:44.136725  2976 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/instance:
uuid: "de4291e3a075466182606eb3a2017fb2"
format_stamp: "Formatted at 2026-08-12 06:16:44 on dist-test-slave-8n49"
I20260812 06:16:44.138312  2976 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:44.139250  3317 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:16:44.139474  2976 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:44.139565  2976 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root
uuid: "de4291e3a075466182606eb3a2017fb2"
format_stamp: "Formatted at 2026-08-12 06:16:44 on dist-test-slave-8n49"
I20260812 06:16:44.139653  2976 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-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:16:44.158536  2976 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:44.158979  2976 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:44.159314  2976 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:44.159797  2976 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:44.159857  2976 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:44.159920  2976 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:44.159957  2976 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:44.164348  2976 rpc_server.cc:307] RPC server started. Bound to: 127.2.232.1:33357
I20260812 06:16:44.164386  3392 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.232.1:33357 every 8 connection(s)
I20260812 06:16:44.175120  3394 heartbeater.cc:344] Connected to a master server at 127.2.232.62:45069
I20260812 06:16:44.175299  3394 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:44.175580  3394 heartbeater.cc:507] Master 127.2.232.62:45069 requested a full tablet report, sending...
I20260812 06:16:44.176295  3242 ts_manager.cc:194] Registered new tserver with Master: de4291e3a075466182606eb3a2017fb2 (127.2.232.1:33357)
I20260812 06:16:44.177093  3242 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:45516
I20260812 06:16:44.177119  2976 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012275759s
I20260812 06:16:44.185680  3242 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:45520:
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:16:44.195065  3350 tablet_service.cc:1511] Processing CreateTablet for tablet baa675bd850e4ed0a7b285047773da1a (DEFAULT_TABLE table=heavy-update-compaction-test [id=d3c392db64af4d1bb5b3fdae79332294]), partition=
I20260812 06:16:44.195403  3350 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet baa675bd850e4ed0a7b285047773da1a. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:44.197882  3409 tablet_bootstrap.cc:492] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Bootstrap starting.
I20260812 06:16:44.198763  3409 tablet_bootstrap.cc:654] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:44.199806  3409 tablet_bootstrap.cc:492] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: No bootstrap required, opened a new log
I20260812 06:16:44.199898  3409 ts_tablet_manager.cc:1403] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:16:44.200285  3409 raft_consensus.cc:359] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "de4291e3a075466182606eb3a2017fb2" member_type: VOTER last_known_addr { host: "127.2.232.1" port: 33357 } }
I20260812 06:16:44.200394  3409 raft_consensus.cc:385] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:44.200430  3409 raft_consensus.cc:740] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: de4291e3a075466182606eb3a2017fb2, State: Initialized, Role: FOLLOWER
I20260812 06:16:44.200606  3409 consensus_queue.cc:260] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2 [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: "de4291e3a075466182606eb3a2017fb2" member_type: VOTER last_known_addr { host: "127.2.232.1" port: 33357 } }
I20260812 06:16:44.200735  3409 raft_consensus.cc:399] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:44.200789  3409 raft_consensus.cc:493] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:44.200826  3409 raft_consensus.cc:3060] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:44.201488  3409 raft_consensus.cc:515] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "de4291e3a075466182606eb3a2017fb2" member_type: VOTER last_known_addr { host: "127.2.232.1" port: 33357 } }
I20260812 06:16:44.201604  3409 leader_election.cc:304] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2 [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: de4291e3a075466182606eb3a2017fb2; no voters: 
I20260812 06:16:44.201756  3409 leader_election.cc:290] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:44.201896  3411 raft_consensus.cc:2804] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:44.202117  3409 ts_tablet_manager.cc:1434] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:44.202131  3394 heartbeater.cc:499] Master 127.2.232.62:45069 was elected leader, sending a full tablet report...
I20260812 06:16:44.202193  3411 raft_consensus.cc:697] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2 [term 1 LEADER]: Becoming Leader. State: Replica: de4291e3a075466182606eb3a2017fb2, State: Running, Role: LEADER
I20260812 06:16:44.202380  3411 consensus_queue.cc:237] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2 [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: "de4291e3a075466182606eb3a2017fb2" member_type: VOTER last_known_addr { host: "127.2.232.1" port: 33357 } }
I20260812 06:16:44.203708  3242 catalog_manager.cc:5719] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2 reported cstate change: term changed from 0 to 1, leader changed from <none> to de4291e3a075466182606eb3a2017fb2 (127.2.232.1). New cstate: current_term: 1 leader_uuid: "de4291e3a075466182606eb3a2017fb2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "de4291e3a075466182606eb3a2017fb2" member_type: VOTER last_known_addr { host: "127.2.232.1" port: 33357 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:44.261744  2976 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.011s	sys 0.011s
I20260812 06:16:44.415418  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushMRSOp(baa675bd850e4ed0a7b285047773da1a): perf score=19.054940
I20260812 06:16:44.591694  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushMRSOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.176s	user 0.125s	sys 0.047s Metrics: {"bytes_written":13127978,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":213,"dirs.run_wall_time_us":917,"drs_written":1,"lbm_read_time_us":100,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44604,"lbm_writes_lt_1ms":777,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":28416,"update_count":1600}
I20260812 06:16:44.592481  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling LogGCOp(baa675bd850e4ed0a7b285047773da1a): free 20743880 bytes of WAL
I20260812 06:16:44.592721  3322 log_reader.cc:385] T baa675bd850e4ed0a7b285047773da1a: removed 2 log segments from log reader
I20260812 06:16:44.592767  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000001 (ops 1-6)
I20260812 06:16:44.592805  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000002 (ops 7-11)
I20260812 06:16:44.597580  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: LogGCOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:16:44.598022  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=2.188937
I20260812 06:16:44.618595  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.020s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692409,"delete_count":0,"lbm_write_time_us":4735,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:44.619158  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling UndoDeltaBlockGCOp(baa675bd850e4ed0a7b285047773da1a): 16411393 bytes on disk
I20260812 06:16:44.619606  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: UndoDeltaBlockGCOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:16:44.620011  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=2.188937
I20260812 06:16:44.630158  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3702,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:44.630555  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling MajorDeltaCompactionOp(baa675bd850e4ed0a7b285047773da1a): perf score=1.000000
I20260812 06:16:44.802695  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: MajorDeltaCompactionOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.172s	user 0.129s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774792,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":576,"lbm_read_time_us":13231,"lbm_reads_lt_1ms":569,"lbm_write_time_us":30274,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10752,"thread_start_us":362,"threads_started":5,"update_count":2500}
I20260812 06:16:44.803295  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=14.095187
I20260812 06:16:44.855713  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.052s	user 0.018s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19298,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:44.856300  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=2.188937
I20260812 06:16:44.871762  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.015s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5722,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.872350  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling MajorDeltaCompactionOp(baa675bd850e4ed0a7b285047773da1a): perf score=1.000000
I20260812 06:16:45.032953  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: MajorDeltaCompactionOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.160s	user 0.114s	sys 0.032s 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":265,"lbm_read_time_us":12222,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26724,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2500}
I20260812 06:16:45.033675  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=14.095187
I20260812 06:16:45.089056  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.055s	user 0.026s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19019,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:45.089512  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=2.188937
I20260812 06:16:45.100762  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3959,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.101347  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling MajorDeltaCompactionOp(baa675bd850e4ed0a7b285047773da1a): perf score=1.000000
I20260812 06:16:45.288003  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: MajorDeltaCompactionOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.186s	user 0.118s	sys 0.068s 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":1049,"lbm_read_time_us":12017,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31580,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:16:45.288532  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=14.095187
I20260812 06:16:45.351810  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.063s	user 0.030s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22446,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:45.352267  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=2.188937
I20260812 06:16:45.365110  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4605,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.365796  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling MajorDeltaCompactionOp(baa675bd850e4ed0a7b285047773da1a): perf score=1.000000
I20260812 06:16:45.540333  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: MajorDeltaCompactionOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.174s	user 0.122s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":902,"lbm_read_time_us":14177,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27613,"lbm_writes_lt_1ms":543,"mutex_wait_us":251,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16640,"update_count":2500}
I20260812 06:16:45.541119  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=14.095187
I20260812 06:16:45.593428  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.052s	user 0.042s	sys 0.003s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18899,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:45.594136  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=2.188937
I20260812 06:16:45.607117  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.013s	user 0.004s	sys 0.007s 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:16:45.607571  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling MajorDeltaCompactionOp(baa675bd850e4ed0a7b285047773da1a): perf score=1.000000
I20260812 06:16:45.796456  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: MajorDeltaCompactionOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.189s	user 0.132s	sys 0.052s 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":577,"lbm_read_time_us":12860,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31738,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2500}
I20260812 06:16:45.797188  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=14.095187
I20260812 06:16:45.855759  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.058s	user 0.039s	sys 0.014s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20527,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:45.856287  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=2.188937
I20260812 06:16:45.867086  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4215,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.867515  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushMRSOp(baa675bd850e4ed0a7b285047773da1a): perf score=1.000000
I20260812 06:16:45.911392  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushMRSOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.044s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":278,"dirs.run_wall_time_us":1410,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1730,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:16:45.912024  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling LogGCOp(baa675bd850e4ed0a7b285047773da1a): free 120553329 bytes of WAL
I20260812 06:16:45.912261  3322 log_reader.cc:385] T baa675bd850e4ed0a7b285047773da1a: removed 12 log segments from log reader
I20260812 06:16:45.912302  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000003 (ops 12-16)
I20260812 06:16:45.912330  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000004 (ops 17-21)
I20260812 06:16:45.912403  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000005 (ops 22-26)
I20260812 06:16:45.912447  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000006 (ops 27-30)
I20260812 06:16:45.912525  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000007 (ops 31-35)
I20260812 06:16:45.912607  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000008 (ops 36-40)
I20260812 06:16:45.912653  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000009 (ops 41-45)
I20260812 06:16:45.912694  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000010 (ops 46-50)
I20260812 06:16:45.912734  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000011 (ops 51-54)
I20260812 06:16:45.912773  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000012 (ops 55-59)
I20260812 06:16:45.912812  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000013 (ops 60-64)
I20260812 06:16:45.912853  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000014 (ops 65-69)
I20260812 06:16:45.936671  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: LogGCOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.024s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:16:45.937249  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=3.181125
I20260812 06:16:45.961575  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.024s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4404,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:45.962008  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=2.188937
I20260812 06:16:45.971191  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.009s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3459,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:45.971639  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling UndoDeltaBlockGCOp(baa675bd850e4ed0a7b285047773da1a): 472 bytes on disk
I20260812 06:16:45.972016  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: UndoDeltaBlockGCOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:16:45.972465  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling MajorDeltaCompactionOp(baa675bd850e4ed0a7b285047773da1a): perf score=1.000000
I20260812 06:16:46.196841  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: MajorDeltaCompactionOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.224s	user 0.123s	sys 0.096s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979740,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":551,"lbm_read_time_us":14744,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39128,"lbm_writes_lt_1ms":743,"mutex_wait_us":39,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2688,"thread_start_us":83,"threads_started":1,"update_count":3500}
I20260812 06:16:46.197588  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=18.063937
I20260812 06:16:46.257926  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.060s	user 0.031s	sys 0.027s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":27420,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:46.258576  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=2.188937
I20260812 06:16:46.272683  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.014s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4360,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:46.273306  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling MajorDeltaCompactionOp(baa675bd850e4ed0a7b285047773da1a): perf score=1.000000
I20260812 06:16:46.455493  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: MajorDeltaCompactionOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.182s	user 0.133s	sys 0.048s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":278,"lbm_read_time_us":12396,"lbm_reads_lt_1ms":664,"lbm_write_time_us":37000,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":3000}
I20260812 06:16:46.456075  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=14.095187
I20260812 06:16:46.508193  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.052s	user 0.037s	sys 0.011s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23406,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:16:46.508977  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=2.188937
I20260812 06:16:46.523547  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5372,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:46.523985  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling MajorDeltaCompactionOp(baa675bd850e4ed0a7b285047773da1a): perf score=1.000000
I20260812 06:16:46.681389  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: MajorDeltaCompactionOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.157s	user 0.127s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1097,"lbm_read_time_us":8793,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31874,"lbm_writes_lt_1ms":543,"mutex_wait_us":306,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2500}
I20260812 06:16:46.681922  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=14.095187
I20260812 06:16:46.749768  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.068s	user 0.027s	sys 0.026s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21611,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:46.750245  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=2.188937
I20260812 06:16:46.761229  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3985,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:46.761907  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling MajorDeltaCompactionOp(baa675bd850e4ed0a7b285047773da1a): perf score=1.000000
I20260812 06:16:46.939783  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: MajorDeltaCompactionOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.178s	user 0.133s	sys 0.044s 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":357,"lbm_read_time_us":12443,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30463,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2500}
I20260812 06:16:46.940503  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=14.095187
I20260812 06:16:46.989810  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.049s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21649,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:46.990381  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=2.188937
I20260812 06:16:47.007222  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.017s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6198,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:47.007819  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling MajorDeltaCompactionOp(baa675bd850e4ed0a7b285047773da1a): perf score=1.000000
I20260812 06:16:47.190773  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: MajorDeltaCompactionOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.183s	user 0.134s	sys 0.040s 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":293,"lbm_read_time_us":12974,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29384,"lbm_writes_lt_1ms":543,"mutex_wait_us":70,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2500}
I20260812 06:16:47.191578  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=14.095187
I20260812 06:16:47.254458  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.063s	user 0.024s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21604,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:47.255023  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=2.188937
I20260812 06:16:47.267066  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4785,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:47.267696  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushMRSOp(baa675bd850e4ed0a7b285047773da1a): perf score=1.000000
I20260812 06:16:47.307539  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushMRSOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.040s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":1532,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1470,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:47.308199  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling LogGCOp(baa675bd850e4ed0a7b285047773da1a): free 112239367 bytes of WAL
I20260812 06:16:47.308423  3322 log_reader.cc:385] T baa675bd850e4ed0a7b285047773da1a: removed 11 log segments from log reader
I20260812 06:16:47.308463  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000015 (ops 70-74)
I20260812 06:16:47.308494  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000016 (ops 75-78)
I20260812 06:16:47.308593  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000017 (ops 79-83)
I20260812 06:16:47.308637  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000018 (ops 84-88)
I20260812 06:16:47.308678  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000019 (ops 89-93)
I20260812 06:16:47.308720  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000020 (ops 94-98)
I20260812 06:16:47.308763  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000021 (ops 99-103)
I20260812 06:16:47.308804  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000022 (ops 104-108)
I20260812 06:16:47.308843  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000023 (ops 109-113)
I20260812 06:16:47.308882  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000024 (ops 114-118)
I20260812 06:16:47.308921  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000025 (ops 119-123)
I20260812 06:16:47.332652  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: LogGCOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.024s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:16:47.333141  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling UndoDeltaBlockGCOp(baa675bd850e4ed0a7b285047773da1a): 447 bytes on disk
I20260812 06:16:47.333576  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: UndoDeltaBlockGCOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:16:47.334106  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=2.188937
I20260812 06:16:47.358270  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.024s	user 0.007s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4378,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:47.358713  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=2.188937
I20260812 06:16:47.371431  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4694,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:47.372090  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling MajorDeltaCompactionOp(baa675bd850e4ed0a7b285047773da1a): perf score=1.000000
I20260812 06:16:47.630475  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: MajorDeltaCompactionOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.258s	user 0.169s	sys 0.059s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":802,"lbm_read_time_us":16532,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38038,"lbm_writes_lt_1ms":743,"mutex_wait_us":291,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:16:47.631811  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=19.056125
I20260812 06:16:47.745491  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.113s	user 0.051s	sys 0.023s Metrics: {"bytes_written":20922553,"delete_count":0,"lbm_write_time_us":33121,"lbm_writes_lt_1ms":513,"reinsert_count":0,"update_count":2550}
I20260812 06:16:47.746186  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=6.157687
I20260812 06:16:47.845050  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.099s	user 0.006s	sys 0.016s Metrics: {"bytes_written":8164057,"delete_count":0,"lbm_write_time_us":9025,"lbm_writes_lt_1ms":202,"reinsert_count":0,"update_count":995}
I20260812 06:16:47.845743  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=10.126437
I20260812 06:16:47.955256  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.109s	user 0.023s	sys 0.019s Metrics: {"bytes_written":11938277,"delete_count":0,"lbm_write_time_us":14325,"lbm_writes_lt_1ms":294,"reinsert_count":0,"update_count":1455}
I20260812 06:16:47.955859  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=7.149875
I20260812 06:16:48.048358  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.092s	user 0.018s	sys 0.007s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":11879,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:48.049062  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=6.157687
I20260812 06:16:48.147390  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.098s	user 0.016s	sys 0.009s Metrics: {"bytes_written":7917910,"delete_count":0,"lbm_write_time_us":11048,"lbm_writes_lt_1ms":196,"reinsert_count":0,"update_count":965}
I20260812 06:16:48.148046  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=7.149875
I20260812 06:16:48.248764  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.100s	user 0.021s	sys 0.007s Metrics: {"bytes_written":8492254,"delete_count":0,"lbm_write_time_us":12128,"lbm_writes_lt_1ms":210,"reinsert_count":0,"update_count":1035}
I20260812 06:16:48.249392  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=8.142062
I20260812 06:16:48.347882  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.098s	user 0.017s	sys 0.010s Metrics: {"bytes_written":10092187,"delete_count":0,"lbm_write_time_us":11834,"lbm_writes_lt_1ms":249,"reinsert_count":0,"update_count":1230}
I20260812 06:16:48.348464  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=8.142062
I20260812 06:16:48.451946  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.103s	user 0.015s	sys 0.013s Metrics: {"bytes_written":10010140,"delete_count":0,"lbm_write_time_us":12148,"lbm_writes_lt_1ms":247,"reinsert_count":0,"update_count":1220}
I20260812 06:16:48.452762  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=7.149875
I20260812 06:16:48.553368  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.100s	user 0.011s	sys 0.009s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":8550,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:48.554207  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=10.126437
I20260812 06:16:48.649597  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.095s	user 0.031s	sys 0.004s Metrics: {"bytes_written":11528033,"delete_count":0,"lbm_write_time_us":14066,"lbm_writes_lt_1ms":284,"reinsert_count":0,"update_count":1405}
I20260812 06:16:48.650187  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=7.149875
I20260812 06:16:48.681244  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.031s	user 0.025s	sys 0.000s Metrics: {"bytes_written":8574304,"delete_count":0,"lbm_write_time_us":10220,"lbm_writes_lt_1ms":212,"reinsert_count":0,"update_count":1045}
I20260812 06:16:48.681773  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=2.188937
I20260812 06:16:48.707465  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.026s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4118,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:48.708060  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushMRSOp(baa675bd850e4ed0a7b285047773da1a): perf score=1.000000
I20260812 06:16:48.760419  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushMRSOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.052s	user 0.028s	sys 0.001s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":227,"dirs.run_cpu_time_us":264,"dirs.run_wall_time_us":1508,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1652,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32,"thread_start_us":88,"threads_started":1}
I20260812 06:16:48.761229  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling LogGCOp(baa675bd850e4ed0a7b285047773da1a): free 133024598 bytes of WAL
I20260812 06:16:48.761519  3322 log_reader.cc:385] T baa675bd850e4ed0a7b285047773da1a: removed 13 log segments from log reader
I20260812 06:16:48.761588  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000026 (ops 124-128)
I20260812 06:16:48.761639  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000027 (ops 129-133)
I20260812 06:16:48.761678  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000028 (ops 134-138)
I20260812 06:16:48.761713  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000029 (ops 139-143)
I20260812 06:16:48.761749  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000030 (ops 144-148)
I20260812 06:16:48.761790  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000031 (ops 149-153)
I20260812 06:16:48.761828  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000032 (ops 154-158)
I20260812 06:16:48.761868  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000033 (ops 159-163)
I20260812 06:16:48.761906  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000034 (ops 164-168)
I20260812 06:16:48.761948  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000035 (ops 169-173)
I20260812 06:16:48.761986  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000036 (ops 174-178)
I20260812 06:16:48.762024  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000037 (ops 179-182)
I20260812 06:16:48.762063  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000038 (ops 183-187)
I20260812 06:16:48.790884  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: LogGCOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:16:48.791380  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=7.149875
I20260812 06:16:48.819551  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.028s	user 0.006s	sys 0.019s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":12080,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:48.820073  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling LogGCOp(baa675bd850e4ed0a7b285047773da1a): free 12018004 bytes of WAL
I20260812 06:16:48.820338  3322 log_reader.cc:385] T baa675bd850e4ed0a7b285047773da1a: removed 1 log segments from log reader
I20260812 06:16:48.820395  3322 log.cc:1079] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: Deleting log segment in path: /tmp/dist-test-taskhAu2HB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397325260-2976-0/minicluster-data/ts-0-root/wals/baa675bd850e4ed0a7b285047773da1a/wal-000000039 (ops 188-192)
I20260812 06:16:48.823302  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: LogGCOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:16:48.823632  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling UndoDeltaBlockGCOp(baa675bd850e4ed0a7b285047773da1a): 493 bytes on disk
I20260812 06:16:48.824127  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: UndoDeltaBlockGCOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:16:48.824726  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a): perf score=2.188937
I20260812 06:16:48.843254  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: FlushDeltaMemStoresOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.018s	user 0.009s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5807,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:48.843771  3395 maintenance_manager.cc:419] P de4291e3a075466182606eb3a2017fb2: Scheduling MajorDeltaCompactionOp(baa675bd850e4ed0a7b285047773da1a): perf score=1.000000
I20260812 06:16:49.027166  2976 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.765s	user 1.745s	sys 0.142s
I20260812 06:16:49.381069  2976 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.353s	user 0.004s	sys 0.000s
I20260812 06:16:49.381682  2976 tablet_server.cc:179] TabletServer@127.2.232.1:0 shutting down...
I20260812 06:16:49.604038  3322 maintenance_manager.cc:643] P de4291e3a075466182606eb3a2017fb2: MajorDeltaCompactionOp(baa675bd850e4ed0a7b285047773da1a) complete. Timing: real 0.760s	user 0.444s	sys 0.316s Metrics: {"cfile_cache_miss":3244,"cfile_cache_miss_bytes":135541274,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":14,"delta_iterators_relevant":14,"dirs.queue_time_us":1163,"lbm_read_time_us":55318,"lbm_reads_lt_1ms":3272,"lbm_write_time_us":134547,"lbm_writes_lt_1ms":3246,"mutex_wait_us":90,"peak_mem_usage":398633344,"reinsert_count":0,"spinlock_wait_cycles":27392,"thread_start_us":452,"threads_started":7,"update_count":16000}
I20260812 06:16:49.604885  2976 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:49.605195  2976 tablet_replica.cc:333] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2: stopping tablet replica
I20260812 06:16:49.605338  2976 raft_consensus.cc:2243] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:49.640009  2976 raft_consensus.cc:2272] T baa675bd850e4ed0a7b285047773da1a P de4291e3a075466182606eb3a2017fb2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:49.659060  2976 tablet_server.cc:196] TabletServer@127.2.232.1:0 shutdown complete.
I20260812 06:16:50.080084  2976 master.cc:562] Master@127.2.232.62:45069 shutting down...
I20260812 06:16:50.084172  2976 raft_consensus.cc:2243] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:50.084348  2976 raft_consensus.cc:2272] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:50.084405  2976 tablet_replica.cc:333] T 00000000000000000000000000000000 P b4751e2db8bb4fa5a82dfbf991a18817: stopping tablet replica
I20260812 06:16:50.096956  2976 master.cc:584] Master@127.2.232.62:45069 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6183 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12842 ms total)

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