[==========] 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:51.338203 11654 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.11.97.190:40787
I20260812 06:17:51.339244 11654 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:51.339854 11654 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:51.346097 11666 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:51.346154 11663 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:51.346359 11660 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:51.346359 11654 server_base.cc:1061] running on GCE node
I20260812 06:17:51.347079 11654 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:51.347208 11654 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:51.347252 11654 hybrid_clock.cc:648] HybridClock initialized: now 1786515471347249 us; error 0 us; skew 500 ppm
I20260812 06:17:51.349043 11654 webserver.cc:533] Webserver started at http://127.11.97.190:40907/ using document root <none> and password file <none>
I20260812 06:17:51.349584 11654 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:51.349671 11654 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:51.349900 11654 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:51.351594 11654 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/master-0-root/instance:
uuid: "1eaf4f88ab60425088597cf764dc06aa"
format_stamp: "Formatted at 2026-08-12 06:17:51 on dist-test-slave-2d19"
I20260812 06:17:51.354990 11654 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:17:51.357008 11673 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:51.358095 11654 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:51.358210 11654 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/master-0-root
uuid: "1eaf4f88ab60425088597cf764dc06aa"
format_stamp: "Formatted at 2026-08-12 06:17:51 on dist-test-slave-2d19"
I20260812 06:17:51.358312 11654 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-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:51.374475 11654 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:51.375093 11654 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:51.375268 11654 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:51.382959 11654 rpc_server.cc:307] RPC server started. Bound to: 127.11.97.190:40787
I20260812 06:17:51.382970 11756 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.97.190:40787 every 8 connection(s)
I20260812 06:17:51.385121 11758 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:51.390288 11758 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa: Bootstrap starting.
I20260812 06:17:51.392490 11758 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:51.393302 11758 log.cc:826] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:51.394824 11758 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa: No bootstrap required, opened a new log
I20260812 06:17:51.397990 11758 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1eaf4f88ab60425088597cf764dc06aa" member_type: VOTER }
I20260812 06:17:51.398149 11758 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:51.398197 11758 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1eaf4f88ab60425088597cf764dc06aa, State: Initialized, Role: FOLLOWER
I20260812 06:17:51.398671 11758 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa [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: "1eaf4f88ab60425088597cf764dc06aa" member_type: VOTER }
I20260812 06:17:51.398797 11758 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:51.398841 11758 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:51.398921 11758 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:51.399605 11758 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1eaf4f88ab60425088597cf764dc06aa" member_type: VOTER }
I20260812 06:17:51.399968 11758 leader_election.cc:304] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa [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: 1eaf4f88ab60425088597cf764dc06aa; no voters: 
I20260812 06:17:51.400233 11758 leader_election.cc:290] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:51.400389 11766 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:51.400668 11766 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa [term 1 LEADER]: Becoming Leader. State: Replica: 1eaf4f88ab60425088597cf764dc06aa, State: Running, Role: LEADER
I20260812 06:17:51.401078 11766 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa [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: "1eaf4f88ab60425088597cf764dc06aa" member_type: VOTER }
I20260812 06:17:51.401197 11758 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:51.402753 11768 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1eaf4f88ab60425088597cf764dc06aa. Latest consensus state: current_term: 1 leader_uuid: "1eaf4f88ab60425088597cf764dc06aa" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1eaf4f88ab60425088597cf764dc06aa" member_type: VOTER } }
I20260812 06:17:51.402797 11767 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1eaf4f88ab60425088597cf764dc06aa" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1eaf4f88ab60425088597cf764dc06aa" member_type: VOTER } }
I20260812 06:17:51.402868 11768 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:51.402892 11767 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:51.403291 11783 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:51.403563 11654 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:51.405411 11783 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:51.409456 11783 catalog_manager.cc:1383] Generated new cluster ID: 35493c3017d4456aafcab31e918ecc08
I20260812 06:17:51.409525 11783 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:51.416452 11783 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:51.417201 11783 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:51.423981 11783 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa: Generated new TSK 0
I20260812 06:17:51.424604 11783 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:51.436369 11654 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:51.439530 11800 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:51.439635 11802 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:51.439530 11798 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:51.439862 11654 server_base.cc:1061] running on GCE node
I20260812 06:17:51.440168 11654 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:51.440229 11654 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:51.440284 11654 hybrid_clock.cc:648] HybridClock initialized: now 1786515471440283 us; error 0 us; skew 500 ppm
I20260812 06:17:51.441293 11654 webserver.cc:533] Webserver started at http://127.11.97.129:42103/ using document root <none> and password file <none>
I20260812 06:17:51.441483 11654 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:51.441558 11654 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:51.441640 11654 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:51.442055 11654 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/instance:
uuid: "ef835425943c489fb43e56a0aedfd3d5"
format_stamp: "Formatted at 2026-08-12 06:17:51 on dist-test-slave-2d19"
I20260812 06:17:51.443576 11654 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:51.444695 11811 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:51.445025 11654 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:51.445118 11654 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root
uuid: "ef835425943c489fb43e56a0aedfd3d5"
format_stamp: "Formatted at 2026-08-12 06:17:51 on dist-test-slave-2d19"
I20260812 06:17:51.445204 11654 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-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:51.467716 11654 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:51.468217 11654 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:51.468782 11654 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:51.469702 11654 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:51.469780 11654 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:51.469854 11654 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:51.469914 11654 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:51.476886 11654 rpc_server.cc:307] RPC server started. Bound to: 127.11.97.129:45381
I20260812 06:17:51.476922 11922 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.97.129:45381 every 8 connection(s)
I20260812 06:17:51.487602 11923 heartbeater.cc:344] Connected to a master server at 127.11.97.190:40787
I20260812 06:17:51.487854 11923 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:51.488345 11923 heartbeater.cc:507] Master 127.11.97.190:40787 requested a full tablet report, sending...
I20260812 06:17:51.489691 11702 ts_manager.cc:194] Registered new tserver with Master: ef835425943c489fb43e56a0aedfd3d5 (127.11.97.129:45381)
I20260812 06:17:51.489894 11654 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012368621s
I20260812 06:17:51.491214 11702 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:46580
I20260812 06:17:51.499454 11702 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:46594:
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:51.512766 11857 tablet_service.cc:1511] Processing CreateTablet for tablet 1db75d8395bf48c8ad37393d17d51c81 (DEFAULT_TABLE table=heavy-update-compaction-test [id=353bcb274f464c4f93462c0efb4aad89]), partition=
I20260812 06:17:51.513283 11857 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 1db75d8395bf48c8ad37393d17d51c81. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:51.515398 11950 tablet_bootstrap.cc:492] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Bootstrap starting.
I20260812 06:17:51.516397 11950 tablet_bootstrap.cc:654] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:51.517630 11950 tablet_bootstrap.cc:492] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: No bootstrap required, opened a new log
I20260812 06:17:51.517714 11950 ts_tablet_manager.cc:1403] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:51.518186 11950 raft_consensus.cc:359] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ef835425943c489fb43e56a0aedfd3d5" member_type: VOTER last_known_addr { host: "127.11.97.129" port: 45381 } }
I20260812 06:17:51.518281 11950 raft_consensus.cc:385] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:51.518304 11950 raft_consensus.cc:740] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ef835425943c489fb43e56a0aedfd3d5, State: Initialized, Role: FOLLOWER
I20260812 06:17:51.518462 11950 consensus_queue.cc:260] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5 [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: "ef835425943c489fb43e56a0aedfd3d5" member_type: VOTER last_known_addr { host: "127.11.97.129" port: 45381 } }
I20260812 06:17:51.518543 11950 raft_consensus.cc:399] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:51.518592 11950 raft_consensus.cc:493] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:51.518646 11950 raft_consensus.cc:3060] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:51.519661 11950 raft_consensus.cc:515] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ef835425943c489fb43e56a0aedfd3d5" member_type: VOTER last_known_addr { host: "127.11.97.129" port: 45381 } }
I20260812 06:17:51.519778 11950 leader_election.cc:304] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5 [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: ef835425943c489fb43e56a0aedfd3d5; no voters: 
I20260812 06:17:51.520051 11950 leader_election.cc:290] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:51.520133 11955 raft_consensus.cc:2804] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:51.520323 11955 raft_consensus.cc:697] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5 [term 1 LEADER]: Becoming Leader. State: Replica: ef835425943c489fb43e56a0aedfd3d5, State: Running, Role: LEADER
I20260812 06:17:51.520429 11950 ts_tablet_manager.cc:1434] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:17:51.520450 11955 consensus_queue.cc:237] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5 [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: "ef835425943c489fb43e56a0aedfd3d5" member_type: VOTER last_known_addr { host: "127.11.97.129" port: 45381 } }
I20260812 06:17:51.520916 11923 heartbeater.cc:499] Master 127.11.97.190:40787 was elected leader, sending a full tablet report...
I20260812 06:17:51.523182 11702 catalog_manager.cc:5719] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5 reported cstate change: term changed from 0 to 1, leader changed from <none> to ef835425943c489fb43e56a0aedfd3d5 (127.11.97.129). New cstate: current_term: 1 leader_uuid: "ef835425943c489fb43e56a0aedfd3d5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ef835425943c489fb43e56a0aedfd3d5" member_type: VOTER last_known_addr { host: "127.11.97.129" port: 45381 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:51.584654 11654 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.014s	sys 0.013s
I20260812 06:17:51.728152 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushMRSOp(1db75d8395bf48c8ad37393d17d51c81): perf score=19.054940
I20260812 06:17:51.895105 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushMRSOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.167s	user 0.124s	sys 0.040s Metrics: {"bytes_written":12348515,"cfile_init":1,"compiler_manager_pool.queue_time_us":247,"delete_count":0,"dirs.queue_time_us":87,"dirs.run_cpu_time_us":187,"dirs.run_wall_time_us":928,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41602,"lbm_writes_lt_1ms":758,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":362880,"thread_start_us":154,"threads_started":1,"update_count":1505}
I20260812 06:17:51.896157 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling LogGCOp(1db75d8395bf48c8ad37393d17d51c81): free 20743880 bytes of WAL
I20260812 06:17:51.896466 11817 log_reader.cc:385] T 1db75d8395bf48c8ad37393d17d51c81: removed 2 log segments from log reader
I20260812 06:17:51.896550 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000001 (ops 1-6)
I20260812 06:17:51.896627 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000002 (ops 7-11)
I20260812 06:17:51.900712 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: LogGCOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.004s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:17:51.901028 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling UndoDeltaBlockGCOp(1db75d8395bf48c8ad37393d17d51c81): 16411396 bytes on disk
I20260812 06:17:51.901557 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: UndoDeltaBlockGCOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:17:51.901995 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:51.920830 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.019s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4061634,"delete_count":0,"lbm_write_time_us":6120,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":495}
I20260812 06:17:51.921299 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81): perf score=1.000000
I20260812 06:17:52.067155 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.146s	user 0.098s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":568,"lbm_read_time_us":7974,"lbm_reads_lt_1ms":460,"lbm_write_time_us":22680,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":299,"threads_started":5,"update_count":2000}
I20260812 06:17:52.067785 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=10.126437
I20260812 06:17:52.113344 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.045s	user 0.032s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20068,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:52.113821 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:52.124536 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3816,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.125051 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81): perf score=1.000000
I20260812 06:17:52.247113 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.122s	user 0.086s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1238,"lbm_read_time_us":7550,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25422,"lbm_writes_lt_1ms":443,"mutex_wait_us":341,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:52.247888 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=10.126437
I20260812 06:17:52.285863 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.038s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16181,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:52.286543 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:52.307724 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.021s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5740,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.308179 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81): perf score=1.000000
I20260812 06:17:52.435407 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.127s	user 0.110s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":721,"lbm_read_time_us":8722,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25018,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17920,"update_count":2000}
I20260812 06:17:52.436154 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=10.126437
I20260812 06:17:52.483531 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.047s	user 0.022s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16544,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:52.484069 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:52.494532 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4027,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.494992 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81): perf score=1.000000
I20260812 06:17:52.641954 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.147s	user 0.080s	sys 0.066s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":525,"lbm_read_time_us":10154,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24200,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:52.642511 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=10.126437
I20260812 06:17:52.686786 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.044s	user 0.018s	sys 0.017s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":17676,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:52.687280 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:52.702322 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5683,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.702875 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81): perf score=1.000000
I20260812 06:17:52.832398 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.129s	user 0.113s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":739,"lbm_read_time_us":9681,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25205,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":23424,"update_count":2000}
I20260812 06:17:52.833102 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=10.126437
I20260812 06:17:52.873675 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.040s	user 0.019s	sys 0.013s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":14379,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:52.874265 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:52.885090 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4079,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.885643 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81): perf score=1.000000
I20260812 06:17:53.000068 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.114s	user 0.085s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":514,"lbm_read_time_us":7603,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21747,"lbm_writes_lt_1ms":443,"mutex_wait_us":271,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2000}
I20260812 06:17:53.000767 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=10.126437
I20260812 06:17:53.046774 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.046s	user 0.017s	sys 0.025s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15658,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:53.047379 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:53.065359 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.018s	user 0.008s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6873,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.066030 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushMRSOp(1db75d8395bf48c8ad37393d17d51c81): perf score=1.000000
I20260812 06:17:53.100064 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushMRSOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.034s	user 0.028s	sys 0.001s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":123,"dirs.run_cpu_time_us":207,"dirs.run_wall_time_us":1291,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2010,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:53.100911 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling LogGCOp(1db75d8395bf48c8ad37393d17d51c81): free 112692371 bytes of WAL
I20260812 06:17:53.101177 11817 log_reader.cc:385] T 1db75d8395bf48c8ad37393d17d51c81: removed 11 log segments from log reader
I20260812 06:17:53.101224 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000003 (ops 12-16)
I20260812 06:17:53.101251 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000004 (ops 17-21)
I20260812 06:17:53.101296 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000005 (ops 22-26)
I20260812 06:17:53.101343 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000006 (ops 27-31)
I20260812 06:17:53.101410 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000007 (ops 32-36)
I20260812 06:17:53.101473 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000008 (ops 37-41)
I20260812 06:17:53.101512 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000009 (ops 42-46)
I20260812 06:17:53.101562 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000010 (ops 47-51)
I20260812 06:17:53.101601 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000011 (ops 52-56)
I20260812 06:17:53.101639 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000012 (ops 57-61)
I20260812 06:17:53.101678 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000013 (ops 62-66)
I20260812 06:17:53.125340 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: LogGCOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.024s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:17:53.125821 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:53.150977 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.025s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5429,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.151546 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:53.163029 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4390,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.163475 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81): perf score=1.000000
I20260812 06:17:53.366591 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.203s	user 0.128s	sys 0.072s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877340,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1064,"lbm_read_time_us":13505,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36867,"lbm_writes_lt_1ms":643,"mutex_wait_us":1371,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1536,"thread_start_us":88,"threads_started":1,"update_count":3000}
I20260812 06:17:53.367394 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling UndoDeltaBlockGCOp(1db75d8395bf48c8ad37393d17d51c81): 447 bytes on disk
I20260812 06:17:53.367961 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: UndoDeltaBlockGCOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":90,"lbm_reads_lt_1ms":4}
I20260812 06:17:53.368637 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=14.095187
I20260812 06:17:53.409929 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.041s	user 0.023s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":18329,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:53.410844 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:53.427129 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6414,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.427567 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81): perf score=1.000000
I20260812 06:17:53.590343 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.163s	user 0.090s	sys 0.071s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":315,"lbm_read_time_us":10433,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28831,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1152,"update_count":2500}
I20260812 06:17:53.590901 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=14.095187
I20260812 06:17:53.642236 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.051s	user 0.021s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21623,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:53.642766 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:53.656426 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.013s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5335,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.657074 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81): perf score=1.000000
I20260812 06:17:53.834636 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.177s	user 0.117s	sys 0.054s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":277,"lbm_read_time_us":12154,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30650,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":48000,"update_count":2500}
I20260812 06:17:53.835258 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=14.095187
I20260812 06:17:53.894629 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.059s	user 0.026s	sys 0.028s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":22178,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:53.895115 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:53.905721 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4150,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.906162 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81): perf score=1.000000
I20260812 06:17:54.073552 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.167s	user 0.130s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":150,"lbm_read_time_us":11709,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26732,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":44544,"update_count":2500}
I20260812 06:17:54.076586 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=10.126437
I20260812 06:17:54.121840 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.045s	user 0.024s	sys 0.018s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19346,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:54.122303 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=3.181125
I20260812 06:17:54.152614 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.030s	user 0.004s	sys 0.019s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5597,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:54.153098 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:54.163021 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3826,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:54.163444 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81): perf score=1.000000
I20260812 06:17:54.337743 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.174s	user 0.114s	sys 0.060s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":808,"lbm_read_time_us":11798,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30154,"lbm_writes_lt_1ms":543,"mutex_wait_us":280,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:17:54.338581 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=11.118625
I20260812 06:17:54.376677 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.038s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16684,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:54.377274 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:54.394932 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.017s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4930,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:54.395414 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81): perf score=1.000000
I20260812 06:17:54.522567 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.127s	user 0.094s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":165,"lbm_read_time_us":8658,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24054,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2000}
I20260812 06:17:54.523164 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=10.126437
I20260812 06:17:54.562904 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.040s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17504,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:54.563434 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:54.574200 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4069,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.574863 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushMRSOp(1db75d8395bf48c8ad37393d17d51c81): perf score=1.000000
I20260812 06:17:54.606746 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushMRSOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.032s	user 0.027s	sys 0.003s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":183,"dirs.run_wall_time_us":1584,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1531,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:54.607434 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling LogGCOp(1db75d8395bf48c8ad37393d17d51c81): free 120553380 bytes of WAL
I20260812 06:17:54.607668 11817 log_reader.cc:385] T 1db75d8395bf48c8ad37393d17d51c81: removed 12 log segments from log reader
I20260812 06:17:54.607715 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000014 (ops 67-70)
I20260812 06:17:54.607743 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000015 (ops 71-75)
I20260812 06:17:54.607801 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000016 (ops 76-80)
I20260812 06:17:54.607846 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000017 (ops 81-85)
I20260812 06:17:54.607887 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000018 (ops 86-90)
I20260812 06:17:54.607928 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000019 (ops 91-94)
I20260812 06:17:54.607969 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000020 (ops 95-99)
I20260812 06:17:54.608008 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000021 (ops 100-104)
I20260812 06:17:54.608049 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000022 (ops 105-109)
I20260812 06:17:54.608089 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000023 (ops 110-114)
I20260812 06:17:54.608129 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000024 (ops 115-119)
I20260812 06:17:54.608168 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000025 (ops 120-124)
I20260812 06:17:54.631717 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: LogGCOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.024s	user 0.002s	sys 0.019s Metrics: {}
I20260812 06:17:54.632102 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=3.181125
I20260812 06:17:54.643931 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4473,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:54.644423 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling LogGCOp(1db75d8395bf48c8ad37393d17d51c81): free 11564877 bytes of WAL
I20260812 06:17:54.644654 11817 log_reader.cc:385] T 1db75d8395bf48c8ad37393d17d51c81: removed 1 log segments from log reader
I20260812 06:17:54.644711 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000026 (ops 125-128)
I20260812 06:17:54.647439 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: LogGCOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:54.647771 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling UndoDeltaBlockGCOp(1db75d8395bf48c8ad37393d17d51c81): 472 bytes on disk
I20260812 06:17:54.648183 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: UndoDeltaBlockGCOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:17:54.648777 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:54.659315 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3596,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:54.659792 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81): perf score=1.000000
I20260812 06:17:54.831825 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.171s	user 0.135s	sys 0.031s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877330,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":6349,"lbm_read_time_us":13324,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32077,"lbm_writes_lt_1ms":643,"mutex_wait_us":1496,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":110,"threads_started":1,"update_count":3000}
I20260812 06:17:54.832412 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=14.095187
I20260812 06:17:54.888206 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.056s	user 0.026s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23437,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:54.888849 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=3.181125
I20260812 06:17:54.909932 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.021s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6720,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:54.910347 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:54.919361 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.009s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3485,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:54.919800 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81): perf score=1.000000
I20260812 06:17:55.110803 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.191s	user 0.123s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877210,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1683,"lbm_read_time_us":11982,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31301,"lbm_writes_lt_1ms":643,"mutex_wait_us":563,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:17:55.114188 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=14.095187
I20260812 06:17:55.166065 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.051s	user 0.023s	sys 0.027s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21600,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.166903 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=3.181125
I20260812 06:17:55.192008 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.025s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7753,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:55.192507 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:55.202221 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3618,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:55.202679 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81): perf score=1.000000
I20260812 06:17:55.389412 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.187s	user 0.118s	sys 0.068s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877208,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":878,"lbm_read_time_us":14297,"lbm_reads_lt_1ms":673,"lbm_write_time_us":30964,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":3000}
I20260812 06:17:55.389889 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=14.095187
I20260812 06:17:55.450469 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.060s	user 0.027s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19444,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.451138 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:55.474316 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.023s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5875,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.474794 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:55.487062 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5662,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.487552 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81): perf score=1.000000
I20260812 06:17:55.683070 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.195s	user 0.151s	sys 0.044s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877218,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":742,"lbm_read_time_us":11788,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34407,"lbm_writes_lt_1ms":643,"mutex_wait_us":73,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":3000}
I20260812 06:17:55.687340 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=14.095187
I20260812 06:17:55.731645 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.044s	user 0.019s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18325,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.732199 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:55.743360 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4438,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.743813 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81): perf score=1.000000
I20260812 06:17:55.915709 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.172s	user 0.123s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":564,"lbm_read_time_us":11086,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30721,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:17:55.916445 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=14.095187
I20260812 06:17:55.972497 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.056s	user 0.024s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20822,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.973042 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:55.984925 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4168,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.985548 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushMRSOp(1db75d8395bf48c8ad37393d17d51c81): perf score=1.000000
I20260812 06:17:56.024537 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushMRSOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.039s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":45,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":1491,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2106,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:56.025501 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling LogGCOp(1db75d8395bf48c8ad37393d17d51c81): free 120553636 bytes of WAL
I20260812 06:17:56.025768 11817 log_reader.cc:385] T 1db75d8395bf48c8ad37393d17d51c81: removed 12 log segments from log reader
I20260812 06:17:56.025839 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000027 (ops 129-133)
I20260812 06:17:56.025892 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000028 (ops 134-138)
I20260812 06:17:56.025928 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000029 (ops 139-143)
I20260812 06:17:56.025976 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000030 (ops 144-148)
I20260812 06:17:56.026013 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000031 (ops 149-152)
I20260812 06:17:56.026049 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000032 (ops 153-157)
I20260812 06:17:56.026084 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000033 (ops 158-162)
I20260812 06:17:56.026121 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000034 (ops 163-167)
I20260812 06:17:56.026156 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000035 (ops 168-172)
I20260812 06:17:56.026192 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000036 (ops 173-177)
I20260812 06:17:56.026228 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000037 (ops 178-182)
I20260812 06:17:56.026264 11817 log.cc:1079] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/1db75d8395bf48c8ad37393d17d51c81/wal-000000038 (ops 183-186)
I20260812 06:17:56.051999 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: LogGCOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:17:56.052738 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:56.074608 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.022s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6255,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.075052 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling UndoDeltaBlockGCOp(1db75d8395bf48c8ad37393d17d51c81): 473 bytes on disk
I20260812 06:17:56.075430 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: UndoDeltaBlockGCOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:17:56.075982 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:56.086061 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3842,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.086653 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81): perf score=1.000000
I20260812 06:17:56.299309 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.212s	user 0.154s	sys 0.048s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":900,"lbm_read_time_us":15049,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37735,"lbm_writes_lt_1ms":743,"mutex_wait_us":44,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":8320,"thread_start_us":77,"threads_started":1,"update_count":3500}
I20260812 06:17:56.300173 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=18.063937
I20260812 06:17:56.349207 11654 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.764s	user 1.733s	sys 0.155s
I20260812 06:17:56.368872 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.068s	user 0.030s	sys 0.037s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":33905,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:17:56.369552 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81): perf score=2.188937
I20260812 06:17:56.385988 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: FlushDeltaMemStoresOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6572,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.386570 11927 maintenance_manager.cc:419] P ef835425943c489fb43e56a0aedfd3d5: Scheduling MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81): perf score=1.000000
I20260812 06:17:56.389349 11654 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.040s	user 0.002s	sys 0.000s
I20260812 06:17:56.389918 11654 tablet_server.cc:179] TabletServer@127.11.97.129:0 shutting down...
I20260812 06:17:56.526237 11817 maintenance_manager.cc:643] P ef835425943c489fb43e56a0aedfd3d5: MajorDeltaCompactionOp(1db75d8395bf48c8ad37393d17d51c81) complete. Timing: real 0.139s	user 0.107s	sys 0.032s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4262390,"cfile_cache_miss":602,"cfile_cache_miss_bytes":24614711,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1081,"lbm_read_time_us":8751,"lbm_reads_lt_1ms":618,"lbm_write_time_us":27331,"lbm_writes_lt_1ms":643,"mutex_wait_us":338,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:17:56.527045 11654 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:56.527462 11654 tablet_replica.cc:333] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5: stopping tablet replica
I20260812 06:17:56.527736 11654 raft_consensus.cc:2243] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:56.527971 11654 raft_consensus.cc:2272] T 1db75d8395bf48c8ad37393d17d51c81 P ef835425943c489fb43e56a0aedfd3d5 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:56.534344 11654 tablet_server.cc:196] TabletServer@127.11.97.129:0 shutdown complete.
I20260812 06:17:56.579689 11654 master.cc:562] Master@127.11.97.190:40787 shutting down...
I20260812 06:17:56.583917 11654 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:56.584123 11654 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:56.584216 11654 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1eaf4f88ab60425088597cf764dc06aa: stopping tablet replica
I20260812 06:17:56.596732 11654 master.cc:584] Master@127.11.97.190:40787 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5350 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:56.687844 11654 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.11.97.190:33155
I20260812 06:17:56.688247 11654 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:56.690311 11999 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.690448 11654 server_base.cc:1061] running on GCE node
W20260812 06:17:56.690308 11988 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:56.690460 11993 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:56.690726 11654 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:56.690771 11654 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.690786 11654 hybrid_clock.cc:648] HybridClock initialized: now 1786515476690786 us; error 0 us; skew 500 ppm
I20260812 06:17:56.691622 11654 webserver.cc:533] Webserver started at http://127.11.97.190:33185/ using document root <none> and password file <none>
I20260812 06:17:56.691800 11654 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:56.691865 11654 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:56.691957 11654 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:56.692407 11654 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/master-0-root/instance:
uuid: "57ac7c7c2df548cd91179080d11bd5bb"
format_stamp: "Formatted at 2026-08-12 06:17:56 on dist-test-slave-2d19"
I20260812 06:17:56.693878 11654 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:56.694796 12005 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.695044 11654 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:56.695138 11654 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/master-0-root
uuid: "57ac7c7c2df548cd91179080d11bd5bb"
format_stamp: "Formatted at 2026-08-12 06:17:56 on dist-test-slave-2d19"
I20260812 06:17:56.695205 11654 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-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:56.715548 11654 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:56.715966 11654 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:56.719916 11654 rpc_server.cc:307] RPC server started. Bound to: 127.11.97.190:33155
I20260812 06:17:56.722496 12094 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:56.724094 12092 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.97.190:33155 every 8 connection(s)
I20260812 06:17:56.726881 12094 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb: Bootstrap starting.
I20260812 06:17:56.727703 12094 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:56.728704 12094 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb: No bootstrap required, opened a new log
I20260812 06:17:56.729115 12094 raft_consensus.cc:359] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "57ac7c7c2df548cd91179080d11bd5bb" member_type: VOTER }
I20260812 06:17:56.729200 12094 raft_consensus.cc:385] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:56.729257 12094 raft_consensus.cc:740] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 57ac7c7c2df548cd91179080d11bd5bb, State: Initialized, Role: FOLLOWER
I20260812 06:17:56.729414 12094 consensus_queue.cc:260] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb [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: "57ac7c7c2df548cd91179080d11bd5bb" member_type: VOTER }
I20260812 06:17:56.729514 12094 raft_consensus.cc:399] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:56.729583 12094 raft_consensus.cc:493] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:56.729645 12094 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:56.730350 12094 raft_consensus.cc:515] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "57ac7c7c2df548cd91179080d11bd5bb" member_type: VOTER }
I20260812 06:17:56.730497 12094 leader_election.cc:304] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb [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: 57ac7c7c2df548cd91179080d11bd5bb; no voters: 
I20260812 06:17:56.730710 12094 leader_election.cc:290] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:56.730818 12100 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:56.731078 12100 raft_consensus.cc:697] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb [term 1 LEADER]: Becoming Leader. State: Replica: 57ac7c7c2df548cd91179080d11bd5bb, State: Running, Role: LEADER
I20260812 06:17:56.731175 12094 sys_catalog.cc:565] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:56.731216 12100 consensus_queue.cc:237] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb [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: "57ac7c7c2df548cd91179080d11bd5bb" member_type: VOTER }
I20260812 06:17:56.731695 12102 sys_catalog.cc:455] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "57ac7c7c2df548cd91179080d11bd5bb" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "57ac7c7c2df548cd91179080d11bd5bb" member_type: VOTER } }
I20260812 06:17:56.731731 12103 sys_catalog.cc:455] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb [sys.catalog]: SysCatalogTable state changed. Reason: New leader 57ac7c7c2df548cd91179080d11bd5bb. Latest consensus state: current_term: 1 leader_uuid: "57ac7c7c2df548cd91179080d11bd5bb" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "57ac7c7c2df548cd91179080d11bd5bb" member_type: VOTER } }
I20260812 06:17:56.731871 12103 sys_catalog.cc:458] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:56.732143 12102 sys_catalog.cc:458] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:56.732329 12114 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:56.733011 12114 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:56.733193 11654 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:56.734750 12114 catalog_manager.cc:1383] Generated new cluster ID: e583d9fe6b3948ff8b035fe3edf6442f
I20260812 06:17:56.734805 12114 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:56.751116 12114 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:56.751647 12114 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:56.762341 12114 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb: Generated new TSK 0
I20260812 06:17:56.762542 12114 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:56.765424 11654 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:56.767393 12138 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.767482 12141 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.767462 11654 server_base.cc:1061] running on GCE node
W20260812 06:17:56.767405 12137 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.767827 11654 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:56.767885 11654 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.767911 11654 hybrid_clock.cc:648] HybridClock initialized: now 1786515476767910 us; error 0 us; skew 500 ppm
I20260812 06:17:56.768847 11654 webserver.cc:533] Webserver started at http://127.11.97.129:38641/ using document root <none> and password file <none>
I20260812 06:17:56.769022 11654 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:56.769093 11654 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:56.769168 11654 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:56.769546 11654 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/instance:
uuid: "5be970abfb714bb8afb216a65cba2d8e"
format_stamp: "Formatted at 2026-08-12 06:17:56 on dist-test-slave-2d19"
I20260812 06:17:56.771030 11654 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:56.771940 12149 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.772166 11654 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:56.772255 11654 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root
uuid: "5be970abfb714bb8afb216a65cba2d8e"
format_stamp: "Formatted at 2026-08-12 06:17:56 on dist-test-slave-2d19"
I20260812 06:17:56.772364 11654 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-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.778743 11654 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:56.779073 11654 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:56.779357 11654 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:56.779814 11654 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:56.779873 11654 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:56.779950 11654 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:56.780001 11654 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:56.784315 11654 rpc_server.cc:307] RPC server started. Bound to: 127.11.97.129:37649
I20260812 06:17:56.786769 12257 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.97.129:37649 every 8 connection(s)
I20260812 06:17:56.796309 12258 heartbeater.cc:344] Connected to a master server at 127.11.97.190:33155
I20260812 06:17:56.796427 12258 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:56.796684 12258 heartbeater.cc:507] Master 127.11.97.190:33155 requested a full tablet report, sending...
I20260812 06:17:56.797360 12028 ts_manager.cc:194] Registered new tserver with Master: 5be970abfb714bb8afb216a65cba2d8e (127.11.97.129:37649)
I20260812 06:17:56.797561 11654 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012111745s
I20260812 06:17:56.798341 12028 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:41252
I20260812 06:17:56.804739 12028 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:41268:
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.813711 12197 tablet_service.cc:1511] Processing CreateTablet for tablet bfd4e6a8adbe4698af98afa11948a818 (DEFAULT_TABLE table=heavy-update-compaction-test [id=ed902a2a78af42a98040630d8feb44ee]), partition=
I20260812 06:17:56.813975 12197 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet bfd4e6a8adbe4698af98afa11948a818. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:56.816445 12279 tablet_bootstrap.cc:492] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Bootstrap starting.
I20260812 06:17:56.817317 12279 tablet_bootstrap.cc:654] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:56.818497 12279 tablet_bootstrap.cc:492] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: No bootstrap required, opened a new log
I20260812 06:17:56.818626 12279 ts_tablet_manager.cc:1403] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:56.819065 12279 raft_consensus.cc:359] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5be970abfb714bb8afb216a65cba2d8e" member_type: VOTER last_known_addr { host: "127.11.97.129" port: 37649 } }
I20260812 06:17:56.819180 12279 raft_consensus.cc:385] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:56.819234 12279 raft_consensus.cc:740] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5be970abfb714bb8afb216a65cba2d8e, State: Initialized, Role: FOLLOWER
I20260812 06:17:56.819386 12279 consensus_queue.cc:260] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e [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: "5be970abfb714bb8afb216a65cba2d8e" member_type: VOTER last_known_addr { host: "127.11.97.129" port: 37649 } }
I20260812 06:17:56.819459 12279 raft_consensus.cc:399] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:56.819530 12279 raft_consensus.cc:493] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:56.819587 12279 raft_consensus.cc:3060] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:56.820392 12279 raft_consensus.cc:515] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5be970abfb714bb8afb216a65cba2d8e" member_type: VOTER last_known_addr { host: "127.11.97.129" port: 37649 } }
I20260812 06:17:56.820554 12279 leader_election.cc:304] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e [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: 5be970abfb714bb8afb216a65cba2d8e; no voters: 
I20260812 06:17:56.820768 12279 leader_election.cc:290] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:56.820910 12285 raft_consensus.cc:2804] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:56.821091 12279 ts_tablet_manager.cc:1434] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Time spent starting tablet: real 0.002s	user 0.001s	sys 0.002s
I20260812 06:17:56.821112 12258 heartbeater.cc:499] Master 127.11.97.190:33155 was elected leader, sending a full tablet report...
I20260812 06:17:56.821166 12285 raft_consensus.cc:697] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e [term 1 LEADER]: Becoming Leader. State: Replica: 5be970abfb714bb8afb216a65cba2d8e, State: Running, Role: LEADER
I20260812 06:17:56.821309 12285 consensus_queue.cc:237] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e [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: "5be970abfb714bb8afb216a65cba2d8e" member_type: VOTER last_known_addr { host: "127.11.97.129" port: 37649 } }
I20260812 06:17:56.822813 12028 catalog_manager.cc:5719] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e reported cstate change: term changed from 0 to 1, leader changed from <none> to 5be970abfb714bb8afb216a65cba2d8e (127.11.97.129). New cstate: current_term: 1 leader_uuid: "5be970abfb714bb8afb216a65cba2d8e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5be970abfb714bb8afb216a65cba2d8e" member_type: VOTER last_known_addr { host: "127.11.97.129" port: 37649 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:56.881429 11654 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.014s	sys 0.008s
I20260812 06:17:57.037382 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushMRSOp(bfd4e6a8adbe4698af98afa11948a818): perf score=19.054940
I20260812 06:17:57.197726 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushMRSOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.160s	user 0.114s	sys 0.043s Metrics: {"bytes_written":13127975,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":202,"dirs.run_wall_time_us":883,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41087,"lbm_writes_lt_1ms":777,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":896,"update_count":1600}
I20260812 06:17:57.198556 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling LogGCOp(bfd4e6a8adbe4698af98afa11948a818): free 20743880 bytes of WAL
I20260812 06:17:57.198889 12158 log_reader.cc:385] T bfd4e6a8adbe4698af98afa11948a818: removed 2 log segments from log reader
I20260812 06:17:57.198985 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000001 (ops 1-6)
I20260812 06:17:57.199043 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000002 (ops 7-11)
I20260812 06:17:57.203222 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: LogGCOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:57.203600 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=2.188937
I20260812 06:17:57.221189 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.017s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3282155,"delete_count":0,"lbm_write_time_us":3465,"lbm_writes_lt_1ms":83,"reinsert_count":0,"update_count":400}
I20260812 06:17:57.221603 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=2.188937
I20260812 06:17:57.232969 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4056,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.233443 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818): perf score=1.000000
I20260812 06:17:57.404842 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.171s	user 0.083s	sys 0.087s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774789,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":782,"lbm_read_time_us":12201,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29298,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"thread_start_us":319,"threads_started":5,"update_count":2500}
I20260812 06:17:57.405427 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling UndoDeltaBlockGCOp(bfd4e6a8adbe4698af98afa11948a818): 16411397 bytes on disk
I20260812 06:17:57.405774 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: UndoDeltaBlockGCOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4}
I20260812 06:17:57.406136 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=14.095187
I20260812 06:17:57.461123 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.055s	user 0.035s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21329,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.461637 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=2.188937
I20260812 06:17:57.476410 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5616,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.476920 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818): perf score=1.000000
I20260812 06:17:57.657140 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.180s	user 0.120s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":325,"lbm_read_time_us":13444,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29038,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":28416,"update_count":2500}
I20260812 06:17:57.657831 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=14.095187
I20260812 06:17:57.716513 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.059s	user 0.019s	sys 0.039s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":24160,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.717046 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=2.188937
I20260812 06:17:57.727419 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4135,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.727847 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818): perf score=1.000000
I20260812 06:17:57.903797 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.176s	user 0.107s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":647,"lbm_read_time_us":12169,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27218,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2500}
I20260812 06:17:57.904377 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=14.095187
I20260812 06:17:57.962671 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.058s	user 0.021s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19456,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.963258 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=2.188937
I20260812 06:17:57.974579 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4484,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.975028 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818): perf score=1.000000
I20260812 06:17:58.152424 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.177s	user 0.105s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":226,"lbm_read_time_us":12040,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27586,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:17:58.153188 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=14.095187
I20260812 06:17:58.207183 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.054s	user 0.024s	sys 0.026s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27193,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:58.207795 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=2.188937
I20260812 06:17:58.231350 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.023s	user 0.010s	sys 0.010s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5366,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.231967 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818): perf score=1.000000
I20260812 06:17:58.413878 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.182s	user 0.142s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":927,"lbm_read_time_us":12635,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28633,"lbm_writes_lt_1ms":543,"mutex_wait_us":238,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2500}
I20260812 06:17:58.414644 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=14.095187
I20260812 06:17:58.461282 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.046s	user 0.035s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20450,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:58.462016 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=2.188937
I20260812 06:17:58.477841 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5977,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.478502 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushMRSOp(bfd4e6a8adbe4698af98afa11948a818): perf score=1.000000
I20260812 06:17:58.533329 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushMRSOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.053s	user 0.038s	sys 0.013s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":185,"dirs.run_wall_time_us":1518,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1918,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:58.534121 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling LogGCOp(bfd4e6a8adbe4698af98afa11948a818): free 120553329 bytes of WAL
I20260812 06:17:58.534396 12158 log_reader.cc:385] T bfd4e6a8adbe4698af98afa11948a818: removed 12 log segments from log reader
I20260812 06:17:58.534457 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000003 (ops 12-16)
I20260812 06:17:58.534499 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000004 (ops 17-21)
I20260812 06:17:58.534545 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000005 (ops 22-26)
I20260812 06:17:58.534579 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000006 (ops 27-31)
I20260812 06:17:58.534613 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000007 (ops 32-36)
I20260812 06:17:58.534643 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000008 (ops 37-41)
I20260812 06:17:58.534677 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000009 (ops 42-46)
I20260812 06:17:58.534710 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000010 (ops 47-50)
I20260812 06:17:58.534744 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000011 (ops 51-55)
I20260812 06:17:58.534775 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000012 (ops 56-60)
I20260812 06:17:58.534811 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000013 (ops 61-64)
I20260812 06:17:58.534840 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000014 (ops 65-69)
I20260812 06:17:58.566184 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: LogGCOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.032s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:58.566802 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling UndoDeltaBlockGCOp(bfd4e6a8adbe4698af98afa11948a818): 472 bytes on disk
I20260812 06:17:58.567354 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: UndoDeltaBlockGCOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":87,"lbm_reads_lt_1ms":4}
I20260812 06:17:58.567996 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=2.188937
I20260812 06:17:58.581599 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.013s	user 0.006s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4843,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.582050 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818): perf score=1.000000
I20260812 06:17:58.794631 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.212s	user 0.112s	sys 0.092s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":614,"lbm_read_time_us":14319,"lbm_reads_lt_1ms":665,"lbm_write_time_us":34130,"lbm_writes_lt_1ms":643,"mutex_wait_us":362,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":23808,"thread_start_us":86,"threads_started":1,"update_count":3000}
I20260812 06:17:58.795222 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=18.063937
I20260812 06:17:58.866035 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.071s	user 0.039s	sys 0.030s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":28149,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:58.866611 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=2.188937
I20260812 06:17:58.879899 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4759,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.880471 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818): perf score=1.000000
I20260812 06:17:59.080842 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.200s	user 0.122s	sys 0.075s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":176,"lbm_read_time_us":11501,"lbm_reads_lt_1ms":664,"lbm_write_time_us":34324,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:17:59.082981 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=14.095187
I20260812 06:17:59.143512 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.060s	user 0.036s	sys 0.021s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":30031,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":399,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.144083 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=2.188937
I20260812 06:17:59.167855 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.024s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5586,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.168416 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=2.188937
I20260812 06:17:59.182670 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5525,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.183208 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818): perf score=1.000000
I20260812 06:17:59.388604 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.205s	user 0.142s	sys 0.063s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877221,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":138,"lbm_read_time_us":15200,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32845,"lbm_writes_lt_1ms":643,"mutex_wait_us":50,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":22656,"update_count":3000}
I20260812 06:17:59.389432 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=14.095187
I20260812 06:17:59.442490 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.053s	user 0.023s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22918,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.443365 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=2.188937
I20260812 06:17:59.463338 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.020s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5284,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.463801 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818): perf score=1.000000
I20260812 06:17:59.637404 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.173s	user 0.110s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":308,"lbm_read_time_us":11344,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30741,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":55040,"update_count":2500}
I20260812 06:17:59.637921 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=14.095187
I20260812 06:17:59.692153 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.054s	user 0.021s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23566,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.692706 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=2.188937
I20260812 06:17:59.704527 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4388,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.704980 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818): perf score=1.000000
I20260812 06:17:59.885113 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.180s	user 0.103s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":209,"lbm_read_time_us":11508,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33047,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":166016,"update_count":2500}
I20260812 06:17:59.885828 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=14.095187
I20260812 06:17:59.944119 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.058s	user 0.024s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18844,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.944834 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=2.188937
I20260812 06:17:59.955417 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4223,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.956012 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushMRSOp(bfd4e6a8adbe4698af98afa11948a818): perf score=1.000000
I20260812 06:17:59.996886 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushMRSOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.041s	user 0.024s	sys 0.005s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":203,"dirs.run_wall_time_us":1430,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1534,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:59.997565 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling LogGCOp(bfd4e6a8adbe4698af98afa11948a818): free 120100379 bytes of WAL
I20260812 06:17:59.997786 12158 log_reader.cc:385] T bfd4e6a8adbe4698af98afa11948a818: removed 12 log segments from log reader
I20260812 06:17:59.997830 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000015 (ops 70-74)
I20260812 06:17:59.997859 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000016 (ops 75-78)
I20260812 06:17:59.997921 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000017 (ops 79-83)
I20260812 06:17:59.997992 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000018 (ops 84-88)
I20260812 06:17:59.998032 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000019 (ops 89-93)
I20260812 06:17:59.998091 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000020 (ops 94-98)
I20260812 06:17:59.998144 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000021 (ops 99-103)
I20260812 06:17:59.998180 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000022 (ops 104-108)
I20260812 06:17:59.998216 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000023 (ops 109-112)
I20260812 06:17:59.998253 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000024 (ops 113-117)
I20260812 06:17:59.998291 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000025 (ops 118-122)
I20260812 06:17:59.998327 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000026 (ops 123-126)
I20260812 06:18:00.021660 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: LogGCOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.024s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:00.022073 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=2.188937
I20260812 06:18:00.044556 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.022s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5743,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.045027 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling UndoDeltaBlockGCOp(bfd4e6a8adbe4698af98afa11948a818): 447 bytes on disk
I20260812 06:18:00.045408 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: UndoDeltaBlockGCOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:18:00.045900 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=2.188937
I20260812 06:18:00.056094 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3914,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.056790 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818): perf score=1.000000
I20260812 06:18:00.271087 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.214s	user 0.119s	sys 0.095s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979751,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":739,"lbm_read_time_us":14832,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38429,"lbm_writes_lt_1ms":743,"mutex_wait_us":89,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3712,"thread_start_us":117,"threads_started":1,"update_count":3500}
I20260812 06:18:00.271863 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=18.063937
I20260812 06:18:00.327875 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.056s	user 0.028s	sys 0.024s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":25279,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:00.328437 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=2.188937
I20260812 06:18:00.349419 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.021s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5888,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.349926 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=2.188937
I20260812 06:18:00.359860 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3801,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.360443 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818): perf score=1.000000
I20260812 06:18:00.541199 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.181s	user 0.152s	sys 0.029s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979634,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":160,"lbm_read_time_us":12887,"lbm_reads_lt_1ms":773,"lbm_write_time_us":38146,"lbm_writes_lt_1ms":743,"mutex_wait_us":42,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":3500}
I20260812 06:18:00.541849 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=14.095187
I20260812 06:18:00.593132 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.049s	user 0.040s	sys 0.008s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":21298,"lbm_writes_lt_1ms":413,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2050}
I20260812 06:18:00.593842 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=2.188937
I20260812 06:18:00.609184 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.015s	user 0.005s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5973,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:00.609644 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818): perf score=1.000000
I20260812 06:18:00.768558 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.159s	user 0.097s	sys 0.046s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774677,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":483,"lbm_read_time_us":10977,"lbm_reads_lt_1ms":568,"lbm_write_time_us":28330,"lbm_writes_lt_1ms":543,"mutex_wait_us":102,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:18:00.769346 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=14.095187
I20260812 06:18:00.825424 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.056s	user 0.022s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23523,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:00.825958 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=2.188937
I20260812 06:18:00.839913 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5192,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.840719 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818): perf score=1.000000
I20260812 06:18:01.014500 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.174s	user 0.113s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":723,"lbm_read_time_us":10172,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29341,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2500}
I20260812 06:18:01.015244 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=14.095187
I20260812 06:18:01.059442 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.044s	user 0.029s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19958,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:01.059931 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818): perf score=1.000000
I20260812 06:18:01.200491 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.140s	user 0.090s	sys 0.045s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":576,"lbm_read_time_us":10240,"lbm_reads_lt_1ms":467,"lbm_write_time_us":21147,"lbm_writes_lt_1ms":443,"mutex_wait_us":279,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:18:01.201283 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=11.118625
I20260812 06:18:01.238400 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.037s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15746,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:01.239115 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=2.188937
I20260812 06:18:01.256377 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.017s	user 0.009s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4931,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:01.256991 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushMRSOp(bfd4e6a8adbe4698af98afa11948a818): perf score=1.000000
I20260812 06:18:01.296350 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushMRSOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.039s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":259,"dirs.run_wall_time_us":1381,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2332,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:01.297047 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling UndoDeltaBlockGCOp(bfd4e6a8adbe4698af98afa11948a818): 447 bytes on disk
I20260812 06:18:01.297609 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: UndoDeltaBlockGCOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:18:01.298130 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=3.181125
I20260812 06:18:01.319826 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.022s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5075,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:01.320453 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling LogGCOp(bfd4e6a8adbe4698af98afa11948a818): free 112239544 bytes of WAL
I20260812 06:18:01.320710 12158 log_reader.cc:385] T bfd4e6a8adbe4698af98afa11948a818: removed 11 log segments from log reader
I20260812 06:18:01.320784 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000027 (ops 127-131)
I20260812 06:18:01.320868 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000028 (ops 132-136)
I20260812 06:18:01.320931 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000029 (ops 137-141)
I20260812 06:18:01.321005 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000030 (ops 142-146)
I20260812 06:18:01.321072 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000031 (ops 147-151)
I20260812 06:18:01.321147 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000032 (ops 152-156)
I20260812 06:18:01.321183 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000033 (ops 157-161)
I20260812 06:18:01.321210 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000034 (ops 162-166)
I20260812 06:18:01.321265 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000035 (ops 167-171)
I20260812 06:18:01.321305 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000036 (ops 172-176)
I20260812 06:18:01.321349 12158 log.cc:1079] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: Deleting log segment in path: /tmp/dist-test-taskqRIoM_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515471327857-11654-0/minicluster-data/ts-0-root/wals/bfd4e6a8adbe4698af98afa11948a818/wal-000000037 (ops 177-180)
I20260812 06:18:01.345772 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: LogGCOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.025s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:18:01.346184 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=2.188937
I20260812 06:18:01.369680 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.023s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5036,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.370138 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=2.188937
I20260812 06:18:01.380219 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3893,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:01.380709 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818): perf score=1.000000
I20260812 06:18:01.614977 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.234s	user 0.134s	sys 0.096s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979851,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1796,"lbm_read_time_us":14591,"lbm_reads_lt_1ms":775,"lbm_write_time_us":38804,"lbm_writes_lt_1ms":743,"mutex_wait_us":422,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":18432,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:18:01.615818 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=18.063937
I20260812 06:18:01.687989 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.072s	user 0.041s	sys 0.012s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":25535,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:01.688525 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818): perf score=2.188937
I20260812 06:18:01.699267 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: FlushDeltaMemStoresOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.011s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4026,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.699986 12260 maintenance_manager.cc:419] P 5be970abfb714bb8afb216a65cba2d8e: Scheduling MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818): perf score=1.000000
I20260812 06:18:01.779904 11654 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.898s	user 1.829s	sys 0.209s
I20260812 06:18:01.849735 11654 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.069s	user 0.003s	sys 0.000s
I20260812 06:18:01.850296 11654 tablet_server.cc:179] TabletServer@127.11.97.129:0 shutting down...
I20260812 06:18:01.893105 12158 maintenance_manager.cc:643] P 5be970abfb714bb8afb216a65cba2d8e: MajorDeltaCompactionOp(bfd4e6a8adbe4698af98afa11948a818) complete. Timing: real 0.193s	user 0.113s	sys 0.079s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":420,"lbm_read_time_us":13674,"lbm_reads_lt_1ms":668,"lbm_write_time_us":32801,"lbm_writes_lt_1ms":643,"mutex_wait_us":86,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":3000}
I20260812 06:18:01.896075 11654 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:01.896457 11654 tablet_replica.cc:333] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e: stopping tablet replica
I20260812 06:18:01.896608 11654 raft_consensus.cc:2243] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:01.896800 11654 raft_consensus.cc:2272] T bfd4e6a8adbe4698af98afa11948a818 P 5be970abfb714bb8afb216a65cba2d8e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:01.914409 11654 tablet_server.cc:196] TabletServer@127.11.97.129:0 shutdown complete.
I20260812 06:18:01.946187 11654 master.cc:562] Master@127.11.97.190:33155 shutting down...
I20260812 06:18:01.949550 11654 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:01.949765 11654 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:01.949862 11654 tablet_replica.cc:333] T 00000000000000000000000000000000 P 57ac7c7c2df548cd91179080d11bd5bb: stopping tablet replica
I20260812 06:18:01.962265 11654 master.cc:584] Master@127.11.97.190:33155 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5368 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10719 ms total)

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