[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:16:33.722749 10912 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.168.62:41949
I20260812 06:16:33.723891 10912 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:16:33.724570 10912 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:33.731269 10919 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:16:33.731333 10917 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:33.731568 10912 server_base.cc:1061] running on GCE node
W20260812 06:16:33.731616 10922 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:33.732103 10912 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:33.732245 10912 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:33.732309 10912 hybrid_clock.cc:648] HybridClock initialized: now 1786515393732307 us; error 0 us; skew 500 ppm
I20260812 06:16:33.734318 10912 webserver.cc:533] Webserver started at http://127.10.168.62:35651/ using document root <none> and password file <none>
I20260812 06:16:33.734925 10912 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:33.735031 10912 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:33.735306 10912 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:33.737100 10912 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/master-0-root/instance:
uuid: "bc5ec0316b144a7eb51e5b39be00b3bf"
format_stamp: "Formatted at 2026-08-12 06:16:33 on dist-test-slave-sb2z"
I20260812 06:16:33.740841 10912 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.001s
I20260812 06:16:33.743182 10927 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:33.744408 10912 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:16:33.744570 10912 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/master-0-root
uuid: "bc5ec0316b144a7eb51e5b39be00b3bf"
format_stamp: "Formatted at 2026-08-12 06:16:33 on dist-test-slave-sb2z"
I20260812 06:16:33.744691 10912 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:33.770335 10912 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:33.771168 10912 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:16:33.771386 10912 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:33.780930 10912 rpc_server.cc:307] RPC server started. Bound to: 127.10.168.62:41949
I20260812 06:16:33.780982 11002 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.168.62:41949 every 8 connection(s)
I20260812 06:16:33.783569 11003 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:33.789455 11003 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf: Bootstrap starting.
I20260812 06:16:33.792568 11003 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:33.793620 11003 log.cc:826] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:33.795907 11003 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf: No bootstrap required, opened a new log
I20260812 06:16:33.799173 11003 raft_consensus.cc:359] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bc5ec0316b144a7eb51e5b39be00b3bf" member_type: VOTER }
I20260812 06:16:33.799374 11003 raft_consensus.cc:385] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:33.799463 11003 raft_consensus.cc:740] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: bc5ec0316b144a7eb51e5b39be00b3bf, State: Initialized, Role: FOLLOWER
I20260812 06:16:33.800261 11003 consensus_queue.cc:260] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf [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: "bc5ec0316b144a7eb51e5b39be00b3bf" member_type: VOTER }
I20260812 06:16:33.800454 11003 raft_consensus.cc:399] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:33.800550 11003 raft_consensus.cc:493] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:33.800721 11003 raft_consensus.cc:3060] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:33.801669 11003 raft_consensus.cc:515] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bc5ec0316b144a7eb51e5b39be00b3bf" member_type: VOTER }
I20260812 06:16:33.802187 11003 leader_election.cc:304] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf [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: bc5ec0316b144a7eb51e5b39be00b3bf; no voters: 
I20260812 06:16:33.802599 11003 leader_election.cc:290] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:33.802815 11007 raft_consensus.cc:2804] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:33.803079 11007 raft_consensus.cc:697] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf [term 1 LEADER]: Becoming Leader. State: Replica: bc5ec0316b144a7eb51e5b39be00b3bf, State: Running, Role: LEADER
I20260812 06:16:33.803620 11007 consensus_queue.cc:237] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf [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: "bc5ec0316b144a7eb51e5b39be00b3bf" member_type: VOTER }
I20260812 06:16:33.803927 11003 sys_catalog.cc:565] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:33.806075 11012 sys_catalog.cc:455] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf [sys.catalog]: SysCatalogTable state changed. Reason: New leader bc5ec0316b144a7eb51e5b39be00b3bf. Latest consensus state: current_term: 1 leader_uuid: "bc5ec0316b144a7eb51e5b39be00b3bf" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bc5ec0316b144a7eb51e5b39be00b3bf" member_type: VOTER } }
I20260812 06:16:33.806075 11010 sys_catalog.cc:455] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "bc5ec0316b144a7eb51e5b39be00b3bf" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bc5ec0316b144a7eb51e5b39be00b3bf" member_type: VOTER } }
I20260812 06:16:33.806313 11010 sys_catalog.cc:458] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:33.806313 11012 sys_catalog.cc:458] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:33.806762 11025 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:33.806878 10912 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:33.809783 11025 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:33.815753 11025 catalog_manager.cc:1383] Generated new cluster ID: 5f632241e2694c9bb25007cf2c9b648d
I20260812 06:16:33.815860 11025 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:33.835945 11025 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:33.837038 11025 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:33.850380 11025 catalog_manager.cc:6092] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf: Generated new TSK 0
I20260812 06:16:33.851256 11025 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:33.872005 10912 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:33.875295 11032 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:16:33.875339 11031 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:33.875447 11034 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:33.875663 10912 server_base.cc:1061] running on GCE node
I20260812 06:16:33.875929 10912 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:33.875973 10912 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:33.875989 10912 hybrid_clock.cc:648] HybridClock initialized: now 1786515393875989 us; error 0 us; skew 500 ppm
I20260812 06:16:33.877007 10912 webserver.cc:533] Webserver started at http://127.10.168.1:37017/ using document root <none> and password file <none>
I20260812 06:16:33.877228 10912 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:33.877285 10912 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:33.877399 10912 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:33.877835 10912 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/instance:
uuid: "6792ff1f0a7f4ffba94ff1799ecfa6ed"
format_stamp: "Formatted at 2026-08-12 06:16:33 on dist-test-slave-sb2z"
I20260812 06:16:33.879457 10912 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.001s
I20260812 06:16:33.880587 11041 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:33.880904 10912 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:33.881021 10912 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root
uuid: "6792ff1f0a7f4ffba94ff1799ecfa6ed"
format_stamp: "Formatted at 2026-08-12 06:16:33 on dist-test-slave-sb2z"
I20260812 06:16:33.881120 10912 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:33.886904 10912 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:33.887363 10912 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:33.887959 10912 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:33.888844 10912 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:33.888923 10912 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:33.888994 10912 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:33.889045 10912 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:33.896158 10912 rpc_server.cc:307] RPC server started. Bound to: 127.10.168.1:45277
I20260812 06:16:33.896188 11137 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.168.1:45277 every 8 connection(s)
I20260812 06:16:33.911353 11138 heartbeater.cc:344] Connected to a master server at 127.10.168.62:41949
I20260812 06:16:33.911710 11138 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:33.912225 11138 heartbeater.cc:507] Master 127.10.168.62:41949 requested a full tablet report, sending...
I20260812 06:16:33.913908 10950 ts_manager.cc:194] Registered new tserver with Master: 6792ff1f0a7f4ffba94ff1799ecfa6ed (127.10.168.1:45277)
I20260812 06:16:33.914009 10912 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.017074333s
I20260812 06:16:33.915488 10950 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:36702
I20260812 06:16:33.924474 10950 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:36718:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:16:33.939914 11084 tablet_service.cc:1511] Processing CreateTablet for tablet e9cb00662df24e3e93519e1bb1181a7f (DEFAULT_TABLE table=heavy-update-compaction-test [id=d0bb730ab4274c84a56deeb855531978]), partition=
I20260812 06:16:33.940399 11084 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet e9cb00662df24e3e93519e1bb1181a7f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:33.943079 11155 tablet_bootstrap.cc:492] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Bootstrap starting.
I20260812 06:16:33.944238 11155 tablet_bootstrap.cc:654] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:33.945695 11155 tablet_bootstrap.cc:492] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: No bootstrap required, opened a new log
I20260812 06:16:33.945820 11155 ts_tablet_manager.cc:1403] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:33.946305 11155 raft_consensus.cc:359] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6792ff1f0a7f4ffba94ff1799ecfa6ed" member_type: VOTER last_known_addr { host: "127.10.168.1" port: 45277 } }
I20260812 06:16:33.946409 11155 raft_consensus.cc:385] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:33.946434 11155 raft_consensus.cc:740] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6792ff1f0a7f4ffba94ff1799ecfa6ed, State: Initialized, Role: FOLLOWER
I20260812 06:16:33.946614 11155 consensus_queue.cc:260] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed [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: "6792ff1f0a7f4ffba94ff1799ecfa6ed" member_type: VOTER last_known_addr { host: "127.10.168.1" port: 45277 } }
I20260812 06:16:33.946718 11155 raft_consensus.cc:399] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:33.946782 11155 raft_consensus.cc:493] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:33.946859 11155 raft_consensus.cc:3060] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:33.947717 11155 raft_consensus.cc:515] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6792ff1f0a7f4ffba94ff1799ecfa6ed" member_type: VOTER last_known_addr { host: "127.10.168.1" port: 45277 } }
I20260812 06:16:33.947878 11155 leader_election.cc:304] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed [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: 6792ff1f0a7f4ffba94ff1799ecfa6ed; no voters: 
I20260812 06:16:33.948135 11155 leader_election.cc:290] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:33.948515 11155 ts_tablet_manager.cc:1434] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:16:33.948801 11138 heartbeater.cc:499] Master 127.10.168.62:41949 was elected leader, sending a full tablet report...
I20260812 06:16:33.949136 11157 raft_consensus.cc:2804] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:33.949455 11157 raft_consensus.cc:697] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed [term 1 LEADER]: Becoming Leader. State: Replica: 6792ff1f0a7f4ffba94ff1799ecfa6ed, State: Running, Role: LEADER
I20260812 06:16:33.949666 11157 consensus_queue.cc:237] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed [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: "6792ff1f0a7f4ffba94ff1799ecfa6ed" member_type: VOTER last_known_addr { host: "127.10.168.1" port: 45277 } }
I20260812 06:16:33.953379 10950 catalog_manager.cc:5719] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed reported cstate change: term changed from 0 to 1, leader changed from <none> to 6792ff1f0a7f4ffba94ff1799ecfa6ed (127.10.168.1). New cstate: current_term: 1 leader_uuid: "6792ff1f0a7f4ffba94ff1799ecfa6ed" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6792ff1f0a7f4ffba94ff1799ecfa6ed" member_type: VOTER last_known_addr { host: "127.10.168.1" port: 45277 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:34.054595 10912 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.092s	user 0.024s	sys 0.026s
I20260812 06:16:34.147792 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushMRSOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=10.125253
I20260812 06:16:34.286695 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushMRSOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.138s	user 0.110s	sys 0.024s Metrics: {"bytes_written":8615323,"cfile_init":1,"compiler_manager_pool.queue_time_us":242,"delete_count":0,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":245,"dirs.run_wall_time_us":984,"drs_written":1,"lbm_read_time_us":121,"lbm_reads_lt_1ms":4,"lbm_write_time_us":29711,"lbm_writes_lt_1ms":467,"peak_mem_usage":0,"reinsert_count":0,"rows_written":102,"thread_start_us":142,"threads_started":1,"update_count":1050}
I20260812 06:16:34.287946 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling LogGCOp(e9cb00662df24e3e93519e1bb1181a7f): free 11976772 bytes of WAL
I20260812 06:16:34.288321 11048 log_reader.cc:385] T e9cb00662df24e3e93519e1bb1181a7f: removed 1 log segments from log reader
I20260812 06:16:34.288415 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000001 (ops 1-6)
I20260812 06:16:34.291293 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: LogGCOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:16:34.291782 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling UndoDeltaBlockGCOp(e9cb00662df24e3e93519e1bb1181a7f): 8206537 bytes on disk
I20260812 06:16:34.292445 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: UndoDeltaBlockGCOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:16:34.292907 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=2.188937
I20260812 06:16:34.306348 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.013s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5107,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:34.306943 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.000000
I20260812 06:16:34.446677 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.140s	user 0.085s	sys 0.044s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16487926,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1130,"lbm_read_time_us":8462,"lbm_reads_lt_1ms":368,"lbm_write_time_us":24641,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":351,"threads_started":5,"update_count":1500}
I20260812 06:16:34.447379 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=10.126437
I20260812 06:16:34.502269 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.055s	user 0.015s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18673,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:34.502867 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=2.188937
I20260812 06:16:34.514295 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4391,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.514999 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.000000
I20260812 06:16:34.667896 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.153s	user 0.110s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1237,"lbm_read_time_us":11039,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27765,"lbm_writes_lt_1ms":443,"mutex_wait_us":311,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":23040,"update_count":2000}
I20260812 06:16:34.668751 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=11.118625
I20260812 06:16:34.719388 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.050s	user 0.026s	sys 0.021s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":19186,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:34.720081 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=2.188937
I20260812 06:16:34.731091 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4151,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:34.731725 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.000000
I20260812 06:16:34.886547 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.155s	user 0.110s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":165,"lbm_read_time_us":11916,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26168,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":80512,"update_count":2000}
I20260812 06:16:34.887423 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=10.126437
I20260812 06:16:34.939293 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.049s	user 0.027s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":24778,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:34.939919 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=2.188937
I20260812 06:16:34.959218 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.019s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5361,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.959828 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.000000
I20260812 06:16:35.093025 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.133s	user 0.111s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":439,"lbm_read_time_us":10396,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26540,"lbm_writes_lt_1ms":443,"mutex_wait_us":86,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16896,"update_count":2000}
I20260812 06:16:35.093665 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=11.118625
I20260812 06:16:35.140193 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.046s	user 0.018s	sys 0.027s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":20121,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:16:35.140794 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=2.188937
I20260812 06:16:35.156308 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.015s	user 0.003s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4810,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:35.156841 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.000000
I20260812 06:16:35.290571 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.134s	user 0.100s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590337,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1137,"lbm_read_time_us":9479,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25712,"lbm_writes_lt_1ms":443,"mutex_wait_us":339,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2000}
I20260812 06:16:35.291175 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=11.118625
I20260812 06:16:35.332996 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.042s	user 0.022s	sys 0.018s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14290,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:35.333631 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=2.188937
I20260812 06:16:35.347400 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.014s	user 0.000s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5324,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:35.348059 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.000000
I20260812 06:16:35.512748 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.164s	user 0.132s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590338,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":237,"lbm_read_time_us":11789,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27187,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2000}
I20260812 06:16:35.514690 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=10.126437
I20260812 06:16:35.548297 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.033s	user 0.028s	sys 0.003s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14164,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":1500}
I20260812 06:16:35.549058 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=2.188937
I20260812 06:16:35.561477 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4334,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:35.562163 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.000000
I20260812 06:16:35.686132 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.124s	user 0.086s	sys 0.038s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590348,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1318,"lbm_read_time_us":9058,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24607,"lbm_writes_lt_1ms":443,"mutex_wait_us":374,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":25088,"update_count":2000}
I20260812 06:16:35.686733 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=10.126437
I20260812 06:16:35.727247 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.040s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17442,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:35.727872 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=2.188937
I20260812 06:16:35.740020 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4297,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:35.740597 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushMRSOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.000000
I20260812 06:16:35.773190 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushMRSOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.032s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":265,"dirs.run_wall_time_us":1434,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1663,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:35.774053 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling LogGCOp(e9cb00662df24e3e93519e1bb1181a7f): free 121459479 bytes of WAL
I20260812 06:16:35.774309 11048 log_reader.cc:385] T e9cb00662df24e3e93519e1bb1181a7f: removed 12 log segments from log reader
I20260812 06:16:35.774356 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000002 (ops 7-11)
I20260812 06:16:35.774389 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000003 (ops 12-16)
I20260812 06:16:35.774448 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000004 (ops 17-21)
I20260812 06:16:35.774504 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000005 (ops 22-26)
I20260812 06:16:35.774545 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000006 (ops 27-31)
I20260812 06:16:35.774585 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000007 (ops 32-36)
I20260812 06:16:35.774619 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000008 (ops 37-41)
I20260812 06:16:35.774643 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000009 (ops 42-46)
I20260812 06:16:35.774685 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000010 (ops 47-51)
I20260812 06:16:35.774724 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000011 (ops 52-56)
I20260812 06:16:35.774761 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000012 (ops 57-61)
I20260812 06:16:35.774801 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000013 (ops 62-66)
I20260812 06:16:35.805904 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: LogGCOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.032s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:16:35.806447 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=3.181125
I20260812 06:16:35.825240 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.019s	user 0.009s	sys 0.008s Metrics: {"bytes_written":5169286,"delete_count":0,"lbm_write_time_us":7483,"lbm_writes_lt_1ms":129,"reinsert_count":0,"update_count":630}
I20260812 06:16:35.825812 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling LogGCOp(e9cb00662df24e3e93519e1bb1181a7f): free 11564875 bytes of WAL
I20260812 06:16:35.826033 11048 log_reader.cc:385] T e9cb00662df24e3e93519e1bb1181a7f: removed 1 log segments from log reader
I20260812 06:16:35.826076 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000014 (ops 67-70)
I20260812 06:16:35.828532 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: LogGCOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:16:35.828882 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling UndoDeltaBlockGCOp(e9cb00662df24e3e93519e1bb1181a7f): 481 bytes on disk
I20260812 06:16:35.829406 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: UndoDeltaBlockGCOp(e9cb00662df24e3e93519e1bb1181a7f) 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:16:35.829873 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.196750
I20260812 06:16:35.841226 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3036005,"delete_count":0,"lbm_write_time_us":3806,"lbm_writes_lt_1ms":77,"reinsert_count":0,"update_count":370}
I20260812 06:16:35.841688 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.000000
I20260812 06:16:36.024762 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.183s	user 0.150s	sys 0.031s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28795382,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":627,"lbm_read_time_us":11187,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37365,"lbm_writes_lt_1ms":643,"mutex_wait_us":385,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11008,"thread_start_us":85,"threads_started":1,"update_count":3000}
I20260812 06:16:36.025503 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=14.095187
I20260812 06:16:36.075976 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.050s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20710,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:36.076472 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=2.188937
I20260812 06:16:36.087951 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4306,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:36.088683 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.000000
I20260812 06:16:36.257292 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.168s	user 0.129s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692761,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":583,"lbm_read_time_us":12110,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31527,"lbm_writes_lt_1ms":543,"mutex_wait_us":93,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24576,"update_count":2500}
I20260812 06:16:36.258071 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=12.110812
I20260812 06:16:36.300503 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.042s	user 0.030s	sys 0.012s Metrics: {"bytes_written":13579241,"delete_count":0,"lbm_write_time_us":18558,"lbm_writes_lt_1ms":334,"reinsert_count":0,"update_count":1655}
I20260812 06:16:36.301144 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=2.188937
I20260812 06:16:36.322866 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.021s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3241134,"delete_count":0,"lbm_write_time_us":4127,"lbm_writes_lt_1ms":82,"reinsert_count":0,"update_count":395}
I20260812 06:16:36.323453 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=2.188937
I20260812 06:16:36.339816 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5696,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:36.340420 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.000000
I20260812 06:16:36.523727 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.183s	user 0.109s	sys 0.057s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24692850,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":446,"lbm_read_time_us":14150,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28587,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:16:36.524570 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=14.095187
I20260812 06:16:36.585399 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.061s	user 0.031s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24808,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:36.586068 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=2.188937
I20260812 06:16:36.597223 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4145,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:36.597890 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.000000
I20260812 06:16:36.778290 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.180s	user 0.118s	sys 0.054s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692757,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":847,"lbm_read_time_us":12874,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31259,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2500}
I20260812 06:16:36.779027 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=14.095187
I20260812 06:16:36.843817 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.065s	user 0.032s	sys 0.028s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":23202,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:36.844487 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=2.188937
I20260812 06:16:36.856019 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4261,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:36.856561 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.000000
I20260812 06:16:37.044997 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.188s	user 0.138s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692761,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":671,"lbm_read_time_us":14572,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31242,"lbm_writes_lt_1ms":543,"mutex_wait_us":30,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":47744,"update_count":2500}
I20260812 06:16:37.045758 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=10.126437
I20260812 06:16:37.092749 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.047s	user 0.012s	sys 0.033s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19885,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:37.093343 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=2.188937
I20260812 06:16:37.126649 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.033s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4769,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:37.127256 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=2.188937
I20260812 06:16:37.147931 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.020s	user 0.017s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6866,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:37.148702 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.000000
I20260812 06:16:37.340158 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.191s	user 0.113s	sys 0.068s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24692877,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":964,"lbm_read_time_us":11885,"lbm_reads_lt_1ms":573,"lbm_write_time_us":34707,"lbm_writes_lt_1ms":543,"mutex_wait_us":278,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":2500}
I20260812 06:16:37.340952 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=14.095187
I20260812 06:16:37.393416 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.052s	user 0.023s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20270,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:37.394132 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=2.188937
I20260812 06:16:37.420470 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.026s	user 0.014s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6510,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:37.421087 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushMRSOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.000000
I20260812 06:16:37.461261 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushMRSOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.040s	user 0.036s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":97,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":1565,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1858,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:16:37.462037 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling LogGCOp(e9cb00662df24e3e93519e1bb1181a7f): free 121006452 bytes of WAL
I20260812 06:16:37.462294 11048 log_reader.cc:385] T e9cb00662df24e3e93519e1bb1181a7f: removed 12 log segments from log reader
I20260812 06:16:37.462343 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000015 (ops 71-75)
I20260812 06:16:37.462374 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000016 (ops 76-80)
I20260812 06:16:37.462440 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000017 (ops 81-84)
I20260812 06:16:37.462513 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000018 (ops 85-89)
I20260812 06:16:37.462556 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000019 (ops 90-94)
I20260812 06:16:37.462613 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000020 (ops 95-99)
I20260812 06:16:37.462671 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000021 (ops 100-104)
I20260812 06:16:37.462706 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000022 (ops 105-109)
I20260812 06:16:37.462750 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000023 (ops 110-114)
I20260812 06:16:37.462790 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000024 (ops 115-119)
I20260812 06:16:37.462829 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000025 (ops 120-124)
I20260812 06:16:37.462868 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000026 (ops 125-129)
I20260812 06:16:37.490465 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: LogGCOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:16:37.491021 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=3.181125
I20260812 06:16:37.510094 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.019s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4741,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:37.510602 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling LogGCOp(e9cb00662df24e3e93519e1bb1181a7f): free 12017954 bytes of WAL
I20260812 06:16:37.510833 11048 log_reader.cc:385] T e9cb00662df24e3e93519e1bb1181a7f: removed 1 log segments from log reader
I20260812 06:16:37.510906 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000027 (ops 130-134)
I20260812 06:16:37.514334 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: LogGCOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:37.514830 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling UndoDeltaBlockGCOp(e9cb00662df24e3e93519e1bb1181a7f): 493 bytes on disk
I20260812 06:16:37.515372 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: UndoDeltaBlockGCOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:16:37.516069 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=2.188937
I20260812 06:16:37.528258 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.012s	user 0.004s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4121,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:37.528767 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.000000
I20260812 06:16:37.763360 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.234s	user 0.145s	sys 0.084s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32897810,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1640,"lbm_read_time_us":15573,"lbm_reads_lt_1ms":770,"lbm_write_time_us":38117,"lbm_writes_lt_1ms":743,"mutex_wait_us":289,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17536,"thread_start_us":132,"threads_started":1,"update_count":3500}
I20260812 06:16:37.764086 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=18.063937
I20260812 06:16:37.838786 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.075s	user 0.031s	sys 0.025s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":27442,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:37.839392 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=2.188937
I20260812 06:16:37.851330 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.012s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4302,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:37.851845 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.000000
I20260812 06:16:38.053960 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.202s	user 0.142s	sys 0.060s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28795173,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":656,"lbm_read_time_us":12684,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35973,"lbm_writes_lt_1ms":643,"mutex_wait_us":72,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17792,"update_count":3000}
I20260812 06:16:38.054647 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=14.095187
I20260812 06:16:38.107604 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.053s	user 0.017s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20032,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:38.110306 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=2.188937
I20260812 06:16:38.128038 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.017s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":6808,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.128806 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.000000
I20260812 06:16:38.320706 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.192s	user 0.159s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692759,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1151,"lbm_read_time_us":12329,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36338,"lbm_writes_lt_1ms":543,"mutex_wait_us":392,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:16:38.321415 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=11.118625
I20260812 06:16:38.366343 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.045s	user 0.018s	sys 0.023s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15308,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:38.366959 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=2.188937
I20260812 06:16:38.383215 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5719,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":450}
I20260812 06:16:38.384747 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.000000
I20260812 06:16:38.562172 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.177s	user 0.123s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590339,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":255,"lbm_read_time_us":11994,"lbm_reads_lt_1ms":464,"lbm_write_time_us":29519,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":90624,"update_count":2000}
I20260812 06:16:38.562799 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=14.095187
I20260812 06:16:38.612656 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.050s	user 0.033s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20722,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:38.613318 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=2.188937
I20260812 06:16:38.625917 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4242,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.626471 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.000000
I20260812 06:16:38.793675 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.166s	user 0.116s	sys 0.046s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692759,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":590,"lbm_read_time_us":11754,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32686,"lbm_writes_lt_1ms":543,"mutex_wait_us":286,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13824,"update_count":2500}
I20260812 06:16:38.794400 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=11.118625
I20260812 06:16:38.846668 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.052s	user 0.031s	sys 0.016s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":23148,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1550}
I20260812 06:16:38.847183 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=2.188937
I20260812 06:16:38.858863 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.011s	user 0.009s	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:16:38.859401 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=2.188937
I20260812 06:16:38.869339 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3519,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:38.869900 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.000000
I20260812 06:16:39.044620 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.175s	user 0.140s	sys 0.023s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24692868,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1541,"lbm_read_time_us":10571,"lbm_reads_lt_1ms":573,"lbm_write_time_us":36242,"lbm_writes_lt_1ms":543,"mutex_wait_us":365,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2500}
I20260812 06:16:39.045483 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=14.095187
I20260812 06:16:39.099798 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.054s	user 0.038s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24491,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:39.100366 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=2.188937
I20260812 06:16:39.112990 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.012s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4249,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:39.113602 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushMRSOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.000000
I20260812 06:16:39.148904 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushMRSOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.035s	user 0.029s	sys 0.005s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":254,"dirs.run_wall_time_us":1746,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1950,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:16:39.149740 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling LogGCOp(e9cb00662df24e3e93519e1bb1181a7f): free 129320776 bytes of WAL
I20260812 06:16:39.150028 11048 log_reader.cc:385] T e9cb00662df24e3e93519e1bb1181a7f: removed 13 log segments from log reader
I20260812 06:16:39.150076 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000028 (ops 135-139)
I20260812 06:16:39.150128 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000029 (ops 140-144)
I20260812 06:16:39.150172 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000030 (ops 145-149)
I20260812 06:16:39.150224 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000031 (ops 150-154)
I20260812 06:16:39.150264 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000032 (ops 155-158)
I20260812 06:16:39.150303 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000033 (ops 159-163)
I20260812 06:16:39.150342 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000034 (ops 164-168)
I20260812 06:16:39.150380 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000035 (ops 169-173)
I20260812 06:16:39.150422 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000036 (ops 174-178)
I20260812 06:16:39.150461 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000037 (ops 179-183)
I20260812 06:16:39.150499 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000038 (ops 184-188)
I20260812 06:16:39.150538 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000039 (ops 189-192)
I20260812 06:16:39.150576 11048 log.cc:1079] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/e9cb00662df24e3e93519e1bb1181a7f/wal-000000040 (ops 193-197)
I20260812 06:16:39.183091 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: LogGCOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.033s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:16:39.183629 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=3.181125
I20260812 06:16:39.202373 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.019s	user 0.012s	sys 0.004s Metrics: {"bytes_written":5169287,"delete_count":0,"lbm_write_time_us":7570,"lbm_writes_lt_1ms":129,"reinsert_count":0,"update_count":630}
I20260812 06:16:39.202958 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling UndoDeltaBlockGCOp(e9cb00662df24e3e93519e1bb1181a7f): 492 bytes on disk
I20260812 06:16:39.203425 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: UndoDeltaBlockGCOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:16:39.204250 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.196750
I20260812 06:16:39.213928 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: FlushDeltaMemStoresOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3036005,"delete_count":0,"lbm_write_time_us":3299,"lbm_writes_lt_1ms":77,"reinsert_count":0,"update_count":370}
I20260812 06:16:39.214848 11140 maintenance_manager.cc:419] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: Scheduling MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f): perf score=1.000000
I20260812 06:16:39.252440 10912 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.198s	user 1.894s	sys 0.150s
I20260812 06:16:39.366493 10912 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.113s	user 0.001s	sys 0.000s
I20260812 06:16:39.367226 10912 tablet_server.cc:179] TabletServer@127.10.168.1:0 shutting down...
I20260812 06:16:39.436525 11048 maintenance_manager.cc:643] P 6792ff1f0a7f4ffba94ff1799ecfa6ed: MajorDeltaCompactionOp(e9cb00662df24e3e93519e1bb1181a7f) complete. Timing: real 0.221s	user 0.126s	sys 0.091s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32897794,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":929,"lbm_read_time_us":15188,"lbm_reads_lt_1ms":770,"lbm_write_time_us":40381,"lbm_writes_lt_1ms":743,"mutex_wait_us":75,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2304,"thread_start_us":89,"threads_started":1,"update_count":3500}
I20260812 06:16:39.437940 10912 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:39.438385 10912 tablet_replica.cc:333] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed: stopping tablet replica
I20260812 06:16:39.438660 10912 raft_consensus.cc:2243] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:39.438941 10912 raft_consensus.cc:2272] T e9cb00662df24e3e93519e1bb1181a7f P 6792ff1f0a7f4ffba94ff1799ecfa6ed [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:39.456459 10912 tablet_server.cc:196] TabletServer@127.10.168.1:0 shutdown complete.
I20260812 06:16:39.495749 10912 master.cc:562] Master@127.10.168.62:41949 shutting down...
I20260812 06:16:39.499404 10912 raft_consensus.cc:2243] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:39.499665 10912 raft_consensus.cc:2272] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:39.499774 10912 tablet_replica.cc:333] T 00000000000000000000000000000000 P bc5ec0316b144a7eb51e5b39be00b3bf: stopping tablet replica
I20260812 06:16:39.512435 10912 master.cc:584] Master@127.10.168.62:41949 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5882 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:39.620086 10912 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.168.62:44801
I20260812 06:16:39.620564 10912 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:39.623039 11180 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:39.623104 11176 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:39.624518 11177 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:39.625264 10912 server_base.cc:1061] running on GCE node
I20260812 06:16:39.625473 10912 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:39.625531 10912 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:39.625558 10912 hybrid_clock.cc:648] HybridClock initialized: now 1786515399625557 us; error 0 us; skew 500 ppm
I20260812 06:16:39.626482 10912 webserver.cc:533] Webserver started at http://127.10.168.62:39639/ using document root <none> and password file <none>
I20260812 06:16:39.626686 10912 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:39.626765 10912 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:39.626854 10912 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:39.627302 10912 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/master-0-root/instance:
uuid: "298e8fb18b754e2e84a2e146462aa05b"
format_stamp: "Formatted at 2026-08-12 06:16:39 on dist-test-slave-sb2z"
I20260812 06:16:39.628963 10912 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:39.630012 11186 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:39.630314 10912 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:39.630414 10912 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/master-0-root
uuid: "298e8fb18b754e2e84a2e146462aa05b"
format_stamp: "Formatted at 2026-08-12 06:16:39 on dist-test-slave-sb2z"
I20260812 06:16:39.630504 10912 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:39.644964 10912 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:39.645449 10912 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:39.650359 10912 rpc_server.cc:307] RPC server started. Bound to: 127.10.168.62:44801
I20260812 06:16:39.657774 11264 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.168.62:44801 every 8 connection(s)
I20260812 06:16:39.658291 11265 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:39.660246 11265 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b: Bootstrap starting.
I20260812 06:16:39.661170 11265 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:39.662262 11265 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b: No bootstrap required, opened a new log
I20260812 06:16:39.662627 11265 raft_consensus.cc:359] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "298e8fb18b754e2e84a2e146462aa05b" member_type: VOTER }
I20260812 06:16:39.662714 11265 raft_consensus.cc:385] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:39.662737 11265 raft_consensus.cc:740] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 298e8fb18b754e2e84a2e146462aa05b, State: Initialized, Role: FOLLOWER
I20260812 06:16:39.662895 11265 consensus_queue.cc:260] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b [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: "298e8fb18b754e2e84a2e146462aa05b" member_type: VOTER }
I20260812 06:16:39.662994 11265 raft_consensus.cc:399] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:39.663028 11265 raft_consensus.cc:493] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:39.663064 11265 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:39.663833 11265 raft_consensus.cc:515] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "298e8fb18b754e2e84a2e146462aa05b" member_type: VOTER }
I20260812 06:16:39.663954 11265 leader_election.cc:304] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b [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: 298e8fb18b754e2e84a2e146462aa05b; no voters: 
I20260812 06:16:39.664126 11265 leader_election.cc:290] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:39.664301 11271 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:39.664515 11271 raft_consensus.cc:697] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b [term 1 LEADER]: Becoming Leader. State: Replica: 298e8fb18b754e2e84a2e146462aa05b, State: Running, Role: LEADER
I20260812 06:16:39.664646 11265 sys_catalog.cc:565] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:39.664709 11271 consensus_queue.cc:237] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b [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: "298e8fb18b754e2e84a2e146462aa05b" member_type: VOTER }
I20260812 06:16:39.665203 11275 sys_catalog.cc:455] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b [sys.catalog]: SysCatalogTable state changed. Reason: New leader 298e8fb18b754e2e84a2e146462aa05b. Latest consensus state: current_term: 1 leader_uuid: "298e8fb18b754e2e84a2e146462aa05b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "298e8fb18b754e2e84a2e146462aa05b" member_type: VOTER } }
I20260812 06:16:39.665163 11274 sys_catalog.cc:455] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "298e8fb18b754e2e84a2e146462aa05b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "298e8fb18b754e2e84a2e146462aa05b" member_type: VOTER } }
I20260812 06:16:39.665274 11275 sys_catalog.cc:458] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:39.665284 11274 sys_catalog.cc:458] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:39.665558 11279 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:39.666445 11279 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:39.666703 10912 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:39.668406 11279 catalog_manager.cc:1383] Generated new cluster ID: 985d7e5d6df44aabb9bfd2932775f27c
I20260812 06:16:39.668468 11279 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:39.677788 11279 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:39.678339 11279 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:39.687559 11279 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b: Generated new TSK 0
I20260812 06:16:39.687774 11279 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:39.699295 10912 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:39.701449 11294 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:39.701550 11298 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:39.701726 11296 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:39.701797 10912 server_base.cc:1061] running on GCE node
I20260812 06:16:39.702016 10912 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:39.702059 10912 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:39.702075 10912 hybrid_clock.cc:648] HybridClock initialized: now 1786515399702075 us; error 0 us; skew 500 ppm
I20260812 06:16:39.702936 10912 webserver.cc:533] Webserver started at http://127.10.168.1:46065/ using document root <none> and password file <none>
I20260812 06:16:39.703125 10912 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:39.703202 10912 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:39.703302 10912 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:39.703804 10912 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/instance:
uuid: "8bc36640cb054e87bd30b8c95fc5fd3d"
format_stamp: "Formatted at 2026-08-12 06:16:39 on dist-test-slave-sb2z"
I20260812 06:16:39.705523 10912 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:16:39.706795 11303 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:39.707144 10912 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:39.707257 10912 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root
uuid: "8bc36640cb054e87bd30b8c95fc5fd3d"
format_stamp: "Formatted at 2026-08-12 06:16:39 on dist-test-slave-sb2z"
I20260812 06:16:39.707361 10912 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:39.726898 10912 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:39.727449 10912 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:39.727855 10912 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:39.728370 10912 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:39.728434 10912 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:39.728510 10912 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:39.728546 10912 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:39.733332 10912 rpc_server.cc:307] RPC server started. Bound to: 127.10.168.1:46215
I20260812 06:16:39.733366 11391 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.168.1:46215 every 8 connection(s)
I20260812 06:16:39.742093 11392 heartbeater.cc:344] Connected to a master server at 127.10.168.62:44801
I20260812 06:16:39.742240 11392 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:39.742482 11392 heartbeater.cc:507] Master 127.10.168.62:44801 requested a full tablet report, sending...
I20260812 06:16:39.743232 11205 ts_manager.cc:194] Registered new tserver with Master: 8bc36640cb054e87bd30b8c95fc5fd3d (127.10.168.1:46215)
I20260812 06:16:39.743891 10912 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010077766s
I20260812 06:16:39.744143 11205 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:37650
I20260812 06:16:39.751700 11205 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:37654:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:16:39.761597 11339 tablet_service.cc:1511] Processing CreateTablet for tablet b6653d3af6114285bb3a32677e4a08df (DEFAULT_TABLE table=heavy-update-compaction-test [id=11bc4d4126cb430b9528f56f012a485e]), partition=
I20260812 06:16:39.761951 11339 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet b6653d3af6114285bb3a32677e4a08df. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:39.764654 11411 tablet_bootstrap.cc:492] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Bootstrap starting.
I20260812 06:16:39.765786 11411 tablet_bootstrap.cc:654] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:39.767095 11411 tablet_bootstrap.cc:492] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: No bootstrap required, opened a new log
I20260812 06:16:39.767207 11411 ts_tablet_manager.cc:1403] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:39.767793 11411 raft_consensus.cc:359] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8bc36640cb054e87bd30b8c95fc5fd3d" member_type: VOTER last_known_addr { host: "127.10.168.1" port: 46215 } }
I20260812 06:16:39.767913 11411 raft_consensus.cc:385] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:39.767961 11411 raft_consensus.cc:740] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8bc36640cb054e87bd30b8c95fc5fd3d, State: Initialized, Role: FOLLOWER
I20260812 06:16:39.768114 11411 consensus_queue.cc:260] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d [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: "8bc36640cb054e87bd30b8c95fc5fd3d" member_type: VOTER last_known_addr { host: "127.10.168.1" port: 46215 } }
I20260812 06:16:39.768215 11411 raft_consensus.cc:399] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:39.768262 11411 raft_consensus.cc:493] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:39.768317 11411 raft_consensus.cc:3060] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:39.769081 11411 raft_consensus.cc:515] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8bc36640cb054e87bd30b8c95fc5fd3d" member_type: VOTER last_known_addr { host: "127.10.168.1" port: 46215 } }
I20260812 06:16:39.769248 11411 leader_election.cc:304] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d [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: 8bc36640cb054e87bd30b8c95fc5fd3d; no voters: 
I20260812 06:16:39.769495 11411 leader_election.cc:290] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:39.769654 11414 raft_consensus.cc:2804] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:39.769873 11411 ts_tablet_manager.cc:1434] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:16:39.769907 11414 raft_consensus.cc:697] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d [term 1 LEADER]: Becoming Leader. State: Replica: 8bc36640cb054e87bd30b8c95fc5fd3d, State: Running, Role: LEADER
I20260812 06:16:39.769914 11392 heartbeater.cc:499] Master 127.10.168.62:44801 was elected leader, sending a full tablet report...
I20260812 06:16:39.770161 11414 consensus_queue.cc:237] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d [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: "8bc36640cb054e87bd30b8c95fc5fd3d" member_type: VOTER last_known_addr { host: "127.10.168.1" port: 46215 } }
I20260812 06:16:39.771711 11204 catalog_manager.cc:5719] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d reported cstate change: term changed from 0 to 1, leader changed from <none> to 8bc36640cb054e87bd30b8c95fc5fd3d (127.10.168.1). New cstate: current_term: 1 leader_uuid: "8bc36640cb054e87bd30b8c95fc5fd3d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8bc36640cb054e87bd30b8c95fc5fd3d" member_type: VOTER last_known_addr { host: "127.10.168.1" port: 46215 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:39.838179 10912 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.060s	user 0.022s	sys 0.003s
I20260812 06:16:39.984268 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushMRSOp(b6653d3af6114285bb3a32677e4a08df): perf score=19.054940
I20260812 06:16:40.138145 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushMRSOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.154s	user 0.107s	sys 0.044s Metrics: {"bytes_written":9148636,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":207,"dirs.run_wall_time_us":821,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36098,"lbm_writes_lt_1ms":680,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":768,"update_count":1115}
I20260812 06:16:40.139047 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling LogGCOp(b6653d3af6114285bb3a32677e4a08df): free 20743831 bytes of WAL
I20260812 06:16:40.139325 11309 log_reader.cc:385] T b6653d3af6114285bb3a32677e4a08df: removed 2 log segments from log reader
I20260812 06:16:40.139397 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000001 (ops 1-6)
I20260812 06:16:40.139483 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000002 (ops 7-11)
I20260812 06:16:40.145768 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: LogGCOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.007s	user 0.000s	sys 0.006s Metrics: {}
I20260812 06:16:40.146354 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling UndoDeltaBlockGCOp(b6653d3af6114285bb3a32677e4a08df): 16411393 bytes on disk
I20260812 06:16:40.146988 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: UndoDeltaBlockGCOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":83,"lbm_reads_lt_1ms":4}
I20260812 06:16:40.147507 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=2.188937
I20260812 06:16:40.165171 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.017s	user 0.011s	sys 0.002s Metrics: {"bytes_written":3569334,"delete_count":0,"lbm_write_time_us":4908,"lbm_writes_lt_1ms":90,"reinsert_count":0,"update_count":435}
I20260812 06:16:40.165776 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df): perf score=1.000000
I20260812 06:16:40.304852 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.139s	user 0.075s	sys 0.064s Metrics: {"cfile_cache_miss":342,"cfile_cache_miss_bytes":16980098,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":671,"lbm_read_time_us":9402,"lbm_reads_lt_1ms":370,"lbm_write_time_us":21670,"lbm_writes_lt_1ms":353,"peak_mem_usage":38673106,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":371,"threads_started":5,"update_count":1550}
I20260812 06:16:40.306003 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=10.126437
I20260812 06:16:40.341753 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.035s	user 0.018s	sys 0.012s Metrics: {"bytes_written":11897252,"delete_count":0,"lbm_write_time_us":14383,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:16:40.342224 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=2.188937
I20260812 06:16:40.353386 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4170,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.354163 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df): perf score=1.000000
I20260812 06:16:40.488510 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.134s	user 0.113s	sys 0.021s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262039,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":311,"lbm_read_time_us":10627,"lbm_reads_lt_1ms":462,"lbm_write_time_us":25423,"lbm_writes_lt_1ms":433,"mutex_wait_us":45,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":102656,"update_count":1950}
I20260812 06:16:40.489176 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=10.126437
I20260812 06:16:40.541406 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.052s	user 0.019s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18209,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:40.541993 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=2.188937
I20260812 06:16:40.553678 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4198,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.554409 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df): perf score=1.000000
I20260812 06:16:40.682910 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.128s	user 0.103s	sys 0.025s 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":421,"lbm_read_time_us":11510,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23493,"lbm_writes_lt_1ms":443,"mutex_wait_us":86,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2000}
I20260812 06:16:40.683701 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=10.126437
I20260812 06:16:40.734591 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.051s	user 0.021s	sys 0.024s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16551,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:40.735399 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=2.188937
I20260812 06:16:40.747013 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4515,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.747500 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df): perf score=1.000000
I20260812 06:16:40.907014 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.159s	user 0.106s	sys 0.053s 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":368,"lbm_read_time_us":11974,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26456,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:40.907711 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=10.126437
I20260812 06:16:40.964244 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.056s	user 0.029s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":23110,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:16:40.964803 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=2.188937
I20260812 06:16:40.976589 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4266,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.977237 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df): perf score=1.000000
I20260812 06:16:41.103245 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.126s	user 0.106s	sys 0.020s 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":480,"lbm_read_time_us":8465,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25255,"lbm_writes_lt_1ms":443,"mutex_wait_us":94,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2000}
I20260812 06:16:41.104089 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=10.126437
I20260812 06:16:41.146394 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.042s	user 0.015s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18596,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:41.146905 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=2.188937
I20260812 06:16:41.163707 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.017s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6230,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.164247 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df): perf score=1.000000
I20260812 06:16:41.288280 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.124s	user 0.090s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":751,"lbm_read_time_us":8210,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24004,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:16:41.289038 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=11.118625
I20260812 06:16:41.346851 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.057s	user 0.028s	sys 0.021s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":19218,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:41.347361 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=4.173312
I20260812 06:16:41.363366 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.016s	user 0.009s	sys 0.005s Metrics: {"bytes_written":6276941,"delete_count":0,"lbm_write_time_us":6635,"lbm_writes_lt_1ms":156,"reinsert_count":0,"update_count":765}
I20260812 06:16:41.363922 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=1.000000
I20260812 06:16:41.371080 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.007s	user 0.000s	sys 0.005s Metrics: {"bytes_written":1518077,"delete_count":0,"lbm_write_time_us":2103,"lbm_writes_lt_1ms":40,"reinsert_count":0,"update_count":185}
I20260812 06:16:41.371665 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushMRSOp(b6653d3af6114285bb3a32677e4a08df): perf score=1.000000
I20260812 06:16:41.400892 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushMRSOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.029s	user 0.022s	sys 0.005s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":99,"dirs.run_cpu_time_us":271,"dirs.run_wall_time_us":1488,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1599,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:41.401530 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling LogGCOp(b6653d3af6114285bb3a32677e4a08df): free 115943236 bytes of WAL
I20260812 06:16:41.401768 11309 log_reader.cc:385] T b6653d3af6114285bb3a32677e4a08df: removed 11 log segments from log reader
I20260812 06:16:41.401813 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000003 (ops 12-16)
I20260812 06:16:41.401866 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000004 (ops 17-21)
I20260812 06:16:41.401912 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000005 (ops 22-26)
I20260812 06:16:41.401957 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000006 (ops 27-31)
I20260812 06:16:41.401996 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000007 (ops 32-36)
I20260812 06:16:41.402060 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000008 (ops 37-41)
I20260812 06:16:41.402101 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000009 (ops 42-46)
I20260812 06:16:41.402140 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000010 (ops 47-51)
I20260812 06:16:41.402180 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000011 (ops 52-56)
I20260812 06:16:41.402220 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000012 (ops 57-61)
I20260812 06:16:41.402261 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000013 (ops 62-66)
I20260812 06:16:41.428309 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: LogGCOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:16:41.428855 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=2.188937
I20260812 06:16:41.444888 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.016s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4337,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.445393 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling UndoDeltaBlockGCOp(b6653d3af6114285bb3a32677e4a08df): 447 bytes on disk
I20260812 06:16:41.445809 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: UndoDeltaBlockGCOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:16:41.446238 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=2.188937
I20260812 06:16:41.457358 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4234,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.458000 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df): perf score=1.000000
I20260812 06:16:41.691975 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.234s	user 0.175s	sys 0.053s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979812,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":725,"lbm_read_time_us":17903,"lbm_reads_lt_1ms":775,"lbm_write_time_us":39138,"lbm_writes_lt_1ms":743,"mutex_wait_us":98,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":81,"threads_started":1,"update_count":3500}
I20260812 06:16:41.692718 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=18.063937
I20260812 06:16:41.756762 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.064s	user 0.039s	sys 0.024s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":28572,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:41.757414 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=2.188937
I20260812 06:16:41.773455 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6014,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.774127 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df): perf score=1.000000
I20260812 06:16:41.945072 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.171s	user 0.145s	sys 0.026s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877100,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":325,"lbm_read_time_us":13053,"lbm_reads_lt_1ms":668,"lbm_write_time_us":35827,"lbm_writes_lt_1ms":643,"mutex_wait_us":114,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":3000}
I20260812 06:16:41.945825 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=14.095187
I20260812 06:16:41.998247 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.052s	user 0.032s	sys 0.018s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23644,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:16:41.998806 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=2.188937
I20260812 06:16:42.011112 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4504,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:42.011672 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df): perf score=1.000000
I20260812 06:16:42.194118 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.182s	user 0.126s	sys 0.045s 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":445,"lbm_read_time_us":12061,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33267,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":36608,"update_count":2500}
I20260812 06:16:42.194913 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=14.095187
I20260812 06:16:42.255746 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.061s	user 0.034s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":24589,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:42.256395 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df): perf score=1.000000
I20260812 06:16:42.415216 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.159s	user 0.108s	sys 0.045s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672156,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":695,"lbm_read_time_us":11023,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25717,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2000}
I20260812 06:16:42.415870 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=14.095187
I20260812 06:16:42.473719 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.058s	user 0.039s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22984,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:42.474233 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=2.188937
I20260812 06:16:42.486119 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4238,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:42.486670 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df): perf score=1.000000
I20260812 06:16:42.668053 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.181s	user 0.105s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":323,"lbm_read_time_us":12068,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27686,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2500}
I20260812 06:16:42.668728 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=14.095187
I20260812 06:16:42.717957 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.049s	user 0.026s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20744,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:42.718595 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=2.188937
I20260812 06:16:42.735097 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6153,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:42.735736 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df): perf score=1.000000
I20260812 06:16:42.905156 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.169s	user 0.099s	sys 0.068s 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":1037,"lbm_read_time_us":11349,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32400,"lbm_writes_lt_1ms":543,"mutex_wait_us":306,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":2500}
I20260812 06:16:42.905805 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=11.118625
I20260812 06:16:42.945171 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.039s	user 0.030s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16605,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:42.945946 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=2.188937
I20260812 06:16:42.961557 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.015s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4187,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:42.962069 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushMRSOp(b6653d3af6114285bb3a32677e4a08df): perf score=1.000000
I20260812 06:16:43.017612 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushMRSOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.055s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":93,"dirs.run_cpu_time_us":228,"dirs.run_wall_time_us":1556,"drs_written":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2436,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:16:43.018580 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling LogGCOp(b6653d3af6114285bb3a32677e4a08df): free 121006389 bytes of WAL
I20260812 06:16:43.018904 11309 log_reader.cc:385] T b6653d3af6114285bb3a32677e4a08df: removed 12 log segments from log reader
I20260812 06:16:43.018987 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000014 (ops 67-71)
I20260812 06:16:43.019043 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000015 (ops 72-76)
I20260812 06:16:43.019100 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000016 (ops 77-81)
I20260812 06:16:43.019145 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000017 (ops 82-86)
I20260812 06:16:43.019181 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000018 (ops 87-91)
I20260812 06:16:43.019222 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000019 (ops 92-96)
I20260812 06:16:43.019261 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000020 (ops 97-101)
I20260812 06:16:43.019300 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000021 (ops 102-106)
I20260812 06:16:43.019340 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000022 (ops 107-110)
I20260812 06:16:43.019379 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000023 (ops 111-115)
I20260812 06:16:43.019424 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000024 (ops 116-120)
I20260812 06:16:43.019464 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000025 (ops 121-125)
I20260812 06:16:43.047906 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: LogGCOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.029s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:16:43.048388 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=6.157687
I20260812 06:16:43.089474 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.041s	user 0.023s	sys 0.016s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12936,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:43.090142 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling LogGCOp(b6653d3af6114285bb3a32677e4a08df): free 12017991 bytes of WAL
I20260812 06:16:43.090440 11309 log_reader.cc:385] T b6653d3af6114285bb3a32677e4a08df: removed 1 log segments from log reader
I20260812 06:16:43.090497 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000026 (ops 126-130)
I20260812 06:16:43.093073 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: LogGCOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:43.093480 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=2.188937
I20260812 06:16:43.104513 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.011s	user 0.004s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4202,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:43.105084 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling UndoDeltaBlockGCOp(b6653d3af6114285bb3a32677e4a08df): 492 bytes on disk
I20260812 06:16:43.105619 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: UndoDeltaBlockGCOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:16:43.106215 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df): perf score=1.000000
I20260812 06:16:43.380313 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.274s	user 0.166s	sys 0.096s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979743,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3805,"lbm_read_time_us":19519,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42136,"lbm_writes_lt_1ms":743,"mutex_wait_us":2469,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":28800,"thread_start_us":81,"threads_started":1,"update_count":3500}
I20260812 06:16:43.381068 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=18.063937
I20260812 06:16:43.450937 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.070s	user 0.037s	sys 0.022s Metrics: {"bytes_written":20512320,"delete_count":0,"lbm_write_time_us":28027,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:43.451622 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=2.188937
I20260812 06:16:43.465202 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.013s	user 0.010s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4652,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:43.465710 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df): perf score=1.000000
I20260812 06:16:43.688704 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.223s	user 0.145s	sys 0.071s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877107,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":242,"lbm_read_time_us":17256,"lbm_reads_lt_1ms":668,"lbm_write_time_us":33715,"lbm_writes_lt_1ms":643,"mutex_wait_us":67,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17792,"update_count":3000}
I20260812 06:16:43.689962 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=17.071750
I20260812 06:16:43.770007 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.080s	user 0.034s	sys 0.028s Metrics: {"bytes_written":18830324,"delete_count":0,"lbm_write_time_us":29132,"lbm_writes_lt_1ms":462,"reinsert_count":0,"update_count":2295}
I20260812 06:16:43.770601 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=4.173312
I20260812 06:16:43.787050 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.016s	user 0.002s	sys 0.011s Metrics: {"bytes_written":5784663,"delete_count":0,"lbm_write_time_us":6178,"lbm_writes_lt_1ms":144,"reinsert_count":0,"update_count":705}
I20260812 06:16:43.787621 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df): perf score=1.000000
I20260812 06:16:43.995811 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.208s	user 0.121s	sys 0.085s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877109,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1072,"lbm_read_time_us":14616,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33497,"lbm_writes_lt_1ms":643,"mutex_wait_us":337,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":3000}
I20260812 06:16:43.996444 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=16.079562
I20260812 06:16:44.044039 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.047s	user 0.026s	sys 0.021s Metrics: {"bytes_written":18009852,"delete_count":0,"lbm_write_time_us":21174,"lbm_writes_lt_1ms":442,"reinsert_count":0,"update_count":2195}
I20260812 06:16:44.044744 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=1.196750
I20260812 06:16:44.067484 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.023s	user 0.005s	sys 0.003s Metrics: {"bytes_written":2502679,"delete_count":0,"lbm_write_time_us":3273,"lbm_writes_lt_1ms":64,"reinsert_count":0,"update_count":305}
I20260812 06:16:44.068020 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=2.188937
I20260812 06:16:44.078555 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4082,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.079022 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df): perf score=1.000000
I20260812 06:16:44.296006 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.217s	user 0.142s	sys 0.075s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877190,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":531,"lbm_read_time_us":16525,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34214,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:16:44.296866 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=15.087375
I20260812 06:16:44.347661 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.051s	user 0.039s	sys 0.011s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":21981,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:16:44.348565 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=2.188937
I20260812 06:16:44.375306 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.026s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5594,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:44.375885 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=2.188937
I20260812 06:16:44.391299 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5919,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.392035 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df): perf score=1.000000
I20260812 06:16:44.610034 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.218s	user 0.120s	sys 0.097s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877206,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":258,"lbm_read_time_us":14405,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38493,"lbm_writes_lt_1ms":643,"mutex_wait_us":56,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16000,"update_count":3000}
I20260812 06:16:44.610674 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=14.095187
I20260812 06:16:44.666247 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.055s	user 0.025s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24349,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:44.667099 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=2.188937
I20260812 06:16:44.683272 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.016s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4639,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.683965 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushMRSOp(b6653d3af6114285bb3a32677e4a08df): perf score=1.000000
I20260812 06:16:44.725961 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushMRSOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.042s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":263,"dirs.run_wall_time_us":1508,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1867,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:16:44.726991 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling UndoDeltaBlockGCOp(b6653d3af6114285bb3a32677e4a08df): 493 bytes on disk
I20260812 06:16:44.727698 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: UndoDeltaBlockGCOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:16:44.728322 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=3.181125
I20260812 06:16:44.744475 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.016s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4827,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:44.745023 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling LogGCOp(b6653d3af6114285bb3a32677e4a08df): free 133024661 bytes of WAL
I20260812 06:16:44.745272 11309 log_reader.cc:385] T b6653d3af6114285bb3a32677e4a08df: removed 13 log segments from log reader
I20260812 06:16:44.745354 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000027 (ops 131-135)
I20260812 06:16:44.745424 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000028 (ops 136-140)
I20260812 06:16:44.745466 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000029 (ops 141-145)
I20260812 06:16:44.745496 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000030 (ops 146-150)
I20260812 06:16:44.745553 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000031 (ops 151-155)
I20260812 06:16:44.745591 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000032 (ops 156-160)
I20260812 06:16:44.745684 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000033 (ops 161-165)
I20260812 06:16:44.745723 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000034 (ops 166-170)
I20260812 06:16:44.745751 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000035 (ops 171-175)
I20260812 06:16:44.745812 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000036 (ops 176-180)
I20260812 06:16:44.745855 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000037 (ops 181-184)
I20260812 06:16:44.745895 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000038 (ops 185-189)
I20260812 06:16:44.745937 11309 log.cc:1079] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: Deleting log segment in path: /tmp/dist-test-taskV4eMSb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515393711291-10912-0/minicluster-data/ts-0-root/wals/b6653d3af6114285bb3a32677e4a08df/wal-000000039 (ops 190-194)
I20260812 06:16:44.777755 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: LogGCOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.033s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:16:44.778255 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=2.188937
I20260812 06:16:44.791399 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4771,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.792171 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df): perf score=2.188937
I20260812 06:16:44.806936 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: FlushDeltaMemStoresOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5601,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:44.807698 11393 maintenance_manager.cc:419] P 8bc36640cb054e87bd30b8c95fc5fd3d: Scheduling MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df): perf score=1.000000
I20260812 06:16:44.890305 10912 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.052s	user 1.864s	sys 0.157s
I20260812 06:16:45.002265 10912 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.111s	user 0.001s	sys 0.000s
I20260812 06:16:45.002882 10912 tablet_server.cc:179] TabletServer@127.10.168.1:0 shutting down...
I20260812 06:16:45.039047 11309 maintenance_manager.cc:643] P 8bc36640cb054e87bd30b8c95fc5fd3d: MajorDeltaCompactionOp(b6653d3af6114285bb3a32677e4a08df) complete. Timing: real 0.231s	user 0.138s	sys 0.093s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082272,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1027,"lbm_read_time_us":17960,"lbm_reads_lt_1ms":871,"lbm_write_time_us":37431,"lbm_writes_lt_1ms":843,"mutex_wait_us":86,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":2944,"thread_start_us":84,"threads_started":1,"update_count":4000}
I20260812 06:16:45.040190 10912 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:45.040607 10912 tablet_replica.cc:333] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d: stopping tablet replica
I20260812 06:16:45.040778 10912 raft_consensus.cc:2243] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:45.041000 10912 raft_consensus.cc:2272] T b6653d3af6114285bb3a32677e4a08df P 8bc36640cb054e87bd30b8c95fc5fd3d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:45.047395 10912 tablet_server.cc:196] TabletServer@127.10.168.1:0 shutdown complete.
I20260812 06:16:45.110518 10912 master.cc:562] Master@127.10.168.62:44801 shutting down...
I20260812 06:16:45.114648 10912 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:45.114846 10912 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:45.114902 10912 tablet_replica.cc:333] T 00000000000000000000000000000000 P 298e8fb18b754e2e84a2e146462aa05b: stopping tablet replica
I20260812 06:16:45.127635 10912 master.cc:584] Master@127.10.168.62:44801 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5623 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11507 ms total)

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