[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:17:49.569540  7515 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.7.86.254:41729
I20260812 06:17:49.570722  7515 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:17:49.571434  7515 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:49.578856  7521 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:17:49.578765  7524 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:49.579159  7522 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:49.579164  7515 server_base.cc:1061] running on GCE node
I20260812 06:17:49.579870  7515 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:49.579989  7515 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:49.580021  7515 hybrid_clock.cc:648] HybridClock initialized: now 1786515469580020 us; error 0 us; skew 500 ppm
I20260812 06:17:49.582994  7515 webserver.cc:533] Webserver started at http://127.7.86.254:39673/ using document root <none> and password file <none>
I20260812 06:17:49.583679  7515 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:49.583747  7515 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:49.583969  7515 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:49.585963  7515 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/master-0-root/instance:
uuid: "0604b8f6209d4b549939af20f9584d44"
format_stamp: "Formatted at 2026-08-12 06:17:49 on dist-test-slave-vxj2"
I20260812 06:17:49.590015  7515 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.003s	sys 0.000s
I20260812 06:17:49.592377  7531 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:49.593680  7515 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:49.593799  7515 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/master-0-root
uuid: "0604b8f6209d4b549939af20f9584d44"
format_stamp: "Formatted at 2026-08-12 06:17:49 on dist-test-slave-vxj2"
I20260812 06:17:49.593888  7515 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:49.615597  7515 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:49.616328  7515 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:17:49.616477  7515 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:49.625351  7515 rpc_server.cc:307] RPC server started. Bound to: 127.7.86.254:41729
I20260812 06:17:49.625385  7597 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.86.254:41729 every 8 connection(s)
I20260812 06:17:49.627933  7598 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:49.633960  7598 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44: Bootstrap starting.
I20260812 06:17:49.636663  7598 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:49.637843  7598 log.cc:826] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:49.639899  7598 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44: No bootstrap required, opened a new log
I20260812 06:17:49.642980  7598 raft_consensus.cc:359] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0604b8f6209d4b549939af20f9584d44" member_type: VOTER }
I20260812 06:17:49.643306  7598 raft_consensus.cc:385] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:49.643412  7598 raft_consensus.cc:740] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0604b8f6209d4b549939af20f9584d44, State: Initialized, Role: FOLLOWER
I20260812 06:17:49.644121  7598 consensus_queue.cc:260] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44 [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: "0604b8f6209d4b549939af20f9584d44" member_type: VOTER }
I20260812 06:17:49.644338  7598 raft_consensus.cc:399] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:49.644426  7598 raft_consensus.cc:493] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:49.644586  7598 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:49.645637  7598 raft_consensus.cc:515] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0604b8f6209d4b549939af20f9584d44" member_type: VOTER }
I20260812 06:17:49.646327  7598 leader_election.cc:304] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44 [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: 0604b8f6209d4b549939af20f9584d44; no voters: 
I20260812 06:17:49.646827  7598 leader_election.cc:290] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:49.647359  7601 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:49.647646  7601 raft_consensus.cc:697] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44 [term 1 LEADER]: Becoming Leader. State: Replica: 0604b8f6209d4b549939af20f9584d44, State: Running, Role: LEADER
I20260812 06:17:49.648104  7598 sys_catalog.cc:565] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:49.648082  7601 consensus_queue.cc:237] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44 [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: "0604b8f6209d4b549939af20f9584d44" member_type: VOTER }
I20260812 06:17:49.650593  7515 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:49.650813  7604 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 0604b8f6209d4b549939af20f9584d44. Latest consensus state: current_term: 1 leader_uuid: "0604b8f6209d4b549939af20f9584d44" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0604b8f6209d4b549939af20f9584d44" member_type: VOTER } }
I20260812 06:17:49.650880  7603 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "0604b8f6209d4b549939af20f9584d44" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0604b8f6209d4b549939af20f9584d44" member_type: VOTER } }
I20260812 06:17:49.650954  7604 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:49.651013  7603 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44 [sys.catalog]: This master's current role is: LEADER
W20260812 06:17:49.653142  7621 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:17:49.653264  7621 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:17:49.653398  7623 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:49.654397  7623 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:49.659659  7623 catalog_manager.cc:1383] Generated new cluster ID: 13b7ce02f83e4610b60462ebc6237340
I20260812 06:17:49.659749  7623 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:49.668113  7623 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:49.669081  7623 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:49.675921  7623 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44: Generated new TSK 0
I20260812 06:17:49.676653  7623 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:49.683704  7515 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:49.686702  7631 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:49.686807  7630 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:17:49.686820  7635 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:49.687005  7515 server_base.cc:1061] running on GCE node
I20260812 06:17:49.687505  7515 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:49.687580  7515 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:49.687605  7515 hybrid_clock.cc:648] HybridClock initialized: now 1786515469687605 us; error 0 us; skew 500 ppm
I20260812 06:17:49.688680  7515 webserver.cc:533] Webserver started at http://127.7.86.193:43085/ using document root <none> and password file <none>
I20260812 06:17:49.688868  7515 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:49.688942  7515 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:49.689028  7515 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:49.689528  7515 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/instance:
uuid: "acc12238dcae4a42879eac025c9f6772"
format_stamp: "Formatted at 2026-08-12 06:17:49 on dist-test-slave-vxj2"
I20260812 06:17:49.691579  7515 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:49.692873  7642 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:49.693228  7515 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.001s
I20260812 06:17:49.693312  7515 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root
uuid: "acc12238dcae4a42879eac025c9f6772"
format_stamp: "Formatted at 2026-08-12 06:17:49 on dist-test-slave-vxj2"
I20260812 06:17:49.693423  7515 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:49.726842  7515 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:49.727416  7515 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:49.728048  7515 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:49.728987  7515 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:49.729041  7515 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:49.729116  7515 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:49.729212  7515 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:49.736296  7515 rpc_server.cc:307] RPC server started. Bound to: 127.7.86.193:45247
I20260812 06:17:49.736317  7715 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.86.193:45247 every 8 connection(s)
I20260812 06:17:49.753526  7716 heartbeater.cc:344] Connected to a master server at 127.7.86.254:41729
I20260812 06:17:49.753947  7716 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:49.754499  7716 heartbeater.cc:507] Master 127.7.86.254:41729 requested a full tablet report, sending...
I20260812 06:17:49.756183  7551 ts_manager.cc:194] Registered new tserver with Master: acc12238dcae4a42879eac025c9f6772 (127.7.86.193:45247)
I20260812 06:17:49.756309  7515 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.019280691s
I20260812 06:17:49.757618  7551 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:58314
I20260812 06:17:49.771266  7551 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:58326:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:49.788254  7673 tablet_service.cc:1511] Processing CreateTablet for tablet f1c5b4d7f7fb48638440437590eb02c9 (DEFAULT_TABLE table=heavy-update-compaction-test [id=6c732fabe4de49c6aad0abfa3b853ea5]), partition=
I20260812 06:17:49.788887  7673 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f1c5b4d7f7fb48638440437590eb02c9. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:49.791779  7729 tablet_bootstrap.cc:492] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Bootstrap starting.
I20260812 06:17:49.793643  7729 tablet_bootstrap.cc:654] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:49.796283  7729 tablet_bootstrap.cc:492] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: No bootstrap required, opened a new log
I20260812 06:17:49.796461  7729 ts_tablet_manager.cc:1403] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Time spent bootstrapping tablet: real 0.005s	user 0.003s	sys 0.000s
I20260812 06:17:49.797226  7729 raft_consensus.cc:359] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "acc12238dcae4a42879eac025c9f6772" member_type: VOTER last_known_addr { host: "127.7.86.193" port: 45247 } }
I20260812 06:17:49.797401  7729 raft_consensus.cc:385] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:49.797459  7729 raft_consensus.cc:740] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: acc12238dcae4a42879eac025c9f6772, State: Initialized, Role: FOLLOWER
I20260812 06:17:49.797626  7729 consensus_queue.cc:260] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772 [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: "acc12238dcae4a42879eac025c9f6772" member_type: VOTER last_known_addr { host: "127.7.86.193" port: 45247 } }
I20260812 06:17:49.797752  7729 raft_consensus.cc:399] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:49.797816  7729 raft_consensus.cc:493] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:49.797878  7729 raft_consensus.cc:3060] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:49.799206  7729 raft_consensus.cc:515] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "acc12238dcae4a42879eac025c9f6772" member_type: VOTER last_known_addr { host: "127.7.86.193" port: 45247 } }
I20260812 06:17:49.799402  7729 leader_election.cc:304] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772 [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: acc12238dcae4a42879eac025c9f6772; no voters: 
I20260812 06:17:49.799736  7729 leader_election.cc:290] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:49.799989  7732 raft_consensus.cc:2804] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:49.800288  7729 ts_tablet_manager.cc:1434] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Time spent starting tablet: real 0.004s	user 0.005s	sys 0.000s
I20260812 06:17:49.800263  7732 raft_consensus.cc:697] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772 [term 1 LEADER]: Becoming Leader. State: Replica: acc12238dcae4a42879eac025c9f6772, State: Running, Role: LEADER
I20260812 06:17:49.800830  7716 heartbeater.cc:499] Master 127.7.86.254:41729 was elected leader, sending a full tablet report...
I20260812 06:17:49.800796  7732 consensus_queue.cc:237] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772 [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: "acc12238dcae4a42879eac025c9f6772" member_type: VOTER last_known_addr { host: "127.7.86.193" port: 45247 } }
I20260812 06:17:49.804035  7551 catalog_manager.cc:5719] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772 reported cstate change: term changed from 0 to 1, leader changed from <none> to acc12238dcae4a42879eac025c9f6772 (127.7.86.193). New cstate: current_term: 1 leader_uuid: "acc12238dcae4a42879eac025c9f6772" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "acc12238dcae4a42879eac025c9f6772" member_type: VOTER last_known_addr { host: "127.7.86.193" port: 45247 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:49.897689  7515 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.086s	user 0.021s	sys 0.016s
I20260812 06:17:49.987545  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushMRSOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=10.125253
I20260812 06:17:50.160985  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushMRSOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.173s	user 0.137s	sys 0.020s Metrics: {"bytes_written":8205078,"cfile_init":1,"compiler_manager_pool.queue_time_us":247,"delete_count":0,"dirs.queue_time_us":100,"dirs.run_cpu_time_us":419,"dirs.run_wall_time_us":1333,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":48091,"lbm_writes_lt_1ms":457,"peak_mem_usage":0,"reinsert_count":0,"rows_written":102,"thread_start_us":136,"threads_started":1,"update_count":1000}
I20260812 06:17:50.162415  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling LogGCOp(f1c5b4d7f7fb48638440437590eb02c9): free 8725963 bytes of WAL
I20260812 06:17:50.162758  7647 log_reader.cc:385] T f1c5b4d7f7fb48638440437590eb02c9: removed 1 log segments from log reader
I20260812 06:17:50.162824  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000001 (ops 1-6)
I20260812 06:17:50.165264  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: LogGCOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.003s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:50.165656  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=2.188937
I20260812 06:17:50.189597  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.024s	user 0.009s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8283,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.190182  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling UndoDeltaBlockGCOp(f1c5b4d7f7fb48638440437590eb02c9): 8206537 bytes on disk
I20260812 06:17:50.190948  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: UndoDeltaBlockGCOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:17:50.191476  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=1.000000
I20260812 06:17:50.335706  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.144s	user 0.093s	sys 0.047s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16487935,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":545,"lbm_read_time_us":7352,"lbm_reads_lt_1ms":360,"lbm_write_time_us":38656,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":342,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":391,"threads_started":5,"update_count":1500}
I20260812 06:17:50.336225  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=10.126437
I20260812 06:17:50.395320  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.059s	user 0.034s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":24647,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:50.395881  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=2.188937
I20260812 06:17:50.412245  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7120,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.412711  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=1.000000
I20260812 06:17:50.599844  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.187s	user 0.123s	sys 0.054s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":215,"lbm_read_time_us":9661,"lbm_reads_lt_1ms":464,"lbm_write_time_us":47877,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2000}
I20260812 06:17:50.600451  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=14.095187
I20260812 06:17:50.676496  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.076s	user 0.033s	sys 0.039s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":36738,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:50.677280  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=2.188937
I20260812 06:17:50.706928  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.029s	user 0.006s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8201,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.707458  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=2.188937
I20260812 06:17:50.719867  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4948,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.720463  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=1.000000
I20260812 06:17:50.986718  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.266s	user 0.178s	sys 0.087s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28795290,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1364,"lbm_read_time_us":15321,"lbm_reads_lt_1ms":673,"lbm_write_time_us":61596,"lbm_writes_lt_1ms":643,"mutex_wait_us":465,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":273920,"update_count":3000}
I20260812 06:17:50.987317  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=14.095187
I20260812 06:17:51.048100  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.061s	user 0.032s	sys 0.025s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":26420,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:51.048698  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=1.000000
I20260812 06:17:51.237432  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.189s	user 0.113s	sys 0.069s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20590224,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":4887,"lbm_read_time_us":10482,"lbm_reads_lt_1ms":463,"lbm_write_time_us":35200,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":4229,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:51.238113  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=11.118625
I20260812 06:17:51.289738  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.051s	user 0.027s	sys 0.024s Metrics: {"bytes_written":13456167,"delete_count":0,"lbm_write_time_us":29204,"lbm_writes_lt_1ms":331,"reinsert_count":0,"update_count":1640}
I20260812 06:17:51.290344  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=2.188937
I20260812 06:17:51.302860  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3364209,"delete_count":0,"lbm_write_time_us":4680,"lbm_writes_lt_1ms":85,"reinsert_count":0,"update_count":410}
I20260812 06:17:51.303354  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=2.188937
I20260812 06:17:51.317967  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.014s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6294,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:51.318549  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=1.000000
I20260812 06:17:51.526019  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.207s	user 0.139s	sys 0.061s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24692851,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":624,"lbm_read_time_us":12038,"lbm_reads_lt_1ms":573,"lbm_write_time_us":37675,"lbm_writes_lt_1ms":543,"mutex_wait_us":94,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2500}
I20260812 06:17:51.526829  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=11.118625
I20260812 06:17:51.582063  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.055s	user 0.041s	sys 0.012s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":28354,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:51.582844  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=2.188937
I20260812 06:17:51.607597  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.024s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6831,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.608151  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=2.188937
I20260812 06:17:51.621635  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.013s	user 0.002s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5442,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:51.622324  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=1.000000
I20260812 06:17:51.814051  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.191s	user 0.136s	sys 0.050s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24692870,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":380,"lbm_read_time_us":11231,"lbm_reads_lt_1ms":573,"lbm_write_time_us":47674,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:17:51.814810  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=10.126437
I20260812 06:17:51.874001  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.059s	user 0.035s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":26584,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:51.874543  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=2.188937
I20260812 06:17:51.886982  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.012s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4713,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.887697  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushMRSOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=1.000000
I20260812 06:17:51.927268  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushMRSOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.039s	user 0.029s	sys 0.006s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":111,"dirs.run_cpu_time_us":274,"dirs.run_wall_time_us":1557,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1909,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:51.928304  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling LogGCOp(f1c5b4d7f7fb48638440437590eb02c9): free 132118261 bytes of WAL
I20260812 06:17:51.928623  7647 log_reader.cc:385] T f1c5b4d7f7fb48638440437590eb02c9: removed 13 log segments from log reader
I20260812 06:17:51.928709  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000002 (ops 7-11)
I20260812 06:17:51.928838  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000003 (ops 12-16)
I20260812 06:17:51.928901  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000004 (ops 17-20)
I20260812 06:17:51.928946  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000005 (ops 21-25)
I20260812 06:17:51.928984  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000006 (ops 26-30)
I20260812 06:17:51.929025  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000007 (ops 31-35)
I20260812 06:17:51.929071  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000008 (ops 36-40)
I20260812 06:17:51.929109  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000009 (ops 41-45)
I20260812 06:17:51.929167  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000010 (ops 46-50)
I20260812 06:17:51.929211  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000011 (ops 51-54)
I20260812 06:17:51.929250  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000012 (ops 55-59)
I20260812 06:17:51.929276  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000013 (ops 60-64)
I20260812 06:17:51.929314  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000014 (ops 65-68)
I20260812 06:17:51.962700  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: LogGCOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.034s	user 0.002s	sys 0.030s Metrics: {}
I20260812 06:17:51.963369  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling UndoDeltaBlockGCOp(f1c5b4d7f7fb48638440437590eb02c9): 483 bytes on disk
I20260812 06:17:51.964301  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: UndoDeltaBlockGCOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:17:51.964833  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=3.181125
I20260812 06:17:51.980610  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.016s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5392,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:51.981338  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=2.188937
I20260812 06:17:51.993425  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4138,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:51.994063  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=1.000000
I20260812 06:17:52.230911  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.237s	user 0.146s	sys 0.079s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28795398,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":622,"lbm_read_time_us":16334,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36531,"lbm_writes_lt_1ms":643,"mutex_wait_us":26,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9088,"thread_start_us":100,"threads_started":1,"update_count":3000}
I20260812 06:17:52.231725  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=14.095187
I20260812 06:17:52.294142  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.062s	user 0.044s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25028,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:52.294862  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=2.188937
I20260812 06:17:52.306159  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4296,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.306716  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=1.000000
I20260812 06:17:52.491376  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.184s	user 0.114s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692758,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":502,"lbm_read_time_us":11435,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32359,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:17:52.496826  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=11.118625
I20260812 06:17:52.530071  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.033s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13946,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:52.530728  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=2.188937
I20260812 06:17:52.545249  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5228,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:52.545735  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=1.000000
I20260812 06:17:52.675815  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.130s	user 0.115s	sys 0.013s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":311,"lbm_read_time_us":8256,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24895,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:17:52.676491  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=10.126437
I20260812 06:17:52.716934  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.040s	user 0.019s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16949,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:52.717542  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=1.000000
I20260812 06:17:52.841329  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.124s	user 0.062s	sys 0.061s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16487816,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":213,"lbm_read_time_us":6383,"lbm_reads_lt_1ms":363,"lbm_write_time_us":26719,"lbm_writes_lt_1ms":343,"mutex_wait_us":71,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":1500}
I20260812 06:17:52.842051  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=10.126437
I20260812 06:17:52.889812  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.047s	user 0.035s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":22978,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:52.890378  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=2.188937
I20260812 06:17:52.903456  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4848,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.903959  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=1.000000
I20260812 06:17:53.047151  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.143s	user 0.116s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":217,"lbm_read_time_us":9204,"lbm_reads_lt_1ms":472,"lbm_write_time_us":31876,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21632,"update_count":2000}
I20260812 06:17:53.047742  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=10.126437
I20260812 06:17:53.092857  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.045s	user 0.015s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17782,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:53.093660  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=1.000000
I20260812 06:17:53.231269  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.137s	user 0.085s	sys 0.052s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16487816,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":268,"lbm_read_time_us":8873,"lbm_reads_lt_1ms":363,"lbm_write_time_us":31611,"lbm_writes_lt_1ms":343,"mutex_wait_us":24,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":18048,"update_count":1500}
I20260812 06:17:53.231980  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=10.126437
I20260812 06:17:53.288079  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.056s	user 0.032s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19345,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:53.288818  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=2.188937
I20260812 06:17:53.307091  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.018s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6839,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.307744  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=1.000000
I20260812 06:17:53.481503  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.174s	user 0.135s	sys 0.038s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":290,"lbm_read_time_us":11676,"lbm_reads_lt_1ms":472,"lbm_write_time_us":42518,"lbm_writes_lt_1ms":443,"mutex_wait_us":63,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:17:53.482239  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=10.126437
I20260812 06:17:53.533257  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.051s	user 0.041s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":23579,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":1500}
I20260812 06:17:53.534754  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=2.188937
I20260812 06:17:53.570124  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.035s	user 0.016s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5508,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.570844  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=2.188937
I20260812 06:17:53.583676  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.013s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4961,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.584697  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushMRSOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=1.000000
I20260812 06:17:53.620009  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushMRSOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.035s	user 0.030s	sys 0.003s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":104,"dirs.run_cpu_time_us":319,"dirs.run_wall_time_us":1757,"drs_written":1,"lbm_read_time_us":168,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1593,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:53.621075  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling UndoDeltaBlockGCOp(f1c5b4d7f7fb48638440437590eb02c9): 472 bytes on disk
I20260812 06:17:53.621626  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: UndoDeltaBlockGCOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:17:53.622287  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=1.000000
I20260812 06:17:53.829533  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.207s	user 0.127s	sys 0.076s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24692877,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":444,"lbm_read_time_us":14720,"lbm_reads_lt_1ms":565,"lbm_write_time_us":48090,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:53.830188  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling LogGCOp(f1c5b4d7f7fb48638440437590eb02c9): free 120553380 bytes of WAL
I20260812 06:17:53.830518  7647 log_reader.cc:385] T f1c5b4d7f7fb48638440437590eb02c9: removed 12 log segments from log reader
I20260812 06:17:53.830585  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000015 (ops 69-73)
I20260812 06:17:53.830644  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000016 (ops 74-78)
I20260812 06:17:53.830682  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000017 (ops 79-82)
I20260812 06:17:53.830720  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000018 (ops 83-87)
I20260812 06:17:53.830757  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000019 (ops 88-92)
I20260812 06:17:53.830803  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000020 (ops 93-97)
I20260812 06:17:53.830840  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000021 (ops 98-102)
I20260812 06:17:53.830876  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000022 (ops 103-107)
I20260812 06:17:53.830912  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000023 (ops 108-112)
I20260812 06:17:53.830955  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000024 (ops 113-116)
I20260812 06:17:53.830992  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000025 (ops 117-121)
I20260812 06:17:53.831029  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000026 (ops 122-126)
I20260812 06:17:53.862764  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: LogGCOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.032s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:53.865471  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=18.063937
I20260812 06:17:53.938055  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.072s	user 0.034s	sys 0.035s Metrics: {"bytes_written":20102079,"delete_count":0,"lbm_write_time_us":27986,"lbm_writes_lt_1ms":493,"reinsert_count":0,"update_count":2450}
I20260812 06:17:53.938735  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=3.181125
I20260812 06:17:53.952165  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4512906,"delete_count":0,"lbm_write_time_us":5093,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:53.952713  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=1.000000
I20260812 06:17:54.164564  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.212s	user 0.142s	sys 0.061s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28795183,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":365,"lbm_read_time_us":16496,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":671,"lbm_write_time_us":34879,"lbm_writes_lt_1ms":643,"mutex_wait_us":83,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":25728,"update_count":3000}
I20260812 06:17:54.165392  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=14.095187
I20260812 06:17:54.239377  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.074s	user 0.032s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25244,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:54.240125  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=2.188937
I20260812 06:17:54.251768  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4341,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.252467  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=1.000000
I20260812 06:17:54.447788  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.195s	user 0.138s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692758,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":579,"lbm_read_time_us":13082,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32704,"lbm_writes_lt_1ms":543,"mutex_wait_us":308,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:17:54.448559  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=10.126437
I20260812 06:17:54.484268  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.035s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14803,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:54.484983  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=2.188937
I20260812 06:17:54.503362  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.018s	user 0.009s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7276,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.503939  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=1.000000
I20260812 06:17:54.656243  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.152s	user 0.096s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590348,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":219,"lbm_read_time_us":10225,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23998,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17408,"update_count":2000}
I20260812 06:17:54.657212  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=10.126437
I20260812 06:17:54.707700  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.050s	user 0.031s	sys 0.009s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":19765,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:54.708408  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=2.188937
I20260812 06:17:54.722499  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.014s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4886,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.723242  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=1.000000
I20260812 06:17:54.876839  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.153s	user 0.129s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590350,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1120,"lbm_read_time_us":8491,"lbm_reads_lt_1ms":472,"lbm_write_time_us":41241,"lbm_writes_lt_1ms":443,"mutex_wait_us":292,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2000}
I20260812 06:17:54.877717  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=10.126437
I20260812 06:17:54.929613  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.052s	user 0.024s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":26734,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:54.930245  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=2.188937
I20260812 06:17:54.943406  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4459,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.944003  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=1.000000
I20260812 06:17:55.096223  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.152s	user 0.108s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":388,"lbm_read_time_us":9919,"lbm_reads_lt_1ms":472,"lbm_write_time_us":40218,"lbm_writes_lt_1ms":443,"mutex_wait_us":89,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2000}
I20260812 06:17:55.097129  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=10.126437
I20260812 06:17:55.156615  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.059s	user 0.033s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":27122,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:55.157441  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=2.188937
I20260812 06:17:55.170267  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4461,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.170943  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=1.000000
I20260812 06:17:55.333855  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.163s	user 0.095s	sys 0.068s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590348,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":272,"lbm_read_time_us":11827,"lbm_reads_lt_1ms":472,"lbm_write_time_us":33255,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":72,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2000}
I20260812 06:17:55.334864  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=10.126437
I20260812 06:17:55.386950  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.052s	user 0.034s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":25236,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:55.387631  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=2.188937
I20260812 06:17:55.409789  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.022s	user 0.008s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6210,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.410352  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushMRSOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=1.000000
I20260812 06:17:55.465801  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushMRSOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.055s	user 0.034s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":90,"dirs.run_cpu_time_us":291,"dirs.run_wall_time_us":1769,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2865,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:55.466791  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling LogGCOp(f1c5b4d7f7fb48638440437590eb02c9): free 129320722 bytes of WAL
I20260812 06:17:55.467105  7647 log_reader.cc:385] T f1c5b4d7f7fb48638440437590eb02c9: removed 13 log segments from log reader
I20260812 06:17:55.467185  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000027 (ops 127-131)
I20260812 06:17:55.467240  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000028 (ops 132-136)
I20260812 06:17:55.467301  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000029 (ops 137-141)
I20260812 06:17:55.467344  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000030 (ops 142-146)
I20260812 06:17:55.467386  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000031 (ops 147-150)
I20260812 06:17:55.467420  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000032 (ops 151-155)
I20260812 06:17:55.467458  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000033 (ops 156-160)
I20260812 06:17:55.467495  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000034 (ops 161-164)
I20260812 06:17:55.467535  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000035 (ops 165-169)
I20260812 06:17:55.467572  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000036 (ops 170-174)
I20260812 06:17:55.467608  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000037 (ops 175-179)
I20260812 06:17:55.467646  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000038 (ops 180-184)
I20260812 06:17:55.467684  7647 log.cc:1079] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/f1c5b4d7f7fb48638440437590eb02c9/wal-000000039 (ops 185-189)
I20260812 06:17:55.497460  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: LogGCOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.030s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:55.503002  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling UndoDeltaBlockGCOp(f1c5b4d7f7fb48638440437590eb02c9): 492 bytes on disk
I20260812 06:17:55.503552  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: UndoDeltaBlockGCOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":93,"lbm_reads_lt_1ms":4}
I20260812 06:17:55.504431  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=6.157687
I20260812 06:17:55.532166  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.028s	user 0.025s	sys 0.000s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":11959,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:55.532757  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=2.188937
I20260812 06:17:55.544576  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4312,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.545337  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=1.000000
I20260812 06:17:55.686578  7515 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.789s	user 2.052s	sys 0.178s
I20260812 06:17:55.764300  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: MajorDeltaCompactionOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.219s	user 0.144s	sys 0.068s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32897823,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":21102,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":769,"lbm_write_time_us":37140,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3500}
I20260812 06:17:55.764884  7717 maintenance_manager.cc:419] P acc12238dcae4a42879eac025c9f6772: Scheduling FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9): perf score=10.126437
I20260812 06:17:55.787773  7515 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.100s	user 0.002s	sys 0.000s
I20260812 06:17:55.790377  7515 tablet_server.cc:179] TabletServer@127.7.86.193:0 shutting down...
I20260812 06:17:55.811468  7647 maintenance_manager.cc:643] P acc12238dcae4a42879eac025c9f6772: FlushDeltaMemStoresOp(f1c5b4d7f7fb48638440437590eb02c9) complete. Timing: real 0.046s	user 0.021s	sys 0.023s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17038,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:55.812306  7515 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:55.812727  7515 tablet_replica.cc:333] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772: stopping tablet replica
I20260812 06:17:55.812980  7515 raft_consensus.cc:2243] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:55.813261  7515 raft_consensus.cc:2272] T f1c5b4d7f7fb48638440437590eb02c9 P acc12238dcae4a42879eac025c9f6772 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:55.829355  7515 tablet_server.cc:196] TabletServer@127.7.86.193:0 shutdown complete.
I20260812 06:17:55.835357  7515 master.cc:562] Master@127.7.86.254:41729 shutting down...
I20260812 06:17:55.839610  7515 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:55.839854  7515 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:55.839963  7515 tablet_replica.cc:333] T 00000000000000000000000000000000 P 0604b8f6209d4b549939af20f9584d44: stopping tablet replica
I20260812 06:17:55.853130  7515 master.cc:584] Master@127.7.86.254:41729 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6380 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:55.949942  7515 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.7.86.254:38315
I20260812 06:17:55.950382  7515 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:55.954116  7758 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:55.954124  7754 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:17:55.954317  7756 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:55.954136  7515 server_base.cc:1061] running on GCE node
I20260812 06:17:55.954551  7515 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:55.954595  7515 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:55.954612  7515 hybrid_clock.cc:648] HybridClock initialized: now 1786515475954612 us; error 0 us; skew 500 ppm
I20260812 06:17:55.955483  7515 webserver.cc:533] Webserver started at http://127.7.86.254:37719/ using document root <none> and password file <none>
I20260812 06:17:55.955694  7515 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:55.955735  7515 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:55.955799  7515 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:55.956179  7515 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/master-0-root/instance:
uuid: "12cc8b832c734adb861b494980b7413c"
format_stamp: "Formatted at 2026-08-12 06:17:55 on dist-test-slave-vxj2"
I20260812 06:17:55.958086  7515 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:55.959295  7765 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:55.959826  7515 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:55.959929  7515 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/master-0-root
uuid: "12cc8b832c734adb861b494980b7413c"
format_stamp: "Formatted at 2026-08-12 06:17:55 on dist-test-slave-vxj2"
I20260812 06:17:55.960135  7515 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:55.974887  7515 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:55.975435  7515 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:55.981572  7515 rpc_server.cc:307] RPC server started. Bound to: 127.7.86.254:38315
I20260812 06:17:55.984481  7827 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:55.987187  7826 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.86.254:38315 every 8 connection(s)
I20260812 06:17:55.991851  7827 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c: Bootstrap starting.
I20260812 06:17:55.995101  7827 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:55.996382  7827 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c: No bootstrap required, opened a new log
I20260812 06:17:55.996891  7827 raft_consensus.cc:359] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "12cc8b832c734adb861b494980b7413c" member_type: VOTER }
I20260812 06:17:55.997023  7827 raft_consensus.cc:385] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:55.997071  7827 raft_consensus.cc:740] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 12cc8b832c734adb861b494980b7413c, State: Initialized, Role: FOLLOWER
I20260812 06:17:55.997309  7827 consensus_queue.cc:260] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c [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: "12cc8b832c734adb861b494980b7413c" member_type: VOTER }
I20260812 06:17:55.997435  7827 raft_consensus.cc:399] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:55.997481  7827 raft_consensus.cc:493] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:55.997540  7827 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:55.998546  7827 raft_consensus.cc:515] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "12cc8b832c734adb861b494980b7413c" member_type: VOTER }
I20260812 06:17:55.998728  7827 leader_election.cc:304] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c [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: 12cc8b832c734adb861b494980b7413c; no voters: 
I20260812 06:17:55.998977  7827 leader_election.cc:290] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:55.999203  7833 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:55.999493  7833 raft_consensus.cc:697] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c [term 1 LEADER]: Becoming Leader. State: Replica: 12cc8b832c734adb861b494980b7413c, State: Running, Role: LEADER
I20260812 06:17:55.999660  7833 consensus_queue.cc:237] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c [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: "12cc8b832c734adb861b494980b7413c" member_type: VOTER }
I20260812 06:17:55.999711  7827 sys_catalog.cc:565] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:56.000233  7834 sys_catalog.cc:455] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "12cc8b832c734adb861b494980b7413c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "12cc8b832c734adb861b494980b7413c" member_type: VOTER } }
I20260812 06:17:56.000260  7835 sys_catalog.cc:455] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c [sys.catalog]: SysCatalogTable state changed. Reason: New leader 12cc8b832c734adb861b494980b7413c. Latest consensus state: current_term: 1 leader_uuid: "12cc8b832c734adb861b494980b7413c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "12cc8b832c734adb861b494980b7413c" member_type: VOTER } }
I20260812 06:17:56.000396  7835 sys_catalog.cc:458] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:56.000660  7834 sys_catalog.cc:458] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:56.000710  7838 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:56.001806  7838 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:56.002096  7515 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:56.004102  7838 catalog_manager.cc:1383] Generated new cluster ID: b86cd46a536c42469c0e418f1f557fda
I20260812 06:17:56.004176  7838 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:56.016335  7838 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:56.016943  7838 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:56.025738  7838 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c: Generated new TSK 0
I20260812 06:17:56.026007  7838 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:56.035064  7515 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:56.037500  7857 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:56.037628  7861 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:56.037647  7515 server_base.cc:1061] running on GCE node
W20260812 06:17:56.037500  7856 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:56.038003  7515 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:56.038051  7515 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:56.038069  7515 hybrid_clock.cc:648] HybridClock initialized: now 1786515476038068 us; error 0 us; skew 500 ppm
I20260812 06:17:56.039057  7515 webserver.cc:533] Webserver started at http://127.7.86.193:40345/ using document root <none> and password file <none>
I20260812 06:17:56.039280  7515 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:56.039336  7515 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:56.039466  7515 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:56.039929  7515 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/instance:
uuid: "fd98dd20984645169b41b531c5d82d59"
format_stamp: "Formatted at 2026-08-12 06:17:56 on dist-test-slave-vxj2"
I20260812 06:17:56.042052  7515 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:56.043785  7866 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:56.044406  7515 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:56.044589  7515 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root
uuid: "fd98dd20984645169b41b531c5d82d59"
format_stamp: "Formatted at 2026-08-12 06:17:56 on dist-test-slave-vxj2"
I20260812 06:17:56.044726  7515 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:56.058532  7515 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:56.059083  7515 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:56.059478  7515 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:56.060043  7515 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:56.060113  7515 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:56.060187  7515 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:56.060246  7515 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:56.066075  7515 rpc_server.cc:307] RPC server started. Bound to: 127.7.86.193:37251
I20260812 06:17:56.066242  7946 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.86.193:37251 every 8 connection(s)
I20260812 06:17:56.078141  7947 heartbeater.cc:344] Connected to a master server at 127.7.86.254:38315
I20260812 06:17:56.078329  7947 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:56.078756  7947 heartbeater.cc:507] Master 127.7.86.254:38315 requested a full tablet report, sending...
I20260812 06:17:56.079825  7787 ts_manager.cc:194] Registered new tserver with Master: fd98dd20984645169b41b531c5d82d59 (127.7.86.193:37251)
I20260812 06:17:56.080751  7787 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:46246
I20260812 06:17:56.080978  7515 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014291757s
I20260812 06:17:56.091301  7787 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:46258:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:56.103682  7901 tablet_service.cc:1511] Processing CreateTablet for tablet efe4492b6b3c42849778958694e4d72f (DEFAULT_TABLE table=heavy-update-compaction-test [id=8eb1f778af3944539544ecaf00ffe01a]), partition=
I20260812 06:17:56.104149  7901 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet efe4492b6b3c42849778958694e4d72f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:56.106637  7962 tablet_bootstrap.cc:492] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Bootstrap starting.
I20260812 06:17:56.107753  7962 tablet_bootstrap.cc:654] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:56.109076  7962 tablet_bootstrap.cc:492] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: No bootstrap required, opened a new log
I20260812 06:17:56.109251  7962 ts_tablet_manager.cc:1403] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:56.109776  7962 raft_consensus.cc:359] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fd98dd20984645169b41b531c5d82d59" member_type: VOTER last_known_addr { host: "127.7.86.193" port: 37251 } }
I20260812 06:17:56.109874  7962 raft_consensus.cc:385] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:56.109897  7962 raft_consensus.cc:740] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: fd98dd20984645169b41b531c5d82d59, State: Initialized, Role: FOLLOWER
I20260812 06:17:56.110062  7962 consensus_queue.cc:260] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59 [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: "fd98dd20984645169b41b531c5d82d59" member_type: VOTER last_known_addr { host: "127.7.86.193" port: 37251 } }
I20260812 06:17:56.110139  7962 raft_consensus.cc:399] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:56.110194  7962 raft_consensus.cc:493] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:56.110251  7962 raft_consensus.cc:3060] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:56.111078  7962 raft_consensus.cc:515] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fd98dd20984645169b41b531c5d82d59" member_type: VOTER last_known_addr { host: "127.7.86.193" port: 37251 } }
I20260812 06:17:56.111287  7962 leader_election.cc:304] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59 [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: fd98dd20984645169b41b531c5d82d59; no voters: 
I20260812 06:17:56.111567  7962 leader_election.cc:290] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:56.111951  7962 ts_tablet_manager.cc:1434] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:56.111838  7965 raft_consensus.cc:2804] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:56.112346  7965 raft_consensus.cc:697] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59 [term 1 LEADER]: Becoming Leader. State: Replica: fd98dd20984645169b41b531c5d82d59, State: Running, Role: LEADER
I20260812 06:17:56.112421  7947 heartbeater.cc:499] Master 127.7.86.254:38315 was elected leader, sending a full tablet report...
I20260812 06:17:56.112520  7965 consensus_queue.cc:237] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59 [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: "fd98dd20984645169b41b531c5d82d59" member_type: VOTER last_known_addr { host: "127.7.86.193" port: 37251 } }
I20260812 06:17:56.114419  7787 catalog_manager.cc:5719] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59 reported cstate change: term changed from 0 to 1, leader changed from <none> to fd98dd20984645169b41b531c5d82d59 (127.7.86.193). New cstate: current_term: 1 leader_uuid: "fd98dd20984645169b41b531c5d82d59" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fd98dd20984645169b41b531c5d82d59" member_type: VOTER last_known_addr { host: "127.7.86.193" port: 37251 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:56.178066  7515 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.016s	sys 0.008s
I20260812 06:17:56.317338  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushMRSOp(efe4492b6b3c42849778958694e4d72f): perf score=15.086190
I20260812 06:17:56.464588  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushMRSOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.147s	user 0.091s	sys 0.052s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":218,"dirs.run_wall_time_us":1043,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36153,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"update_count":1500}
I20260812 06:17:56.465364  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling LogGCOp(efe4492b6b3c42849778958694e4d72f): free 8725963 bytes of WAL
I20260812 06:17:56.465590  7873 log_reader.cc:385] T efe4492b6b3c42849778958694e4d72f: removed 1 log segments from log reader
I20260812 06:17:56.465632  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000001 (ops 1-6)
I20260812 06:17:56.467484  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: LogGCOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:56.467857  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=2.188937
I20260812 06:17:56.482987  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5486,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.483672  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling UndoDeltaBlockGCOp(efe4492b6b3c42849778958694e4d72f): 12308958 bytes on disk
I20260812 06:17:56.485019  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: UndoDeltaBlockGCOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:17:56.485582  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f): perf score=1.000000
I20260812 06:17:56.654537  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.169s	user 0.130s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":660,"lbm_read_time_us":10452,"lbm_reads_lt_1ms":460,"lbm_write_time_us":29185,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14592,"thread_start_us":354,"threads_started":5,"update_count":2000}
I20260812 06:17:56.655208  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=14.095187
I20260812 06:17:56.707299  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.052s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22093,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:56.707996  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f): perf score=1.000000
I20260812 06:17:56.870405  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.162s	user 0.113s	sys 0.043s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631192,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":268,"lbm_read_time_us":11733,"lbm_reads_lt_1ms":463,"lbm_write_time_us":28579,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":45824,"update_count":2000}
I20260812 06:17:56.871381  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=11.118625
I20260812 06:17:56.910748  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.039s	user 0.014s	sys 0.024s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":17215,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:56.911392  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=2.188937
I20260812 06:17:56.932269  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.021s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5294,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:56.933049  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=2.188937
I20260812 06:17:56.949342  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6150,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.949966  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f): perf score=1.000000
I20260812 06:17:57.154910  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.205s	user 0.121s	sys 0.071s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733836,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":224,"lbm_read_time_us":12927,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29145,"lbm_writes_lt_1ms":543,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":84096,"update_count":2500}
I20260812 06:17:57.155583  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=14.095187
I20260812 06:17:57.216907  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.061s	user 0.031s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24436,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:57.217473  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=2.188937
I20260812 06:17:57.230792  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4585,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.231442  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f): perf score=1.000000
I20260812 06:17:57.402004  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.170s	user 0.147s	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":161,"lbm_read_time_us":12283,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33413,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:17:57.406139  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=10.126437
I20260812 06:17:57.441896  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.036s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12348515,"delete_count":0,"lbm_write_time_us":15371,"lbm_writes_lt_1ms":304,"reinsert_count":0,"update_count":1505}
I20260812 06:17:57.442589  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=2.188937
I20260812 06:17:57.459128  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4061634,"delete_count":0,"lbm_write_time_us":6002,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":495}
I20260812 06:17:57.459803  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f): perf score=1.000000
I20260812 06:17:57.595489  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.135s	user 0.102s	sys 0.032s 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":155,"lbm_read_time_us":8852,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26944,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:17:57.596274  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=10.126437
I20260812 06:17:57.640166  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.044s	user 0.030s	sys 0.007s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":17267,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:57.640736  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=2.188937
I20260812 06:17:57.654579  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4652,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.655314  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f): perf score=1.000000
I20260812 06:17:57.788468  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.133s	user 0.100s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631315,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":733,"lbm_read_time_us":8550,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24832,"lbm_writes_lt_1ms":443,"mutex_wait_us":61,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2000}
I20260812 06:17:57.789805  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=10.126437
I20260812 06:17:57.839423  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.049s	user 0.034s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16613,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:57.840098  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=2.188937
I20260812 06:17:57.851531  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4345,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.852083  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushMRSOp(efe4492b6b3c42849778958694e4d72f): perf score=1.000000
I20260812 06:17:57.901243  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushMRSOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.049s	user 0.033s	sys 0.004s Metrics: {"bytes_written":1234474,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":329,"dirs.run_wall_time_us":1707,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2107,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:57.902016  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling LogGCOp(efe4492b6b3c42849778958694e4d72f): free 132571301 bytes of WAL
I20260812 06:17:57.902302  7873 log_reader.cc:385] T efe4492b6b3c42849778958694e4d72f: removed 13 log segments from log reader
I20260812 06:17:57.902398  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000002 (ops 7-11)
I20260812 06:17:57.902452  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000003 (ops 12-16)
I20260812 06:17:57.902489  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000004 (ops 17-21)
I20260812 06:17:57.902514  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000005 (ops 22-26)
I20260812 06:17:57.902544  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000006 (ops 27-30)
I20260812 06:17:57.902565  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000007 (ops 31-35)
I20260812 06:17:57.902587  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000008 (ops 36-40)
I20260812 06:17:57.902619  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000009 (ops 41-45)
I20260812 06:17:57.902654  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000010 (ops 46-50)
I20260812 06:17:57.902683  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000011 (ops 51-55)
I20260812 06:17:57.902707  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000012 (ops 56-60)
I20260812 06:17:57.902737  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000013 (ops 61-64)
I20260812 06:17:57.902765  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000014 (ops 65-69)
I20260812 06:17:57.936467  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: LogGCOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.034s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:17:57.936998  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=2.188937
I20260812 06:17:57.962222  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.025s	user 0.010s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6310,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.962764  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling UndoDeltaBlockGCOp(efe4492b6b3c42849778958694e4d72f): 473 bytes on disk
I20260812 06:17:57.963202  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: UndoDeltaBlockGCOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:17:57.963652  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=2.188937
I20260812 06:17:57.974941  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4087,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.975603  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f): perf score=1.000000
I20260812 06:17:58.194898  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.219s	user 0.137s	sys 0.080s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836374,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":604,"lbm_read_time_us":15439,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34738,"lbm_writes_lt_1ms":643,"mutex_wait_us":331,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7424,"thread_start_us":107,"threads_started":1,"update_count":3000}
I20260812 06:17:58.195752  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=14.095187
I20260812 06:17:58.248323  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.052s	user 0.037s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23296,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:58.248946  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=2.188937
I20260812 06:17:58.261689  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4284,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.262301  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f): perf score=1.000000
I20260812 06:17:58.456437  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.194s	user 0.125s	sys 0.061s 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":448,"lbm_read_time_us":14022,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31635,"lbm_writes_lt_1ms":543,"mutex_wait_us":94,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:58.457227  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=14.095187
I20260812 06:17:58.518638  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.061s	user 0.032s	sys 0.024s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20552,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:58.519253  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=2.188937
I20260812 06:17:58.531298  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4641,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.531888  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f): perf score=1.000000
I20260812 06:17:58.722326  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.190s	user 0.126s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733726,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":779,"lbm_read_time_us":12899,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30171,"lbm_writes_lt_1ms":543,"mutex_wait_us":268,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2500}
I20260812 06:17:58.722985  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=14.095187
I20260812 06:17:58.794229  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.071s	user 0.031s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26453,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:58.795003  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=2.188937
I20260812 06:17:58.806562  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4525,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.807091  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f): perf score=1.000000
I20260812 06:17:59.005378  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.198s	user 0.120s	sys 0.067s 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":493,"lbm_read_time_us":13335,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30855,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2500}
I20260812 06:17:59.006131  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=14.095187
I20260812 06:17:59.061792  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.055s	user 0.035s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24497,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.062517  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=2.188937
I20260812 06:17:59.087234  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.024s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6221,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.087791  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f): perf score=1.000000
I20260812 06:17:59.290633  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.203s	user 0.153s	sys 0.047s 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":254,"lbm_read_time_us":14002,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33699,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2500}
I20260812 06:17:59.291363  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=14.095187
I20260812 06:17:59.349439  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.058s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20229,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.350034  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=2.188937
I20260812 06:17:59.363114  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.013s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4556,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.363842  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f): perf score=1.000000
I20260812 06:17:59.558017  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.194s	user 0.124s	sys 0.059s 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":682,"lbm_read_time_us":13327,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30338,"lbm_writes_lt_1ms":543,"mutex_wait_us":304,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16640,"update_count":2500}
I20260812 06:17:59.558696  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=14.095187
I20260812 06:17:59.613713  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.055s	user 0.027s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24231,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.614387  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=2.188937
I20260812 06:17:59.631505  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6741,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.632129  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushMRSOp(efe4492b6b3c42849778958694e4d72f): perf score=1.000000
I20260812 06:17:59.661870  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushMRSOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.029s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":264,"dirs.run_wall_time_us":1909,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2040,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:59.662729  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling LogGCOp(efe4492b6b3c42849778958694e4d72f): free 129320520 bytes of WAL
I20260812 06:17:59.663028  7873 log_reader.cc:385] T efe4492b6b3c42849778958694e4d72f: removed 13 log segments from log reader
I20260812 06:17:59.663102  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000015 (ops 70-74)
I20260812 06:17:59.663163  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000016 (ops 75-78)
I20260812 06:17:59.663218  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000017 (ops 79-83)
I20260812 06:17:59.663261  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000018 (ops 84-88)
I20260812 06:17:59.663298  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000019 (ops 89-93)
I20260812 06:17:59.663339  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000020 (ops 94-98)
I20260812 06:17:59.663378  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000021 (ops 99-103)
I20260812 06:17:59.663439  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000022 (ops 104-108)
I20260812 06:17:59.663477  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000023 (ops 109-112)
I20260812 06:17:59.663515  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000024 (ops 113-117)
I20260812 06:17:59.663558  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000025 (ops 118-122)
I20260812 06:17:59.663599  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000026 (ops 123-127)
I20260812 06:17:59.663642  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000027 (ops 128-132)
I20260812 06:17:59.695200  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: LogGCOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.032s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:59.696139  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=4.173312
I20260812 06:17:59.722792  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.026s	user 0.013s	sys 0.012s Metrics: {"bytes_written":6482066,"delete_count":0,"lbm_write_time_us":11058,"lbm_writes_lt_1ms":161,"reinsert_count":0,"update_count":790}
I20260812 06:17:59.723343  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=1.000000
I20260812 06:17:59.729674  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.006s	user 0.002s	sys 0.004s Metrics: {"bytes_written":1723202,"delete_count":0,"lbm_write_time_us":1810,"lbm_writes_lt_1ms":45,"reinsert_count":0,"update_count":210}
I20260812 06:17:59.730194  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling UndoDeltaBlockGCOp(efe4492b6b3c42849778958694e4d72f): 492 bytes on disk
I20260812 06:17:59.730661  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: UndoDeltaBlockGCOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:17:59.731258  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f): perf score=1.000000
I20260812 06:17:59.949908  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.218s	user 0.135s	sys 0.083s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938730,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":169,"lbm_read_time_us":17056,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36526,"lbm_writes_lt_1ms":743,"mutex_wait_us":37,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":18560,"thread_start_us":103,"threads_started":1,"update_count":3500}
I20260812 06:17:59.950656  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=14.095187
I20260812 06:18:00.023818  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.072s	user 0.049s	sys 0.017s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":34967,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"spinlock_wait_cycles":6367104,"update_count":2000}
I20260812 06:18:00.024366  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=2.188937
I20260812 06:18:00.051318  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.027s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6352,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.051895  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=2.188937
I20260812 06:18:00.064391  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4547,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.065099  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f): perf score=1.000000
I20260812 06:18:00.292666  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.227s	user 0.133s	sys 0.093s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836257,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1074,"lbm_read_time_us":15756,"lbm_reads_lt_1ms":673,"lbm_write_time_us":37802,"lbm_writes_lt_1ms":643,"mutex_wait_us":287,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":3000}
I20260812 06:18:00.293437  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=15.087375
I20260812 06:18:00.364457  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.071s	user 0.031s	sys 0.033s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":32937,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2050}
I20260812 06:18:00.365242  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=2.188937
I20260812 06:18:00.379058  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.014s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4892,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.379684  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=2.188937
I20260812 06:18:00.391451  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.011s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4246,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:00.392021  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f): perf score=1.000000
I20260812 06:18:00.604705  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.212s	user 0.136s	sys 0.076s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836242,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":376,"lbm_read_time_us":15394,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34897,"lbm_writes_lt_1ms":643,"mutex_wait_us":78,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":44288,"update_count":3000}
I20260812 06:18:00.605532  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=15.087375
I20260812 06:18:00.660810  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.055s	user 0.036s	sys 0.015s Metrics: {"bytes_written":16656050,"delete_count":0,"lbm_write_time_us":22224,"lbm_writes_lt_1ms":409,"reinsert_count":0,"update_count":2030}
I20260812 06:18:00.661712  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=2.188937
I20260812 06:18:00.682113  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.020s	user 0.007s	sys 0.009s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":6341,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:18:00.683281  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f): perf score=1.000000
I20260812 06:18:00.876092  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.193s	user 0.142s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":428,"lbm_read_time_us":13924,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31487,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2500}
I20260812 06:18:00.876965  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=14.095187
I20260812 06:18:00.942653  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.065s	user 0.027s	sys 0.034s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24135,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:00.943378  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=2.188937
I20260812 06:18:00.955286  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4497,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.955823  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f): perf score=1.000000
I20260812 06:18:01.142686  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.187s	user 0.134s	sys 0.052s 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":1981,"lbm_read_time_us":14246,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30065,"lbm_writes_lt_1ms":543,"mutex_wait_us":427,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:18:01.143760  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=11.118625
I20260812 06:18:01.191443  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.047s	user 0.032s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":23996,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:01.192076  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=2.188937
I20260812 06:18:01.219812  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.028s	user 0.006s	sys 0.014s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6111,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:01.220443  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushMRSOp(efe4492b6b3c42849778958694e4d72f): perf score=1.000000
I20260812 06:18:01.270107  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushMRSOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.049s	user 0.036s	sys 0.003s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":104,"dirs.run_cpu_time_us":317,"dirs.run_wall_time_us":1837,"drs_written":1,"lbm_read_time_us":106,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1746,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:01.271188  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=3.181125
I20260812 06:18:01.290680  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.019s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4471879,"delete_count":0,"lbm_write_time_us":5977,"lbm_writes_lt_1ms":112,"reinsert_count":0,"update_count":545}
I20260812 06:18:01.291636  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling LogGCOp(efe4492b6b3c42849778958694e4d72f): free 120100590 bytes of WAL
I20260812 06:18:01.292330  7873 log_reader.cc:385] T efe4492b6b3c42849778958694e4d72f: removed 12 log segments from log reader
I20260812 06:18:01.292550  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000028 (ops 133-136)
I20260812 06:18:01.292665  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000029 (ops 137-141)
I20260812 06:18:01.292737  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000030 (ops 142-146)
I20260812 06:18:01.292797  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000031 (ops 147-151)
I20260812 06:18:01.292837  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000032 (ops 152-156)
I20260812 06:18:01.292876  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000033 (ops 157-160)
I20260812 06:18:01.292918  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000034 (ops 161-165)
I20260812 06:18:01.292959  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000035 (ops 166-170)
I20260812 06:18:01.292999  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000036 (ops 171-174)
I20260812 06:18:01.293038  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000037 (ops 175-179)
I20260812 06:18:01.293076  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000038 (ops 180-184)
I20260812 06:18:01.293115  7873 log.cc:1079] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: Deleting log segment in path: /tmp/dist-test-task6HlKVc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515469558028-7515-0/minicluster-data/ts-0-root/wals/efe4492b6b3c42849778958694e4d72f/wal-000000039 (ops 185-189)
I20260812 06:18:01.328234  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: LogGCOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.036s	user 0.002s	sys 0.031s Metrics: {}
I20260812 06:18:01.329218  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=2.188937
I20260812 06:18:01.348482  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.019s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4143687,"delete_count":0,"lbm_write_time_us":6188,"lbm_writes_lt_1ms":104,"reinsert_count":0,"update_count":505}
I20260812 06:18:01.349062  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=2.188937
I20260812 06:18:01.360960  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4291,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:01.361704  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling UndoDeltaBlockGCOp(efe4492b6b3c42849778958694e4d72f): 463 bytes on disk
I20260812 06:18:01.362572  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: UndoDeltaBlockGCOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":116,"lbm_reads_lt_1ms":4}
I20260812 06:18:01.363581  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f): perf score=1.000000
I20260812 06:18:01.571349  7515 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.393s	user 1.903s	sys 0.234s
I20260812 06:18:01.628183  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: MajorDeltaCompactionOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.264s	user 0.151s	sys 0.110s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32938890,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"lbm_read_time_us":19371,"lbm_reads_lt_1ms":771,"lbm_write_time_us":45229,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":18048,"update_count":3500}
I20260812 06:18:01.628896  7948 maintenance_manager.cc:419] P fd98dd20984645169b41b531c5d82d59: Scheduling FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f): perf score=14.095187
I20260812 06:18:01.683576  7515 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.112s	user 0.001s	sys 0.000s
I20260812 06:18:01.684193  7515 tablet_server.cc:179] TabletServer@127.7.86.193:0 shutting down...
I20260812 06:18:01.722918  7873 maintenance_manager.cc:643] P fd98dd20984645169b41b531c5d82d59: FlushDeltaMemStoresOp(efe4492b6b3c42849778958694e4d72f) complete. Timing: real 0.094s	user 0.035s	sys 0.008s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":18274,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:01.723578  7515 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:01.723873  7515 tablet_replica.cc:333] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59: stopping tablet replica
I20260812 06:18:01.724062  7515 raft_consensus.cc:2243] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:01.724272  7515 raft_consensus.cc:2272] T efe4492b6b3c42849778958694e4d72f P fd98dd20984645169b41b531c5d82d59 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:01.738480  7515 tablet_server.cc:196] TabletServer@127.7.86.193:0 shutdown complete.
I20260812 06:18:01.743052  7515 master.cc:562] Master@127.7.86.254:38315 shutting down...
I20260812 06:18:01.748189  7515 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:01.748425  7515 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:01.748523  7515 tablet_replica.cc:333] T 00000000000000000000000000000000 P 12cc8b832c734adb861b494980b7413c: stopping tablet replica
I20260812 06:18:01.763228  7515 master.cc:584] Master@127.7.86.254:38315 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5916 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12298 ms total)

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