[==========] 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:20:20.773368  4692 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.4.149.62:38315
I20260812 06:20:20.774401  4692 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:20:20.775014  4692 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:20.781371  4702 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:20:20.781421  4692 server_base.cc:1061] running on GCE node
W20260812 06:20:20.781371  4704 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:20:20.781678  4706 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:20:20.782172  4692 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:20.782269  4692 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:20:20.782300  4692 hybrid_clock.cc:648] HybridClock initialized: now 1786515620782298 us; error 0 us; skew 500 ppm
I20260812 06:20:20.783942  4692 webserver.cc:533] Webserver started at http://127.4.149.62:41227/ using document root <none> and password file <none>
I20260812 06:20:20.784502  4692 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:20.784562  4692 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:20.784742  4692 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:20.786273  4692 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/master-0-root/instance:
uuid: "82c8d8e7bd594177b2f5a90e4a417e50"
format_stamp: "Formatted at 2026-08-12 06:20:20 on dist-test-slave-gmjp"
I20260812 06:20:20.789603  4692 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.001s	sys 0.003s
I20260812 06:20:20.791508  4714 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:20:20.792496  4692 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:20.792651  4692 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/master-0-root
uuid: "82c8d8e7bd594177b2f5a90e4a417e50"
format_stamp: "Formatted at 2026-08-12 06:20:20 on dist-test-slave-gmjp"
I20260812 06:20:20.792744  4692 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-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:20:20.807397  4692 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:20.807972  4692 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:20:20.808245  4692 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:20.816078  4692 rpc_server.cc:307] RPC server started. Bound to: 127.4.149.62:38315
I20260812 06:20:20.816090  4804 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.4.149.62:38315 every 8 connection(s)
I20260812 06:20:20.818339  4805 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:20:20.823613  4805 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50: Bootstrap starting.
I20260812 06:20:20.825989  4805 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:20.826857  4805 log.cc:826] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:20.828598  4805 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50: No bootstrap required, opened a new log
I20260812 06:20:20.831271  4805 raft_consensus.cc:359] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "82c8d8e7bd594177b2f5a90e4a417e50" member_type: VOTER }
I20260812 06:20:20.831430  4805 raft_consensus.cc:385] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:20.831480  4805 raft_consensus.cc:740] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 82c8d8e7bd594177b2f5a90e4a417e50, State: Initialized, Role: FOLLOWER
I20260812 06:20:20.832000  4805 consensus_queue.cc:260] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50 [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: "82c8d8e7bd594177b2f5a90e4a417e50" member_type: VOTER }
I20260812 06:20:20.832129  4805 raft_consensus.cc:399] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:20.832268  4805 raft_consensus.cc:493] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:20.832374  4805 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:20.833133  4805 raft_consensus.cc:515] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "82c8d8e7bd594177b2f5a90e4a417e50" member_type: VOTER }
I20260812 06:20:20.833508  4805 leader_election.cc:304] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50 [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: 82c8d8e7bd594177b2f5a90e4a417e50; no voters: 
I20260812 06:20:20.833760  4805 leader_election.cc:290] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:20.833864  4809 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:20.834182  4809 raft_consensus.cc:697] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50 [term 1 LEADER]: Becoming Leader. State: Replica: 82c8d8e7bd594177b2f5a90e4a417e50, State: Running, Role: LEADER
I20260812 06:20:20.834574  4809 consensus_queue.cc:237] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50 [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: "82c8d8e7bd594177b2f5a90e4a417e50" member_type: VOTER }
I20260812 06:20:20.834827  4805 sys_catalog.cc:565] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:20.836495  4810 sys_catalog.cc:455] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 82c8d8e7bd594177b2f5a90e4a417e50. Latest consensus state: current_term: 1 leader_uuid: "82c8d8e7bd594177b2f5a90e4a417e50" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "82c8d8e7bd594177b2f5a90e4a417e50" member_type: VOTER } }
I20260812 06:20:20.836488  4812 sys_catalog.cc:455] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "82c8d8e7bd594177b2f5a90e4a417e50" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "82c8d8e7bd594177b2f5a90e4a417e50" member_type: VOTER } }
I20260812 06:20:20.836638  4810 sys_catalog.cc:458] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:20.836638  4812 sys_catalog.cc:458] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:20.837343  4692 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:20:20.839461  4835 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:20:20.839524  4835 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:20:20.839607  4831 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:20.840421  4831 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:20.845279  4831 catalog_manager.cc:1383] Generated new cluster ID: 3c1ac1c0435c43f080c21a434465e605
I20260812 06:20:20.845352  4831 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:20.852469  4831 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:20.853335  4831 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:20.865443  4831 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50: Generated new TSK 0
I20260812 06:20:20.866056  4831 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:20.870025  4692 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:20.872673  4840 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:20:20.872881  4839 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:20:20.872730  4844 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:20:20.873005  4692 server_base.cc:1061] running on GCE node
I20260812 06:20:20.873365  4692 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:20.873446  4692 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:20:20.873476  4692 hybrid_clock.cc:648] HybridClock initialized: now 1786515620873475 us; error 0 us; skew 500 ppm
I20260812 06:20:20.874408  4692 webserver.cc:533] Webserver started at http://127.4.149.1:46029/ using document root <none> and password file <none>
I20260812 06:20:20.874596  4692 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:20.874670  4692 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:20.874747  4692 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:20.875146  4692 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/instance:
uuid: "51c8dbf9c31b442cb57e6bbb6a174cbf"
format_stamp: "Formatted at 2026-08-12 06:20:20 on dist-test-slave-gmjp"
I20260812 06:20:20.876832  4692 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:20.878111  4856 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:20:20.878381  4692 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:20.878479  4692 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root
uuid: "51c8dbf9c31b442cb57e6bbb6a174cbf"
format_stamp: "Formatted at 2026-08-12 06:20:20 on dist-test-slave-gmjp"
I20260812 06:20:20.878582  4692 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-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:20:20.905738  4692 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:20.907511  4692 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:20.908360  4692 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:20.909472  4692 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:20.909581  4692 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:20.909683  4692 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:20.909747  4692 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:20.917841  4692 rpc_server.cc:307] RPC server started. Bound to: 127.4.149.1:44283
I20260812 06:20:20.917881  4980 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.4.149.1:44283 every 8 connection(s)
I20260812 06:20:20.929679  4983 heartbeater.cc:344] Connected to a master server at 127.4.149.62:38315
I20260812 06:20:20.929940  4983 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:20.930470  4983 heartbeater.cc:507] Master 127.4.149.62:38315 requested a full tablet report, sending...
I20260812 06:20:20.931927  4744 ts_manager.cc:194] Registered new tserver with Master: 51c8dbf9c31b442cb57e6bbb6a174cbf (127.4.149.1:44283)
I20260812 06:20:20.932197  4692 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013431474s
I20260812 06:20:20.934120  4744 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:45310
I20260812 06:20:20.943426  4744 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:45312:
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:20:20.958421  4912 tablet_service.cc:1511] Processing CreateTablet for tablet c6545f41ab8c4658be9da5b37583892d (DEFAULT_TABLE table=heavy-update-compaction-test [id=847268813b444726b6ddc844c4d77be6]), partition=
I20260812 06:20:20.958912  4912 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet c6545f41ab8c4658be9da5b37583892d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:20.961762  5015 tablet_bootstrap.cc:492] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Bootstrap starting.
I20260812 06:20:20.962702  5015 tablet_bootstrap.cc:654] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:20.963817  5015 tablet_bootstrap.cc:492] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: No bootstrap required, opened a new log
I20260812 06:20:20.963899  5015 ts_tablet_manager.cc:1403] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:20.964387  5015 raft_consensus.cc:359] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "51c8dbf9c31b442cb57e6bbb6a174cbf" member_type: VOTER last_known_addr { host: "127.4.149.1" port: 44283 } }
I20260812 06:20:20.964491  5015 raft_consensus.cc:385] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:20.964515  5015 raft_consensus.cc:740] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 51c8dbf9c31b442cb57e6bbb6a174cbf, State: Initialized, Role: FOLLOWER
I20260812 06:20:20.964712  5015 consensus_queue.cc:260] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf [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: "51c8dbf9c31b442cb57e6bbb6a174cbf" member_type: VOTER last_known_addr { host: "127.4.149.1" port: 44283 } }
I20260812 06:20:20.964794  5015 raft_consensus.cc:399] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:20.964852  5015 raft_consensus.cc:493] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:20.964912  5015 raft_consensus.cc:3060] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:20.965888  5015 raft_consensus.cc:515] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "51c8dbf9c31b442cb57e6bbb6a174cbf" member_type: VOTER last_known_addr { host: "127.4.149.1" port: 44283 } }
I20260812 06:20:20.966033  5015 leader_election.cc:304] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf [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: 51c8dbf9c31b442cb57e6bbb6a174cbf; no voters: 
I20260812 06:20:20.966248  5015 leader_election.cc:290] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:20.966346  5017 raft_consensus.cc:2804] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:20.966531  5017 raft_consensus.cc:697] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf [term 1 LEADER]: Becoming Leader. State: Replica: 51c8dbf9c31b442cb57e6bbb6a174cbf, State: Running, Role: LEADER
I20260812 06:20:20.966626  5015 ts_tablet_manager.cc:1434] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:20.966733  5017 consensus_queue.cc:237] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf [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: "51c8dbf9c31b442cb57e6bbb6a174cbf" member_type: VOTER last_known_addr { host: "127.4.149.1" port: 44283 } }
I20260812 06:20:20.966822  4983 heartbeater.cc:499] Master 127.4.149.62:38315 was elected leader, sending a full tablet report...
I20260812 06:20:20.969662  4744 catalog_manager.cc:5719] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf reported cstate change: term changed from 0 to 1, leader changed from <none> to 51c8dbf9c31b442cb57e6bbb6a174cbf (127.4.149.1). New cstate: current_term: 1 leader_uuid: "51c8dbf9c31b442cb57e6bbb6a174cbf" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "51c8dbf9c31b442cb57e6bbb6a174cbf" member_type: VOTER last_known_addr { host: "127.4.149.1" port: 44283 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:21.035084  4692 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.012s	sys 0.013s
I20260812 06:20:21.169132  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushMRSOp(c6545f41ab8c4658be9da5b37583892d): perf score=19.054940
I20260812 06:20:21.351521  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushMRSOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.182s	user 0.137s	sys 0.033s Metrics: {"bytes_written":12307493,"cfile_init":1,"compiler_manager_pool.queue_time_us":208,"delete_count":0,"dirs.queue_time_us":47,"dirs.run_cpu_time_us":178,"dirs.run_wall_time_us":907,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":46416,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":756,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":896,"thread_start_us":138,"threads_started":1,"update_count":1500}
I20260812 06:20:21.352797  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling LogGCOp(c6545f41ab8c4658be9da5b37583892d): free 20290830 bytes of WAL
I20260812 06:20:21.353111  4862 log_reader.cc:385] T c6545f41ab8c4658be9da5b37583892d: removed 2 log segments from log reader
I20260812 06:20:21.353180  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000001 (ops 1-6)
I20260812 06:20:21.353291  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000002 (ops 7-10)
I20260812 06:20:21.358739  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: LogGCOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:21.359105  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=2.188937
I20260812 06:20:21.376827  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.018s	user 0.004s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6621,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.377329  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling UndoDeltaBlockGCOp(c6545f41ab8c4658be9da5b37583892d): 16411396 bytes on disk
I20260812 06:20:21.378006  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: UndoDeltaBlockGCOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:20:21.378438  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d): perf score=1.000000
I20260812 06:20:21.517047  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.138s	user 0.079s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":279,"lbm_read_time_us":7397,"lbm_reads_lt_1ms":460,"lbm_write_time_us":23192,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8576,"thread_start_us":299,"threads_started":5,"update_count":2000}
I20260812 06:20:21.517604  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=10.126437
I20260812 06:20:21.547430  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.030s	user 0.020s	sys 0.007s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":12965,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.547932  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=2.188937
I20260812 06:20:21.561950  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4978,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.562397  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d): perf score=1.000000
I20260812 06:20:21.691391  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.129s	user 0.101s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":945,"lbm_read_time_us":9299,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26112,"lbm_writes_lt_1ms":443,"mutex_wait_us":315,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16896,"update_count":2000}
I20260812 06:20:21.691840  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=10.126437
I20260812 06:20:21.737860  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.046s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16986,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.738299  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=2.188937
I20260812 06:20:21.749225  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3997,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.749717  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d): perf score=1.000000
I20260812 06:20:21.867683  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.118s	user 0.085s	sys 0.032s 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":291,"lbm_read_time_us":7783,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25137,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":59264,"update_count":2000}
I20260812 06:20:21.868192  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=10.126437
I20260812 06:20:21.925519  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.057s	user 0.018s	sys 0.027s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17323,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.926013  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=2.188937
I20260812 06:20:21.936793  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4088,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.937289  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d): perf score=1.000000
I20260812 06:20:22.089425  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.152s	user 0.096s	sys 0.056s 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":961,"lbm_read_time_us":10018,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27614,"lbm_writes_lt_1ms":443,"mutex_wait_us":271,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2000}
I20260812 06:20:22.090035  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=10.126437
I20260812 06:20:22.132247  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.042s	user 0.019s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15710,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.132656  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=2.188937
I20260812 06:20:22.143122  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4141,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.143842  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d): perf score=1.000000
I20260812 06:20:22.260874  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.117s	user 0.093s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":519,"lbm_read_time_us":8397,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22327,"lbm_writes_lt_1ms":443,"mutex_wait_us":32,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":32384,"update_count":2000}
I20260812 06:20:22.261518  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=10.126437
I20260812 06:20:22.304181  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.042s	user 0.016s	sys 0.023s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":20571,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.304780  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=2.188937
I20260812 06:20:22.318961  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5072,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.319471  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d): perf score=1.000000
I20260812 06:20:22.438187  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.119s	user 0.094s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":416,"lbm_read_time_us":8096,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22814,"lbm_writes_lt_1ms":443,"mutex_wait_us":98,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":2000}
I20260812 06:20:22.438882  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=10.126437
I20260812 06:20:22.482132  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.043s	user 0.022s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15418,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1500}
I20260812 06:20:22.482709  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=2.188937
I20260812 06:20:22.494029  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4447,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.494490  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushMRSOp(c6545f41ab8c4658be9da5b37583892d): perf score=1.000000
I20260812 06:20:22.541668  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushMRSOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.047s	user 0.027s	sys 0.008s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":222,"dirs.run_wall_time_us":1272,"drs_written":1,"lbm_read_time_us":111,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2195,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:22.542557  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling LogGCOp(c6545f41ab8c4658be9da5b37583892d): free 112692309 bytes of WAL
I20260812 06:20:22.542809  4862 log_reader.cc:385] T c6545f41ab8c4658be9da5b37583892d: removed 11 log segments from log reader
I20260812 06:20:22.542876  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000003 (ops 11-15)
I20260812 06:20:22.542937  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000004 (ops 16-20)
I20260812 06:20:22.542999  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000005 (ops 21-25)
I20260812 06:20:22.543048  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000006 (ops 26-30)
I20260812 06:20:22.543092  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000007 (ops 31-35)
I20260812 06:20:22.543136  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000008 (ops 36-40)
I20260812 06:20:22.543180  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000009 (ops 41-45)
I20260812 06:20:22.543224  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000010 (ops 46-50)
I20260812 06:20:22.543275  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000011 (ops 51-55)
I20260812 06:20:22.543321  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000012 (ops 56-60)
I20260812 06:20:22.543401  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000013 (ops 61-65)
I20260812 06:20:22.567147  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: LogGCOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.024s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:20:22.567751  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling UndoDeltaBlockGCOp(c6545f41ab8c4658be9da5b37583892d): 447 bytes on disk
I20260812 06:20:22.568406  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: UndoDeltaBlockGCOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":123,"lbm_reads_lt_1ms":4}
I20260812 06:20:22.568972  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=3.181125
I20260812 06:20:22.587597  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.018s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5184,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:22.588001  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=2.188937
I20260812 06:20:22.597244  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3420,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:22.597688  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d): perf score=1.000000
I20260812 06:20:22.789921  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.192s	user 0.124s	sys 0.067s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":967,"lbm_read_time_us":12913,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35549,"lbm_writes_lt_1ms":643,"mutex_wait_us":340,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":33664,"thread_start_us":83,"threads_started":1,"update_count":3000}
I20260812 06:20:22.790692  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=14.095187
I20260812 06:20:22.851006  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.060s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":21083,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.851495  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=2.188937
I20260812 06:20:22.861729  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3953,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.862285  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d): perf score=1.000000
I20260812 06:20:23.038092  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.176s	user 0.102s	sys 0.067s 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":220,"lbm_read_time_us":11482,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29689,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2500}
I20260812 06:20:23.038725  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=14.095187
I20260812 06:20:23.087970  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.049s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21526,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.088449  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=2.188937
I20260812 06:20:23.099246  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4097,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.099921  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d): perf score=1.000000
I20260812 06:20:23.286291  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.186s	user 0.117s	sys 0.063s 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":614,"lbm_read_time_us":12173,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31272,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:23.286841  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=14.095187
I20260812 06:20:23.344097  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.057s	user 0.019s	sys 0.034s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20609,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.344678  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=2.188937
I20260812 06:20:23.354996  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4060,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.355417  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d): perf score=1.000000
I20260812 06:20:23.523710  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.168s	user 0.108s	sys 0.060s 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":159,"lbm_read_time_us":12144,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29316,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:23.524430  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=11.118625
I20260812 06:20:23.560956  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.036s	user 0.025s	sys 0.009s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15114,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:23.561510  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=2.188937
I20260812 06:20:23.587879  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.026s	user 0.011s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4860,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.588433  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=2.188937
I20260812 06:20:23.598219  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3750,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.598650  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d): perf score=1.000000
I20260812 06:20:23.768186  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.169s	user 0.114s	sys 0.053s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":889,"lbm_read_time_us":13330,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28169,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:23.769058  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=11.118625
I20260812 06:20:23.814008  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.045s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":20208,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:20:23.814463  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=2.188937
I20260812 06:20:23.825325  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4212,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.825771  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=2.188937
I20260812 06:20:23.838806  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4949,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.839262  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d): perf score=1.000000
I20260812 06:20:24.011112  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.172s	user 0.092s	sys 0.075s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":596,"lbm_read_time_us":10797,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29080,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:20:24.011977  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=11.118625
I20260812 06:20:24.046411  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.034s	user 0.015s	sys 0.017s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14925,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:24.046941  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=2.188937
I20260812 06:20:24.069986  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.023s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5954,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:24.070480  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=2.188937
I20260812 06:20:24.082307  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4497,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.082968  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushMRSOp(c6545f41ab8c4658be9da5b37583892d): perf score=1.000000
I20260812 06:20:24.115438  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushMRSOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.032s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":1227,"drs_written":1,"lbm_read_time_us":84,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1777,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:24.116271  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling LogGCOp(c6545f41ab8c4658be9da5b37583892d): free 133024419 bytes of WAL
I20260812 06:20:24.116498  4862 log_reader.cc:385] T c6545f41ab8c4658be9da5b37583892d: removed 13 log segments from log reader
I20260812 06:20:24.116545  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000014 (ops 66-70)
I20260812 06:20:24.116575  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000015 (ops 71-75)
I20260812 06:20:24.116632  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000016 (ops 76-80)
I20260812 06:20:24.116678  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000017 (ops 81-84)
I20260812 06:20:24.116732  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000018 (ops 85-89)
I20260812 06:20:24.116772  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000019 (ops 90-94)
I20260812 06:20:24.116817  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000020 (ops 95-99)
I20260812 06:20:24.116858  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000021 (ops 100-104)
I20260812 06:20:24.116897  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000022 (ops 105-109)
I20260812 06:20:24.116937  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000023 (ops 110-114)
I20260812 06:20:24.116976  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000024 (ops 115-119)
I20260812 06:20:24.117015  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000025 (ops 120-124)
I20260812 06:20:24.117058  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000026 (ops 125-129)
I20260812 06:20:24.148072  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: LogGCOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.032s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:20:24.148566  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling UndoDeltaBlockGCOp(c6545f41ab8c4658be9da5b37583892d): 492 bytes on disk
I20260812 06:20:24.149029  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: UndoDeltaBlockGCOp(c6545f41ab8c4658be9da5b37583892d) 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:20:24.149559  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=3.181125
I20260812 06:20:24.169486  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.020s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7213,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:24.169976  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=2.188937
I20260812 06:20:24.179191  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3474,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:24.179618  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d): perf score=1.000000
I20260812 06:20:24.419696  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.240s	user 0.167s	sys 0.060s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979847,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":666,"lbm_read_time_us":14233,"lbm_reads_lt_1ms":775,"lbm_write_time_us":41192,"lbm_writes_lt_1ms":743,"mutex_wait_us":28,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":32896,"thread_start_us":89,"threads_started":1,"update_count":3500}
I20260812 06:20:24.420547  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=18.063937
I20260812 06:20:24.491496  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.071s	user 0.031s	sys 0.032s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":31804,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:20:24.491997  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=2.188937
I20260812 06:20:24.503647  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3948,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.504285  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d): perf score=1.000000
I20260812 06:20:24.706975  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.203s	user 0.145s	sys 0.057s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":337,"lbm_read_time_us":14134,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33697,"lbm_writes_lt_1ms":643,"mutex_wait_us":42,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":61696,"update_count":3000}
I20260812 06:20:24.707626  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=16.079562
I20260812 06:20:24.770805  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.063s	user 0.037s	sys 0.008s Metrics: {"bytes_written":17968827,"delete_count":0,"lbm_write_time_us":21290,"lbm_writes_lt_1ms":441,"reinsert_count":0,"update_count":2190}
I20260812 06:20:24.771399  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=5.165500
I20260812 06:20:24.790165  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.019s	user 0.009s	sys 0.008s Metrics: {"bytes_written":6646162,"delete_count":0,"lbm_write_time_us":7403,"lbm_writes_lt_1ms":165,"reinsert_count":0,"update_count":810}
I20260812 06:20:24.790692  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d): perf score=1.000000
I20260812 06:20:24.995240  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.204s	user 0.152s	sys 0.048s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877111,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1159,"lbm_read_time_us":13889,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35578,"lbm_writes_lt_1ms":643,"mutex_wait_us":58,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":76928,"update_count":3000}
I20260812 06:20:24.996961  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=15.087375
I20260812 06:20:25.056886  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.060s	user 0.032s	sys 0.021s Metrics: {"bytes_written":17681651,"delete_count":0,"lbm_write_time_us":23178,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":433,"reinsert_count":0,"update_count":2155}
I20260812 06:20:25.057392  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=5.165500
I20260812 06:20:25.077481  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.020s	user 0.006s	sys 0.012s Metrics: {"bytes_written":6933333,"delete_count":0,"lbm_write_time_us":7951,"lbm_writes_lt_1ms":172,"reinsert_count":0,"update_count":845}
I20260812 06:20:25.078127  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d): perf score=1.000000
I20260812 06:20:25.280068  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.202s	user 0.121s	sys 0.077s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877106,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":165,"lbm_read_time_us":13310,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36141,"lbm_writes_lt_1ms":643,"mutex_wait_us":31,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:20:25.280823  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=16.079562
I20260812 06:20:25.345463  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.064s	user 0.017s	sys 0.035s Metrics: {"bytes_written":17804724,"delete_count":0,"lbm_write_time_us":24387,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":436,"reinsert_count":0,"update_count":2170}
I20260812 06:20:25.345974  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=5.165500
I20260812 06:20:25.363459  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":6810261,"delete_count":0,"lbm_write_time_us":7307,"lbm_writes_lt_1ms":169,"reinsert_count":0,"update_count":830}
I20260812 06:20:25.364013  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d): perf score=1.000000
I20260812 06:20:25.572583  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.208s	user 0.132s	sys 0.071s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877107,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":152,"lbm_read_time_us":14682,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36772,"lbm_writes_lt_1ms":643,"mutex_wait_us":20,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":3000}
I20260812 06:20:25.573383  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=18.063937
I20260812 06:20:25.647586  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.074s	user 0.046s	sys 0.025s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":32773,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:25.648115  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=2.188937
I20260812 06:20:25.659168  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3923,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.659659  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushMRSOp(c6545f41ab8c4658be9da5b37583892d): perf score=1.000000
I20260812 06:20:25.693290  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushMRSOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.033s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":221,"dirs.run_wall_time_us":1120,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1761,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:25.693977  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling LogGCOp(c6545f41ab8c4658be9da5b37583892d): free 128867690 bytes of WAL
I20260812 06:20:25.694211  4862 log_reader.cc:385] T c6545f41ab8c4658be9da5b37583892d: removed 13 log segments from log reader
I20260812 06:20:25.694271  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000027 (ops 130-134)
I20260812 06:20:25.694325  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000028 (ops 135-138)
I20260812 06:20:25.694380  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000029 (ops 139-143)
I20260812 06:20:25.694424  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000030 (ops 144-148)
I20260812 06:20:25.694463  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000031 (ops 149-153)
I20260812 06:20:25.694499  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000032 (ops 154-158)
I20260812 06:20:25.694536  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000033 (ops 159-162)
I20260812 06:20:25.694573  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000034 (ops 163-167)
I20260812 06:20:25.694609  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000035 (ops 168-172)
I20260812 06:20:25.694646  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000036 (ops 173-177)
I20260812 06:20:25.694682  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000037 (ops 178-182)
I20260812 06:20:25.694718  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000038 (ops 183-186)
I20260812 06:20:25.694756  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000039 (ops 187-191)
I20260812 06:20:25.724036  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: LogGCOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.030s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:25.724464  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d): perf score=6.157687
I20260812 06:20:25.751756  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: FlushDeltaMemStoresOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.027s	user 0.004s	sys 0.016s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9659,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:25.752424  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling LogGCOp(c6545f41ab8c4658be9da5b37583892d): free 12018006 bytes of WAL
I20260812 06:20:25.752691  4862 log_reader.cc:385] T c6545f41ab8c4658be9da5b37583892d: removed 1 log segments from log reader
I20260812 06:20:25.752758  4862 log.cc:1079] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/c6545f41ab8c4658be9da5b37583892d/wal-000000040 (ops 192-196)
I20260812 06:20:25.755692  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: LogGCOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:25.756036  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling UndoDeltaBlockGCOp(c6545f41ab8c4658be9da5b37583892d): 493 bytes on disk
I20260812 06:20:25.756508  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: UndoDeltaBlockGCOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:20:25.757169  4987 maintenance_manager.cc:419] P 51c8dbf9c31b442cb57e6bbb6a174cbf: Scheduling MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d): perf score=1.000000
I20260812 06:20:25.820226  4692 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.785s	user 1.753s	sys 0.159s
I20260812 06:20:25.921267  4692 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.100s	user 0.003s	sys 0.000s
I20260812 06:20:25.921926  4692 tablet_server.cc:179] TabletServer@127.4.149.1:0 shutting down...
I20260812 06:20:25.973800  4862 maintenance_manager.cc:643] P 51c8dbf9c31b442cb57e6bbb6a174cbf: MajorDeltaCompactionOp(c6545f41ab8c4658be9da5b37583892d) complete. Timing: real 0.216s	user 0.147s	sys 0.068s Metrics: {"cfile_cache_miss":833,"cfile_cache_miss_bytes":37082047,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":641,"lbm_read_time_us":18589,"lbm_reads_lt_1ms":861,"lbm_write_time_us":37017,"lbm_writes_lt_1ms":843,"mutex_wait_us":19,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":13440,"thread_start_us":87,"threads_started":1,"update_count":4000}
I20260812 06:20:25.974817  4692 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:25.975420  4692 tablet_replica.cc:333] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf: stopping tablet replica
I20260812 06:20:25.975687  4692 raft_consensus.cc:2243] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:25.975934  4692 raft_consensus.cc:2272] T c6545f41ab8c4658be9da5b37583892d P 51c8dbf9c31b442cb57e6bbb6a174cbf [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:25.992782  4692 tablet_server.cc:196] TabletServer@127.4.149.1:0 shutdown complete.
I20260812 06:20:26.046206  4692 master.cc:562] Master@127.4.149.62:38315 shutting down...
I20260812 06:20:26.049917  4692 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:26.050127  4692 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:26.050228  4692 tablet_replica.cc:333] T 00000000000000000000000000000000 P 82c8d8e7bd594177b2f5a90e4a417e50: stopping tablet replica
I20260812 06:20:26.062633  4692 master.cc:584] Master@127.4.149.62:38315 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5374 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:26.147217  4692 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.4.149.62:46595
I20260812 06:20:26.147634  4692 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:26.149955  5051 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:20:26.150079  4692 server_base.cc:1061] running on GCE node
W20260812 06:20:26.150131  5049 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:20:26.150126  5047 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:20:26.150506  4692 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:26.150547  4692 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:20:26.150563  4692 hybrid_clock.cc:648] HybridClock initialized: now 1786515626150562 us; error 0 us; skew 500 ppm
I20260812 06:20:26.151409  4692 webserver.cc:533] Webserver started at http://127.4.149.62:36281/ using document root <none> and password file <none>
I20260812 06:20:26.151543  4692 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:26.151585  4692 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:26.151646  4692 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:26.152099  4692 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/master-0-root/instance:
uuid: "1f4a743e558444d98ab467d81b9e8565"
format_stamp: "Formatted at 2026-08-12 06:20:26 on dist-test-slave-gmjp"
I20260812 06:20:26.153622  4692 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:26.154461  5063 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:20:26.154729  4692 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:26.154826  4692 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/master-0-root
uuid: "1f4a743e558444d98ab467d81b9e8565"
format_stamp: "Formatted at 2026-08-12 06:20:26 on dist-test-slave-gmjp"
I20260812 06:20:26.154912  4692 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-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:20:26.164419  4692 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:26.164743  4692 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:26.168649  4692 rpc_server.cc:307] RPC server started. Bound to: 127.4.149.62:46595
I20260812 06:20:26.173542  5154 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.4.149.62:46595 every 8 connection(s)
I20260812 06:20:26.189606  5155 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:20:26.191622  5155 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565: Bootstrap starting.
I20260812 06:20:26.192427  5155 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:26.193542  5155 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565: No bootstrap required, opened a new log
I20260812 06:20:26.193922  5155 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1f4a743e558444d98ab467d81b9e8565" member_type: VOTER }
I20260812 06:20:26.194010  5155 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:26.194032  5155 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1f4a743e558444d98ab467d81b9e8565, State: Initialized, Role: FOLLOWER
I20260812 06:20:26.194135  5155 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565 [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: "1f4a743e558444d98ab467d81b9e8565" member_type: VOTER }
I20260812 06:20:26.194195  5155 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:26.194217  5155 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:26.194252  5155 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:26.194907  5155 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1f4a743e558444d98ab467d81b9e8565" member_type: VOTER }
I20260812 06:20:26.195021  5155 leader_election.cc:304] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565 [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: 1f4a743e558444d98ab467d81b9e8565; no voters: 
I20260812 06:20:26.195182  5155 leader_election.cc:290] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:26.195324  5161 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:26.195538  5161 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565 [term 1 LEADER]: Becoming Leader. State: Replica: 1f4a743e558444d98ab467d81b9e8565, State: Running, Role: LEADER
I20260812 06:20:26.195701  5155 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:26.195675  5161 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565 [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: "1f4a743e558444d98ab467d81b9e8565" member_type: VOTER }
I20260812 06:20:26.196135  5163 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1f4a743e558444d98ab467d81b9e8565" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1f4a743e558444d98ab467d81b9e8565" member_type: VOTER } }
I20260812 06:20:26.196267  5163 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:26.196161  5164 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1f4a743e558444d98ab467d81b9e8565. Latest consensus state: current_term: 1 leader_uuid: "1f4a743e558444d98ab467d81b9e8565" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1f4a743e558444d98ab467d81b9e8565" member_type: VOTER } }
I20260812 06:20:26.196412  5164 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:26.196992  5167 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:26.198027  5167 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:26.198251  4692 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:26.199837  5167 catalog_manager.cc:1383] Generated new cluster ID: ff471030f32d4c91929842401d76fd0a
I20260812 06:20:26.199884  5167 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:26.228530  5167 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:26.229107  5167 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:26.235050  5167 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565: Generated new TSK 0
I20260812 06:20:26.235210  5167 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:26.262826  4692 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:26.264755  5189 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:20:26.264845  5197 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:20:26.264922  4692 server_base.cc:1061] running on GCE node
W20260812 06:20:26.264798  5190 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:20:26.265141  4692 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:26.265210  4692 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:20:26.265244  4692 hybrid_clock.cc:648] HybridClock initialized: now 1786515626265244 us; error 0 us; skew 500 ppm
I20260812 06:20:26.266103  4692 webserver.cc:533] Webserver started at http://127.4.149.1:35163/ using document root <none> and password file <none>
I20260812 06:20:26.266285  4692 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:26.266366  4692 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:26.266456  4692 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:26.266871  4692 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/instance:
uuid: "104cee39e5e54d96a28e3e80c90acb27"
format_stamp: "Formatted at 2026-08-12 06:20:26 on dist-test-slave-gmjp"
I20260812 06:20:26.268481  4692 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:26.269550  5206 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:20:26.269871  4692 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:26.269963  4692 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root
uuid: "104cee39e5e54d96a28e3e80c90acb27"
format_stamp: "Formatted at 2026-08-12 06:20:26 on dist-test-slave-gmjp"
I20260812 06:20:26.270051  4692 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-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:20:26.282840  4692 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:26.283185  4692 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:26.283500  4692 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:26.283958  4692 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:26.284020  4692 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:26.284076  4692 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:26.284126  4692 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:26.288564  4692 rpc_server.cc:307] RPC server started. Bound to: 127.4.149.1:38809
I20260812 06:20:26.288599  5299 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.4.149.1:38809 every 8 connection(s)
I20260812 06:20:26.297251  5301 heartbeater.cc:344] Connected to a master server at 127.4.149.62:46595
I20260812 06:20:26.297387  5301 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:26.297679  5301 heartbeater.cc:507] Master 127.4.149.62:46595 requested a full tablet report, sending...
I20260812 06:20:26.298458  5094 ts_manager.cc:194] Registered new tserver with Master: 104cee39e5e54d96a28e3e80c90acb27 (127.4.149.1:38809)
I20260812 06:20:26.298897  4692 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009891155s
I20260812 06:20:26.299294  5094 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60356
I20260812 06:20:26.305872  5094 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60360:
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:20:26.315121  5246 tablet_service.cc:1511] Processing CreateTablet for tablet adcb9573d5b646138bd7c5a83d5bcb40 (DEFAULT_TABLE table=heavy-update-compaction-test [id=348e4d3c73e9441f929c52552c80fa95]), partition=
I20260812 06:20:26.315368  5246 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet adcb9573d5b646138bd7c5a83d5bcb40. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:26.317499  5329 tablet_bootstrap.cc:492] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Bootstrap starting.
I20260812 06:20:26.318331  5329 tablet_bootstrap.cc:654] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:26.319401  5329 tablet_bootstrap.cc:492] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: No bootstrap required, opened a new log
I20260812 06:20:26.319521  5329 ts_tablet_manager.cc:1403] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:26.319949  5329 raft_consensus.cc:359] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "104cee39e5e54d96a28e3e80c90acb27" member_type: VOTER last_known_addr { host: "127.4.149.1" port: 38809 } }
I20260812 06:20:26.320081  5329 raft_consensus.cc:385] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:26.320123  5329 raft_consensus.cc:740] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 104cee39e5e54d96a28e3e80c90acb27, State: Initialized, Role: FOLLOWER
I20260812 06:20:26.320293  5329 consensus_queue.cc:260] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27 [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: "104cee39e5e54d96a28e3e80c90acb27" member_type: VOTER last_known_addr { host: "127.4.149.1" port: 38809 } }
I20260812 06:20:26.320396  5329 raft_consensus.cc:399] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:26.320461  5329 raft_consensus.cc:493] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:26.320523  5329 raft_consensus.cc:3060] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:26.321339  5329 raft_consensus.cc:515] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "104cee39e5e54d96a28e3e80c90acb27" member_type: VOTER last_known_addr { host: "127.4.149.1" port: 38809 } }
I20260812 06:20:26.321501  5329 leader_election.cc:304] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27 [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: 104cee39e5e54d96a28e3e80c90acb27; no voters: 
I20260812 06:20:26.321714  5329 leader_election.cc:290] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:26.321864  5335 raft_consensus.cc:2804] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:26.322108  5335 raft_consensus.cc:697] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27 [term 1 LEADER]: Becoming Leader. State: Replica: 104cee39e5e54d96a28e3e80c90acb27, State: Running, Role: LEADER
I20260812 06:20:26.322093  5301 heartbeater.cc:499] Master 127.4.149.62:46595 was elected leader, sending a full tablet report...
I20260812 06:20:26.322077  5329 ts_tablet_manager.cc:1434] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:26.322328  5335 consensus_queue.cc:237] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27 [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: "104cee39e5e54d96a28e3e80c90acb27" member_type: VOTER last_known_addr { host: "127.4.149.1" port: 38809 } }
I20260812 06:20:26.323664  5094 catalog_manager.cc:5719] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27 reported cstate change: term changed from 0 to 1, leader changed from <none> to 104cee39e5e54d96a28e3e80c90acb27 (127.4.149.1). New cstate: current_term: 1 leader_uuid: "104cee39e5e54d96a28e3e80c90acb27" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "104cee39e5e54d96a28e3e80c90acb27" member_type: VOTER last_known_addr { host: "127.4.149.1" port: 38809 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:26.380929  4692 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.010s	sys 0.012s
I20260812 06:20:26.539552  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushMRSOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=19.054940
I20260812 06:20:26.707289  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushMRSOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.167s	user 0.134s	sys 0.028s Metrics: {"bytes_written":12389542,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":209,"dirs.run_wall_time_us":785,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43721,"lbm_writes_lt_1ms":859,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":768,"update_count":1510}
I20260812 06:20:26.708089  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling LogGCOp(adcb9573d5b646138bd7c5a83d5bcb40): free 20290830 bytes of WAL
I20260812 06:20:26.708484  5213 log_reader.cc:385] T adcb9573d5b646138bd7c5a83d5bcb40: removed 2 log segments from log reader
I20260812 06:20:26.708606  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000001 (ops 1-6)
I20260812 06:20:26.708701  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000002 (ops 7-10)
I20260812 06:20:26.713593  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: LogGCOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:20:26.713958  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=2.188937
I20260812 06:20:26.725371  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4020609,"delete_count":0,"lbm_write_time_us":3965,"lbm_writes_lt_1ms":101,"reinsert_count":0,"update_count":490}
I20260812 06:20:26.725889  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling UndoDeltaBlockGCOp(adcb9573d5b646138bd7c5a83d5bcb40): 20513799 bytes on disk
I20260812 06:20:26.726326  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: UndoDeltaBlockGCOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:20:26.726768  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=1.000000
I20260812 06:20:26.883164  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.156s	user 0.101s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":584,"lbm_read_time_us":10655,"lbm_reads_lt_1ms":460,"lbm_write_time_us":25469,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":335,"threads_started":5,"update_count":2000}
I20260812 06:20:26.883850  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=14.095187
I20260812 06:20:26.935182  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.051s	user 0.016s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21142,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.935636  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=2.188937
I20260812 06:20:26.946651  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3991,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.947170  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=1.000000
I20260812 06:20:27.106359  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.159s	user 0.121s	sys 0.035s 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":827,"lbm_read_time_us":11180,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31367,"lbm_writes_lt_1ms":543,"mutex_wait_us":30,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2500}
I20260812 06:20:27.107030  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=11.118625
I20260812 06:20:27.144029  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.037s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":15987,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:20:27.144601  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=2.188937
I20260812 06:20:27.156143  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4308,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:27.157757  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=1.000000
I20260812 06:20:27.289201  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.131s	user 0.104s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672267,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":407,"lbm_read_time_us":7531,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25016,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2000}
I20260812 06:20:27.289728  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=11.118625
I20260812 06:20:27.337244  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.047s	user 0.027s	sys 0.019s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":15923,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:27.337842  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=2.188937
I20260812 06:20:27.354175  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.016s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4974,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:27.354653  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=1.000000
I20260812 06:20:27.511875  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.157s	user 0.091s	sys 0.059s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672267,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":183,"lbm_read_time_us":10567,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24186,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.512524  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=11.118625
I20260812 06:20:27.552527  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.040s	user 0.011s	sys 0.028s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":17848,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:20:27.553050  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=2.188937
I20260812 06:20:27.564505  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4122,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.564929  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=2.188937
I20260812 06:20:27.574208  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3612,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:27.574683  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=1.000000
I20260812 06:20:27.748273  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.173s	user 0.115s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774801,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":155,"lbm_read_time_us":10486,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26435,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":63360,"update_count":2500}
I20260812 06:20:27.748956  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=14.095187
I20260812 06:20:27.799163  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.050s	user 0.010s	sys 0.037s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22665,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.799711  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=2.188937
I20260812 06:20:27.815353  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.015s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6135,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.815850  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushMRSOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=1.000000
I20260812 06:20:27.841140  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushMRSOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.025s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":237,"dirs.run_wall_time_us":1095,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1855,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:27.841693  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling LogGCOp(adcb9573d5b646138bd7c5a83d5bcb40): free 112239312 bytes of WAL
I20260812 06:20:27.841908  5213 log_reader.cc:385] T adcb9573d5b646138bd7c5a83d5bcb40: removed 11 log segments from log reader
I20260812 06:20:27.841971  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000003 (ops 11-15)
I20260812 06:20:27.842024  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000004 (ops 16-20)
I20260812 06:20:27.842082  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000005 (ops 21-24)
I20260812 06:20:27.842123  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000006 (ops 25-29)
I20260812 06:20:27.842159  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000007 (ops 30-34)
I20260812 06:20:27.842197  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000008 (ops 35-39)
I20260812 06:20:27.842236  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000009 (ops 40-44)
I20260812 06:20:27.842273  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000010 (ops 45-49)
I20260812 06:20:27.842311  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000011 (ops 50-54)
I20260812 06:20:27.842348  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000012 (ops 55-59)
I20260812 06:20:27.842386  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000013 (ops 60-64)
I20260812 06:20:27.870450  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: LogGCOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.029s	user 0.004s	sys 0.023s Metrics: {}
I20260812 06:20:27.870972  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=3.181125
I20260812 06:20:27.896481  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.025s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4744,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:27.896925  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling UndoDeltaBlockGCOp(adcb9573d5b646138bd7c5a83d5bcb40): 447 bytes on disk
I20260812 06:20:27.897380  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: UndoDeltaBlockGCOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":88,"lbm_reads_lt_1ms":4}
I20260812 06:20:27.897791  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=2.188937
I20260812 06:20:27.907232  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.009s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3607,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:27.907646  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=1.000000
I20260812 06:20:28.155074  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.247s	user 0.168s	sys 0.068s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979736,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":735,"lbm_read_time_us":15580,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38649,"lbm_writes_lt_1ms":743,"mutex_wait_us":475,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4096,"thread_start_us":90,"threads_started":1,"update_count":3500}
I20260812 06:20:28.155866  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=18.063937
I20260812 06:20:28.220454  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.064s	user 0.040s	sys 0.024s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":30242,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":500,"reinsert_count":0,"update_count":2500}
I20260812 06:20:28.221014  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=2.188937
I20260812 06:20:28.236433  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.015s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5918,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.237064  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=1.000000
I20260812 06:20:28.454761  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.217s	user 0.148s	sys 0.063s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":720,"lbm_read_time_us":13733,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36874,"lbm_writes_lt_1ms":643,"mutex_wait_us":65,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1152,"update_count":3000}
I20260812 06:20:28.455385  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=18.063937
I20260812 06:20:28.523031  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.067s	user 0.021s	sys 0.028s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":23799,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:28.523488  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=2.188937
I20260812 06:20:28.533810  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4015,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.534428  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=1.000000
I20260812 06:20:28.756999  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.222s	user 0.136s	sys 0.076s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877101,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1068,"lbm_read_time_us":13803,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34458,"lbm_writes_lt_1ms":643,"mutex_wait_us":326,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":34304,"update_count":3000}
I20260812 06:20:28.757611  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=18.063937
I20260812 06:20:28.831169  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.073s	user 0.043s	sys 0.017s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":28800,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:28.831645  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=2.188937
I20260812 06:20:28.841929  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3924,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.842455  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=1.000000
I20260812 06:20:29.048614  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.206s	user 0.138s	sys 0.067s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1037,"lbm_read_time_us":14012,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33216,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:20:29.049532  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=14.095187
I20260812 06:20:29.097607  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.048s	user 0.034s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21551,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.098151  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=2.188937
I20260812 06:20:29.114004  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6056,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.114548  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=1.000000
I20260812 06:20:29.292953  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.178s	user 0.126s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":852,"lbm_read_time_us":12088,"lbm_reads_lt_1ms":568,"lbm_write_time_us":31978,"lbm_writes_lt_1ms":543,"mutex_wait_us":301,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":35712,"update_count":2500}
I20260812 06:20:29.293727  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=14.095187
I20260812 06:20:29.345731  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.052s	user 0.026s	sys 0.020s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":19526,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.346282  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=2.188937
I20260812 06:20:29.358176  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4314,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.358654  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushMRSOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=1.000000
I20260812 06:20:29.389972  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushMRSOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.031s	user 0.027s	sys 0.003s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":1240,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1659,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:29.390596  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling LogGCOp(adcb9573d5b646138bd7c5a83d5bcb40): free 121006434 bytes of WAL
I20260812 06:20:29.390813  5213 log_reader.cc:385] T adcb9573d5b646138bd7c5a83d5bcb40: removed 12 log segments from log reader
I20260812 06:20:29.390873  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000014 (ops 65-69)
I20260812 06:20:29.390926  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000015 (ops 70-74)
I20260812 06:20:29.390986  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000016 (ops 75-79)
I20260812 06:20:29.391028  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000017 (ops 80-84)
I20260812 06:20:29.391064  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000018 (ops 85-89)
I20260812 06:20:29.391098  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000019 (ops 90-94)
I20260812 06:20:29.391132  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000020 (ops 95-98)
I20260812 06:20:29.391168  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000021 (ops 99-103)
I20260812 06:20:29.391206  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000022 (ops 104-108)
I20260812 06:20:29.391240  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000023 (ops 109-113)
I20260812 06:20:29.391278  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000024 (ops 114-118)
I20260812 06:20:29.391315  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000025 (ops 119-123)
I20260812 06:20:29.417802  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: LogGCOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:29.418190  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling UndoDeltaBlockGCOp(adcb9573d5b646138bd7c5a83d5bcb40): 472 bytes on disk
I20260812 06:20:29.418702  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: UndoDeltaBlockGCOp(adcb9573d5b646138bd7c5a83d5bcb40) 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:20:29.419299  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=4.173312
I20260812 06:20:29.436252  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.017s	user 0.009s	sys 0.007s Metrics: {"bytes_written":5743633,"delete_count":0,"lbm_write_time_us":6764,"lbm_writes_lt_1ms":143,"reinsert_count":0,"update_count":700}
I20260812 06:20:29.436759  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=1.196750
I20260812 06:20:29.447678  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":2461654,"delete_count":0,"lbm_write_time_us":3713,"lbm_writes_lt_1ms":63,"reinsert_count":0,"update_count":300}
I20260812 06:20:29.448406  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=1.000000
I20260812 06:20:29.670591  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.222s	user 0.161s	sys 0.061s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979717,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":283,"lbm_read_time_us":16574,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40562,"lbm_writes_lt_1ms":743,"mutex_wait_us":40,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6784,"thread_start_us":145,"threads_started":1,"update_count":3500}
I20260812 06:20:29.671300  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=15.087375
I20260812 06:20:29.743067  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.071s	user 0.033s	sys 0.027s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":28975,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":410,"reinsert_count":0,"update_count":2050}
I20260812 06:20:29.743600  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=6.157687
I20260812 06:20:29.775003  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.031s	user 0.020s	sys 0.004s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":11191,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:20:29.775494  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=1.000000
I20260812 06:20:29.948006  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.172s	user 0.148s	sys 0.024s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877100,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":369,"lbm_read_time_us":11947,"lbm_reads_lt_1ms":664,"lbm_write_time_us":33511,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:20:29.948798  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=14.095187
I20260812 06:20:30.001305  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.052s	user 0.036s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22747,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2000}
I20260812 06:20:30.001880  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=3.181125
I20260812 06:20:30.021569  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.020s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5177,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:30.022123  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=2.188937
I20260812 06:20:30.037416  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5905,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:30.037977  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=1.000000
I20260812 06:20:30.218924  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.181s	user 0.133s	sys 0.047s 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":571,"lbm_read_time_us":13199,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36055,"lbm_writes_lt_1ms":643,"mutex_wait_us":19,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15872,"update_count":3000}
I20260812 06:20:30.219537  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=14.095187
I20260812 06:20:30.268301  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.049s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19956,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.268759  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=2.188937
I20260812 06:20:30.279577  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4235,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.280033  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=1.000000
I20260812 06:20:30.436197  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.156s	user 0.116s	sys 0.039s 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":900,"lbm_read_time_us":12488,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29344,"lbm_writes_lt_1ms":543,"mutex_wait_us":297,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:20:30.437549  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=11.118625
I20260812 06:20:30.475752  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.038s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12717739,"delete_count":0,"lbm_write_time_us":16184,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:30.477223  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=2.188937
I20260812 06:20:30.492985  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692408,"delete_count":0,"lbm_write_time_us":5599,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:30.493521  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=1.000000
I20260812 06:20:30.627956  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.134s	user 0.087s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":390,"lbm_read_time_us":9103,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23422,"lbm_writes_lt_1ms":443,"mutex_wait_us":57,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":178048,"update_count":2000}
I20260812 06:20:30.628763  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=11.118625
I20260812 06:20:30.669678  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.041s	user 0.020s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18528,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:30.670154  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=2.188937
I20260812 06:20:30.690940  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.021s	user 0.006s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4200,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.691496  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=2.188937
I20260812 06:20:30.702135  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4099,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:30.702574  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushMRSOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=1.000000
I20260812 06:20:30.727025  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushMRSOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.024s	user 0.023s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":1439,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1370,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:30.727653  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling LogGCOp(adcb9573d5b646138bd7c5a83d5bcb40): free 120100581 bytes of WAL
I20260812 06:20:30.727895  5213 log_reader.cc:385] T adcb9573d5b646138bd7c5a83d5bcb40: removed 12 log segments from log reader
I20260812 06:20:30.727941  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000026 (ops 124-128)
I20260812 06:20:30.727977  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000027 (ops 129-133)
I20260812 06:20:30.728039  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000028 (ops 134-138)
I20260812 06:20:30.728102  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000029 (ops 139-142)
I20260812 06:20:30.728143  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000030 (ops 143-147)
I20260812 06:20:30.728221  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000031 (ops 148-152)
I20260812 06:20:30.728266  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000032 (ops 153-156)
I20260812 06:20:30.728303  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000033 (ops 157-161)
I20260812 06:20:30.728329  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000034 (ops 162-166)
I20260812 06:20:30.728369  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000035 (ops 167-171)
I20260812 06:20:30.728405  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000036 (ops 172-176)
I20260812 06:20:30.728443  5213 log.cc:1079] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: Deleting log segment in path: /tmp/dist-test-taskSWFuGr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620762374-4692-0/minicluster-data/ts-0-root/wals/adcb9573d5b646138bd7c5a83d5bcb40/wal-000000037 (ops 177-180)
I20260812 06:20:30.756467  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: LogGCOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:20:30.756901  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling UndoDeltaBlockGCOp(adcb9573d5b646138bd7c5a83d5bcb40): 447 bytes on disk
I20260812 06:20:30.757525  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: UndoDeltaBlockGCOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:20:30.758082  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=2.188937
I20260812 06:20:30.768910  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.011s	user 0.003s	sys 0.007s Metrics: {"bytes_written":3446259,"delete_count":0,"lbm_write_time_us":4109,"lbm_writes_lt_1ms":87,"reinsert_count":0,"update_count":420}
I20260812 06:20:30.769371  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=1.000000
I20260812 06:20:30.982697  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.213s	user 0.154s	sys 0.054s Metrics: {"cfile_cache_miss":618,"cfile_cache_miss_bytes":28220930,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":679,"lbm_read_time_us":14735,"lbm_reads_lt_1ms":654,"lbm_write_time_us":36316,"lbm_writes_lt_1ms":627,"mutex_wait_us":29,"peak_mem_usage":72805144,"reinsert_count":0,"spinlock_wait_cycles":4224,"thread_start_us":64,"threads_started":1,"update_count":2920}
I20260812 06:20:30.983358  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=15.087375
I20260812 06:20:31.043805  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.060s	user 0.048s	sys 0.008s Metrics: {"bytes_written":17066298,"delete_count":0,"lbm_write_time_us":25247,"lbm_writes_lt_1ms":419,"reinsert_count":0,"update_count":2080}
I20260812 06:20:31.044382  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=2.188937
I20260812 06:20:31.057790  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4821,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.058367  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=1.000000
I20260812 06:20:31.230819  4692 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.850s	user 1.774s	sys 0.205s
I20260812 06:20:31.236328  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: MajorDeltaCompactionOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.178s	user 0.120s	sys 0.052s Metrics: {"cfile_cache_miss":548,"cfile_cache_miss_bytes":25431084,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":951,"lbm_read_time_us":11430,"lbm_reads_lt_1ms":588,"lbm_write_time_us":30865,"lbm_writes_lt_1ms":559,"mutex_wait_us":267,"peak_mem_usage":64812844,"reinsert_count":0,"spinlock_wait_cycles":49920,"update_count":2580}
I20260812 06:20:31.237049  5302 maintenance_manager.cc:419] P 104cee39e5e54d96a28e3e80c90acb27: Scheduling FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40): perf score=14.095187
I20260812 06:20:31.256428  4692 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.025s	user 0.003s	sys 0.000s
I20260812 06:20:31.256943  4692 tablet_server.cc:179] TabletServer@127.4.149.1:0 shutting down...
I20260812 06:20:31.290340  5213 maintenance_manager.cc:643] P 104cee39e5e54d96a28e3e80c90acb27: FlushDeltaMemStoresOp(adcb9573d5b646138bd7c5a83d5bcb40) complete. Timing: real 0.053s	user 0.028s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19582,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:31.290874  4692 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:31.291114  4692 tablet_replica.cc:333] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27: stopping tablet replica
I20260812 06:20:31.291272  4692 raft_consensus.cc:2243] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:31.291448  4692 raft_consensus.cc:2272] T adcb9573d5b646138bd7c5a83d5bcb40 P 104cee39e5e54d96a28e3e80c90acb27 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:31.294836  4692 tablet_server.cc:196] TabletServer@127.4.149.1:0 shutdown complete.
I20260812 06:20:31.297713  4692 master.cc:562] Master@127.4.149.62:46595 shutting down...
I20260812 06:20:31.300967  4692 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:31.301121  4692 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:31.301216  4692 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1f4a743e558444d98ab467d81b9e8565: stopping tablet replica
I20260812 06:20:31.313328  4692 master.cc:584] Master@127.4.149.62:46595 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5258 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10633 ms total)

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