[==========] 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:18:58.012487 17733 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.17.81.126:39365
I20260812 06:18:58.013684 17733 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:18:58.014427 17733 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:18:58.023044 17733 server_base.cc:1061] running on GCE node
W20260812 06:18:58.023002 17739 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:18:58.023002 17740 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:18:58.023291 17742 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:18:58.023975 17733 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:58.024108 17733 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:18:58.024159 17733 hybrid_clock.cc:648] HybridClock initialized: now 1786515538024157 us; error 0 us; skew 500 ppm
I20260812 06:18:58.026198 17733 webserver.cc:533] Webserver started at http://127.17.81.126:45307/ using document root <none> and password file <none>
I20260812 06:18:58.026865 17733 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:58.026955 17733 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:58.027235 17733 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:58.029171 17733 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/master-0-root/instance:
uuid: "405e59dfb76641798ebfe939d1335033"
format_stamp: "Formatted at 2026-08-12 06:18:58 on dist-test-slave-27sr"
I20260812 06:18:58.033284 17733 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.004s	sys 0.000s
I20260812 06:18:58.035782 17747 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:18:58.037215 17733 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:58.037393 17733 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/master-0-root
uuid: "405e59dfb76641798ebfe939d1335033"
format_stamp: "Formatted at 2026-08-12 06:18:58 on dist-test-slave-27sr"
I20260812 06:18:58.037523 17733 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-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:18:58.051388 17733 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:58.052217 17733 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:18:58.052414 17733 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:58.061154 17733 rpc_server.cc:307] RPC server started. Bound to: 127.17.81.126:39365
I20260812 06:18:58.061156 17814 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.81.126:39365 every 8 connection(s)
I20260812 06:18:58.064152 17815 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:18:58.070154 17815 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033: Bootstrap starting.
I20260812 06:18:58.072882 17815 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:58.073988 17815 log.cc:826] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:58.076151 17815 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033: No bootstrap required, opened a new log
I20260812 06:18:58.079402 17815 raft_consensus.cc:359] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "405e59dfb76641798ebfe939d1335033" member_type: VOTER }
I20260812 06:18:58.079609 17815 raft_consensus.cc:385] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:58.079746 17815 raft_consensus.cc:740] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 405e59dfb76641798ebfe939d1335033, State: Initialized, Role: FOLLOWER
I20260812 06:18:58.080507 17815 consensus_queue.cc:260] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033 [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: "405e59dfb76641798ebfe939d1335033" member_type: VOTER }
I20260812 06:18:58.080760 17815 raft_consensus.cc:399] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:58.080827 17815 raft_consensus.cc:493] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:58.081014 17815 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:58.081950 17815 raft_consensus.cc:515] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "405e59dfb76641798ebfe939d1335033" member_type: VOTER }
I20260812 06:18:58.082458 17815 leader_election.cc:304] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033 [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: 405e59dfb76641798ebfe939d1335033; no voters: 
I20260812 06:18:58.082881 17815 leader_election.cc:290] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:58.083041 17818 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:58.083371 17818 raft_consensus.cc:697] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033 [term 1 LEADER]: Becoming Leader. State: Replica: 405e59dfb76641798ebfe939d1335033, State: Running, Role: LEADER
I20260812 06:18:58.083879 17818 consensus_queue.cc:237] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033 [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: "405e59dfb76641798ebfe939d1335033" member_type: VOTER }
I20260812 06:18:58.084134 17815 sys_catalog.cc:565] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:58.086134 17821 sys_catalog.cc:455] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 405e59dfb76641798ebfe939d1335033. Latest consensus state: current_term: 1 leader_uuid: "405e59dfb76641798ebfe939d1335033" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "405e59dfb76641798ebfe939d1335033" member_type: VOTER } }
I20260812 06:18:58.086123 17819 sys_catalog.cc:455] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "405e59dfb76641798ebfe939d1335033" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "405e59dfb76641798ebfe939d1335033" member_type: VOTER } }
I20260812 06:18:58.086292 17819 sys_catalog.cc:458] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:58.086292 17821 sys_catalog.cc:458] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:58.086675 17831 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:58.086897 17733 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:58.089139 17831 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:58.094841 17831 catalog_manager.cc:1383] Generated new cluster ID: f17e1821daab4944b9691b4362f3bb1b
I20260812 06:18:58.094938 17831 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:58.110176 17831 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:58.111133 17831 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:58.125027 17831 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033: Generated new TSK 0
I20260812 06:18:58.125809 17831 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:58.152016 17733 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:58.155027 17838 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:18:58.155071 17841 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:18:58.155064 17839 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:18:58.155543 17733 server_base.cc:1061] running on GCE node
I20260812 06:18:58.155741 17733 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:58.155793 17733 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:18:58.155833 17733 hybrid_clock.cc:648] HybridClock initialized: now 1786515538155812 us; error 0 us; skew 500 ppm
I20260812 06:18:58.156857 17733 webserver.cc:533] Webserver started at http://127.17.81.65:36567/ using document root <none> and password file <none>
I20260812 06:18:58.157052 17733 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:58.157112 17733 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:58.157218 17733 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:58.157660 17733 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/instance:
uuid: "70af1453b364416bad390ca9a80e7949"
format_stamp: "Formatted at 2026-08-12 06:18:58 on dist-test-slave-27sr"
I20260812 06:18:58.159318 17733 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:58.160410 17849 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:18:58.160691 17733 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:18:58.160768 17733 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root
uuid: "70af1453b364416bad390ca9a80e7949"
format_stamp: "Formatted at 2026-08-12 06:18:58 on dist-test-slave-27sr"
I20260812 06:18:58.160845 17733 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-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:18:58.168632 17733 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:58.169137 17733 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:58.169711 17733 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:58.170681 17733 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:58.170734 17733 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:58.170812 17733 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:58.170853 17733 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:58.178190 17733 rpc_server.cc:307] RPC server started. Bound to: 127.17.81.65:40805
I20260812 06:18:58.178213 17920 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.81.65:40805 every 8 connection(s)
I20260812 06:18:58.189949 17921 heartbeater.cc:344] Connected to a master server at 127.17.81.126:39365
I20260812 06:18:58.190253 17921 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:58.190810 17921 heartbeater.cc:507] Master 127.17.81.126:39365 requested a full tablet report, sending...
I20260812 06:18:58.192579 17770 ts_manager.cc:194] Registered new tserver with Master: 70af1453b364416bad390ca9a80e7949 (127.17.81.65:40805)
I20260812 06:18:58.192655 17733 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013731782s
I20260812 06:18:58.194226 17770 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60584
I20260812 06:18:58.202914 17770 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60594:
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:18:58.217741 17879 tablet_service.cc:1511] Processing CreateTablet for tablet 51fe702f12ab4cc88fd6c712e3fb1b41 (DEFAULT_TABLE table=heavy-update-compaction-test [id=9f72f03296f74b87aae776555e8e6562]), partition=
I20260812 06:18:58.218251 17879 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 51fe702f12ab4cc88fd6c712e3fb1b41. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:58.220824 17936 tablet_bootstrap.cc:492] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Bootstrap starting.
I20260812 06:18:58.221964 17936 tablet_bootstrap.cc:654] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:58.223287 17936 tablet_bootstrap.cc:492] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: No bootstrap required, opened a new log
I20260812 06:18:58.223385 17936 ts_tablet_manager.cc:1403] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:58.223978 17936 raft_consensus.cc:359] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "70af1453b364416bad390ca9a80e7949" member_type: VOTER last_known_addr { host: "127.17.81.65" port: 40805 } }
I20260812 06:18:58.224092 17936 raft_consensus.cc:385] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:58.224114 17936 raft_consensus.cc:740] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 70af1453b364416bad390ca9a80e7949, State: Initialized, Role: FOLLOWER
I20260812 06:18:58.224311 17936 consensus_queue.cc:260] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949 [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: "70af1453b364416bad390ca9a80e7949" member_type: VOTER last_known_addr { host: "127.17.81.65" port: 40805 } }
I20260812 06:18:58.224400 17936 raft_consensus.cc:399] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:58.224447 17936 raft_consensus.cc:493] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:58.224509 17936 raft_consensus.cc:3060] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:58.225463 17936 raft_consensus.cc:515] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "70af1453b364416bad390ca9a80e7949" member_type: VOTER last_known_addr { host: "127.17.81.65" port: 40805 } }
I20260812 06:18:58.225633 17936 leader_election.cc:304] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949 [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: 70af1453b364416bad390ca9a80e7949; no voters: 
I20260812 06:18:58.225912 17936 leader_election.cc:290] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:58.226039 17938 raft_consensus.cc:2804] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:58.226267 17938 raft_consensus.cc:697] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949 [term 1 LEADER]: Becoming Leader. State: Replica: 70af1453b364416bad390ca9a80e7949, State: Running, Role: LEADER
I20260812 06:18:58.226333 17936 ts_tablet_manager.cc:1434] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:58.226423 17938 consensus_queue.cc:237] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949 [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: "70af1453b364416bad390ca9a80e7949" member_type: VOTER last_known_addr { host: "127.17.81.65" port: 40805 } }
I20260812 06:18:58.226820 17921 heartbeater.cc:499] Master 127.17.81.126:39365 was elected leader, sending a full tablet report...
I20260812 06:18:58.230299 17770 catalog_manager.cc:5719] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949 reported cstate change: term changed from 0 to 1, leader changed from <none> to 70af1453b364416bad390ca9a80e7949 (127.17.81.65). New cstate: current_term: 1 leader_uuid: "70af1453b364416bad390ca9a80e7949" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "70af1453b364416bad390ca9a80e7949" member_type: VOTER last_known_addr { host: "127.17.81.65" port: 40805 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:58.302000 17733 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.021s	sys 0.007s
I20260812 06:18:58.429468 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushMRSOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=15.086190
I20260812 06:18:58.600543 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushMRSOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.171s	user 0.123s	sys 0.036s Metrics: {"bytes_written":11897249,"cfile_init":1,"compiler_manager_pool.queue_time_us":229,"delete_count":0,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":246,"dirs.run_wall_time_us":1187,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40101,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":113,"threads_started":1,"update_count":1450}
I20260812 06:18:58.601681 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling LogGCOp(51fe702f12ab4cc88fd6c712e3fb1b41): free 20743880 bytes of WAL
I20260812 06:18:58.602000 17854 log_reader.cc:385] T 51fe702f12ab4cc88fd6c712e3fb1b41: removed 2 log segments from log reader
I20260812 06:18:58.602082 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000001 (ops 1-6)
I20260812 06:18:58.602172 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000002 (ops 7-11)
I20260812 06:18:58.606458 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: LogGCOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:58.606802 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=2.188937
I20260812 06:18:58.624010 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5711,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:58.624497 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=1.000000
I20260812 06:18:58.756379 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.132s	user 0.095s	sys 0.037s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262036,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":905,"lbm_read_time_us":7617,"lbm_reads_lt_1ms":458,"lbm_write_time_us":25824,"lbm_writes_lt_1ms":433,"mutex_wait_us":24,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":13696,"thread_start_us":356,"threads_started":5,"update_count":1950}
I20260812 06:18:58.757042 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling UndoDeltaBlockGCOp(51fe702f12ab4cc88fd6c712e3fb1b41): 12719216 bytes on disk
I20260812 06:18:58.757593 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: UndoDeltaBlockGCOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":88,"lbm_reads_lt_1ms":4}
I20260812 06:18:58.758147 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=10.126437
I20260812 06:18:58.798593 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.040s	user 0.010s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19062,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:58.799098 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=2.188937
I20260812 06:18:58.811028 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4370,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:58.811676 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=1.000000
I20260812 06:18:58.957442 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.146s	user 0.119s	sys 0.026s 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":261,"lbm_read_time_us":8828,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29885,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:58.958122 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=10.126437
I20260812 06:18:58.996308 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.038s	user 0.024s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15322,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:58.996837 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=2.188937
I20260812 06:18:59.008553 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4065,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.009078 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=1.000000
I20260812 06:18:59.144935 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.136s	user 0.116s	sys 0.019s 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":350,"lbm_read_time_us":10530,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25618,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2000}
I20260812 06:18:59.145478 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=10.126437
I20260812 06:18:59.190423 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.045s	user 0.013s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13895,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:59.190955 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=2.188937
I20260812 06:18:59.202158 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4349,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.202661 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=1.000000
I20260812 06:18:59.357445 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.155s	user 0.120s	sys 0.033s 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":153,"lbm_read_time_us":11111,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25137,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":83968,"update_count":2000}
I20260812 06:18:59.358160 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=10.126437
I20260812 06:18:59.401930 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.044s	user 0.024s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17515,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:18:59.402396 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=2.188937
I20260812 06:18:59.413409 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4111,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.414199 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=1.000000
I20260812 06:18:59.547149 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.133s	user 0.100s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1177,"lbm_read_time_us":10074,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24154,"lbm_writes_lt_1ms":443,"mutex_wait_us":330,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2000}
I20260812 06:18:59.547919 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=10.126437
I20260812 06:18:59.588459 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.040s	user 0.031s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17878,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:18:59.589085 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=2.188937
I20260812 06:18:59.605280 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.016s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6419,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.608878 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=1.000000
I20260812 06:18:59.734248 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.125s	user 0.099s	sys 0.026s 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":762,"lbm_read_time_us":8281,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25873,"lbm_writes_lt_1ms":443,"mutex_wait_us":77,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:59.734958 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=10.126437
I20260812 06:18:59.777921 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.043s	user 0.028s	sys 0.005s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15558,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:59.778388 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=2.188937
I20260812 06:18:59.789325 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.011s	user 0.009s	sys 0.001s 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:18:59.789810 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=1.000000
I20260812 06:18:59.910392 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.120s	user 0.076s	sys 0.044s 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":1029,"lbm_read_time_us":9404,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23472,"lbm_writes_lt_1ms":443,"mutex_wait_us":304,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2000}
I20260812 06:18:59.911231 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=10.126437
I20260812 06:18:59.960427 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.049s	user 0.033s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16037,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:59.960978 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=2.188937
I20260812 06:18:59.972172 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.011s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4310,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.972668 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushMRSOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=1.000000
I20260812 06:19:00.005038 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushMRSOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.032s	user 0.025s	sys 0.006s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":1503,"drs_written":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1557,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:00.005882 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=1.000000
I20260812 06:19:00.150261 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.144s	user 0.096s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":783,"lbm_read_time_us":8941,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24241,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2000}
I20260812 06:19:00.151125 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling LogGCOp(51fe702f12ab4cc88fd6c712e3fb1b41): free 120553329 bytes of WAL
I20260812 06:19:00.151393 17854 log_reader.cc:385] T 51fe702f12ab4cc88fd6c712e3fb1b41: removed 12 log segments from log reader
I20260812 06:19:00.151446 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000003 (ops 12-16)
I20260812 06:19:00.151495 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000004 (ops 17-20)
I20260812 06:19:00.151535 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000005 (ops 21-25)
I20260812 06:19:00.151619 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000006 (ops 26-30)
I20260812 06:19:00.151679 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000007 (ops 31-35)
I20260812 06:19:00.151716 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000008 (ops 36-40)
I20260812 06:19:00.151780 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000009 (ops 41-44)
I20260812 06:19:00.151824 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000010 (ops 45-49)
I20260812 06:19:00.151916 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000011 (ops 50-54)
I20260812 06:19:00.151973 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000012 (ops 55-59)
I20260812 06:19:00.152031 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000013 (ops 60-64)
I20260812 06:19:00.152074 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000014 (ops 65-69)
I20260812 06:19:00.179836 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: LogGCOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.029s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:19:00.180353 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=14.095187
I20260812 06:19:00.226225 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.046s	user 0.035s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19934,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:00.226835 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=2.188937
I20260812 06:19:00.261680 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.035s	user 0.014s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5659,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.262204 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling UndoDeltaBlockGCOp(51fe702f12ab4cc88fd6c712e3fb1b41): 483 bytes on disk
I20260812 06:19:00.262653 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: UndoDeltaBlockGCOp(51fe702f12ab4cc88fd6c712e3fb1b41) 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:19:00.263101 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=2.188937
I20260812 06:19:00.274147 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4110,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.274662 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=1.000000
I20260812 06:19:00.486014 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.211s	user 0.141s	sys 0.063s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":318,"lbm_read_time_us":15370,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33552,"lbm_writes_lt_1ms":643,"mutex_wait_us":40,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":3000}
I20260812 06:19:00.486748 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=14.095187
I20260812 06:19:00.563632 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.077s	user 0.033s	sys 0.026s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":35921,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:00.564198 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=2.188937
I20260812 06:19:00.579869 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.015s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4810,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.580402 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=2.188937
I20260812 06:19:00.591176 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4109,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.591629 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=1.000000
I20260812 06:19:00.801083 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.209s	user 0.157s	sys 0.051s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":259,"lbm_read_time_us":15998,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36726,"lbm_writes_lt_1ms":643,"mutex_wait_us":58,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":3000}
I20260812 06:19:00.801685 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=14.095187
I20260812 06:19:00.863989 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.062s	user 0.021s	sys 0.034s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":24535,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:00.864564 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=2.188937
I20260812 06:19:00.875008 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4023,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.875507 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=1.000000
I20260812 06:19:01.046609 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.171s	user 0.108s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":210,"lbm_read_time_us":13570,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29550,"lbm_writes_lt_1ms":543,"mutex_wait_us":91,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13056,"update_count":2500}
I20260812 06:19:01.047494 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=11.118625
I20260812 06:19:01.092962 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.045s	user 0.021s	sys 0.023s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16414,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:01.093500 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=2.188937
I20260812 06:19:01.104660 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4149,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:01.105127 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=1.000000
I20260812 06:19:01.253515 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.148s	user 0.103s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":264,"lbm_read_time_us":10683,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24601,"lbm_writes_lt_1ms":443,"mutex_wait_us":94,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:01.254212 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=11.118625
I20260812 06:19:01.284941 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.031s	user 0.018s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13725,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:01.285640 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=2.188937
I20260812 06:19:01.297648 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3779,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:01.298426 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=1.000000
I20260812 06:19:01.428156 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.129s	user 0.110s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":224,"lbm_read_time_us":9073,"lbm_reads_lt_1ms":468,"lbm_write_time_us":25372,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2000}
I20260812 06:19:01.429283 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=10.126437
I20260812 06:19:01.472857 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.041s	user 0.018s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13937,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:01.473417 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=2.188937
I20260812 06:19:01.484369 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4017,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.485298 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushMRSOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=1.000000
I20260812 06:19:01.513841 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushMRSOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.028s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":49,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":1494,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1678,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:01.514561 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling LogGCOp(51fe702f12ab4cc88fd6c712e3fb1b41): free 128867509 bytes of WAL
I20260812 06:19:01.514810 17854 log_reader.cc:385] T 51fe702f12ab4cc88fd6c712e3fb1b41: removed 13 log segments from log reader
I20260812 06:19:01.514856 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000015 (ops 70-74)
I20260812 06:19:01.514885 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000016 (ops 75-78)
I20260812 06:19:01.514940 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000017 (ops 79-83)
I20260812 06:19:01.514986 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000018 (ops 84-88)
I20260812 06:19:01.515046 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000019 (ops 89-92)
I20260812 06:19:01.515094 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000020 (ops 93-97)
I20260812 06:19:01.515156 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000021 (ops 98-102)
I20260812 06:19:01.515202 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000022 (ops 103-106)
I20260812 06:19:01.515239 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000023 (ops 107-111)
I20260812 06:19:01.515276 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000024 (ops 112-116)
I20260812 06:19:01.515314 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000025 (ops 117-121)
I20260812 06:19:01.515354 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000026 (ops 122-126)
I20260812 06:19:01.515393 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000027 (ops 127-131)
I20260812 06:19:01.544739 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: LogGCOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:01.545217 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=3.181125
I20260812 06:19:01.557691 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4674,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:01.558167 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=2.188937
I20260812 06:19:01.572438 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5413,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:01.573010 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=1.000000
I20260812 06:19:01.758749 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.186s	user 0.145s	sys 0.029s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2844,"lbm_read_time_us":12113,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37159,"lbm_writes_lt_1ms":643,"mutex_wait_us":2709,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14976,"thread_start_us":98,"threads_started":1,"update_count":3000}
I20260812 06:19:01.759286 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=14.095187
I20260812 06:19:01.819586 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.060s	user 0.027s	sys 0.023s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23736,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:01.820151 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling UndoDeltaBlockGCOp(51fe702f12ab4cc88fd6c712e3fb1b41): 462 bytes on disk
I20260812 06:19:01.820604 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: UndoDeltaBlockGCOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:19:01.821112 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=2.188937
I20260812 06:19:01.832652 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4032,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.833148 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=1.000000
I20260812 06:19:02.010553 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.177s	user 0.136s	sys 0.029s 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":174,"lbm_read_time_us":11204,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35613,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17408,"update_count":2500}
I20260812 06:19:02.011175 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=14.095187
I20260812 06:19:02.073694 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.062s	user 0.042s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24496,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:02.074220 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=2.188937
I20260812 06:19:02.087822 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4670,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.088438 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=1.000000
I20260812 06:19:02.278151 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.190s	user 0.132s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1194,"lbm_read_time_us":13067,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32960,"lbm_writes_lt_1ms":543,"mutex_wait_us":363,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2500}
I20260812 06:19:02.278863 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=14.095187
I20260812 06:19:02.343570 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.065s	user 0.024s	sys 0.024s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":23963,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:02.344125 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=2.188937
I20260812 06:19:02.356029 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4239,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.356534 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=1.000000
I20260812 06:19:02.534623 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.178s	user 0.124s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1011,"lbm_read_time_us":11975,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31399,"lbm_writes_lt_1ms":543,"mutex_wait_us":276,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2500}
I20260812 06:19:02.535356 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=14.095187
I20260812 06:19:02.596063 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.060s	user 0.032s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23431,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:02.596591 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=2.188937
I20260812 06:19:02.608491 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4121,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.609051 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=1.000000
I20260812 06:19:02.777473 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.168s	user 0.109s	sys 0.058s 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":1159,"lbm_read_time_us":11898,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31462,"lbm_writes_lt_1ms":543,"mutex_wait_us":291,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:19:02.778076 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=14.095187
I20260812 06:19:02.836193 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.058s	user 0.029s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24111,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:19:02.836807 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=2.188937
I20260812 06:19:02.848012 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.011s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4372,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.848500 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=1.000000
I20260812 06:19:03.040729 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.192s	user 0.138s	sys 0.042s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":759,"lbm_read_time_us":12833,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31780,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:19:03.041337 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=14.095187
I20260812 06:19:03.112898 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.071s	user 0.035s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23875,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:03.113623 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=2.188937
I20260812 06:19:03.130007 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6482,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.130533 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushMRSOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=1.000000
I20260812 06:19:03.176635 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushMRSOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.046s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":251,"dirs.run_wall_time_us":1265,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1622,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:03.177413 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling LogGCOp(51fe702f12ab4cc88fd6c712e3fb1b41): free 124710510 bytes of WAL
I20260812 06:19:03.177649 17854 log_reader.cc:385] T 51fe702f12ab4cc88fd6c712e3fb1b41: removed 12 log segments from log reader
I20260812 06:19:03.177695 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000028 (ops 132-136)
I20260812 06:19:03.177724 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000029 (ops 137-141)
I20260812 06:19:03.177799 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000030 (ops 142-146)
I20260812 06:19:03.177845 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000031 (ops 147-151)
I20260812 06:19:03.177889 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000032 (ops 152-156)
I20260812 06:19:03.177932 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000033 (ops 157-161)
I20260812 06:19:03.177966 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000034 (ops 162-166)
I20260812 06:19:03.178006 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000035 (ops 167-171)
I20260812 06:19:03.178046 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000036 (ops 172-176)
I20260812 06:19:03.178087 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000037 (ops 177-181)
I20260812 06:19:03.178126 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000038 (ops 182-186)
I20260812 06:19:03.178165 17854 log.cc:1079] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/51fe702f12ab4cc88fd6c712e3fb1b41/wal-000000039 (ops 187-191)
I20260812 06:19:03.206661 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: LogGCOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:03.207273 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=3.181125
I20260812 06:19:03.223794 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.016s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4389828,"delete_count":0,"lbm_write_time_us":4575,"lbm_writes_lt_1ms":110,"reinsert_count":0,"update_count":535}
I20260812 06:19:03.224294 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling UndoDeltaBlockGCOp(51fe702f12ab4cc88fd6c712e3fb1b41): 493 bytes on disk
I20260812 06:19:03.224730 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: UndoDeltaBlockGCOp(51fe702f12ab4cc88fd6c712e3fb1b41) 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:19:03.225344 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=2.188937
I20260812 06:19:03.236091 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: FlushDeltaMemStoresOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":3996,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:19:03.236797 17923 maintenance_manager.cc:419] P 70af1453b364416bad390ca9a80e7949: Scheduling MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41): perf score=1.000000
I20260812 06:19:03.323447 17733 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.021s	user 1.897s	sys 0.095s
I20260812 06:19:03.426641 17733 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.102s	user 0.001s	sys 0.000s
I20260812 06:19:03.427358 17733 tablet_server.cc:179] TabletServer@127.17.81.65:0 shutting down...
I20260812 06:19:03.454947 17854 maintenance_manager.cc:643] P 70af1453b364416bad390ca9a80e7949: MajorDeltaCompactionOp(51fe702f12ab4cc88fd6c712e3fb1b41) complete. Timing: real 0.218s	user 0.146s	sys 0.072s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979744,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":363,"lbm_read_time_us":16021,"lbm_reads_lt_1ms":770,"lbm_write_time_us":32728,"lbm_writes_lt_1ms":743,"mutex_wait_us":71,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":146560,"thread_start_us":94,"threads_started":1,"update_count":3500}
I20260812 06:19:03.456229 17733 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:03.456771 17733 tablet_replica.cc:333] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949: stopping tablet replica
I20260812 06:19:03.457077 17733 raft_consensus.cc:2243] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:03.457351 17733 raft_consensus.cc:2272] T 51fe702f12ab4cc88fd6c712e3fb1b41 P 70af1453b364416bad390ca9a80e7949 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:03.475700 17733 tablet_server.cc:196] TabletServer@127.17.81.65:0 shutdown complete.
I20260812 06:19:03.514976 17733 master.cc:562] Master@127.17.81.126:39365 shutting down...
I20260812 06:19:03.519722 17733 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:03.519985 17733 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:03.520073 17733 tablet_replica.cc:333] T 00000000000000000000000000000000 P 405e59dfb76641798ebfe939d1335033: stopping tablet replica
I20260812 06:19:03.532883 17733 master.cc:584] Master@127.17.81.126:39365 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5614 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:03.626035 17733 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.17.81.126:46037
I20260812 06:19:03.626410 17733 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:19:03.628908 17733 server_base.cc:1061] running on GCE node
W20260812 06:19:03.629004 17962 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:19:03.629004 17958 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:19:03.629101 17959 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:19:03.629590 17733 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:03.629637 17733 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:19:03.629652 17733 hybrid_clock.cc:648] HybridClock initialized: now 1786515543629653 us; error 0 us; skew 500 ppm
I20260812 06:19:03.630537 17733 webserver.cc:533] Webserver started at http://127.17.81.126:35953/ using document root <none> and password file <none>
I20260812 06:19:03.630714 17733 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:03.630770 17733 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:03.630865 17733 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:03.631265 17733 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/master-0-root/instance:
uuid: "0d90c310b64d4468976f72e9e741d2c9"
format_stamp: "Formatted at 2026-08-12 06:19:03 on dist-test-slave-27sr"
I20260812 06:19:03.633545 17733 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:03.634580 17967 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:19:03.634853 17733 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:03.634923 17733 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/master-0-root
uuid: "0d90c310b64d4468976f72e9e741d2c9"
format_stamp: "Formatted at 2026-08-12 06:19:03 on dist-test-slave-27sr"
I20260812 06:19:03.635020 17733 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-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:19:03.654453 17733 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:03.654932 17733 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:03.659585 17733 rpc_server.cc:307] RPC server started. Bound to: 127.17.81.126:46037
I20260812 06:19:03.661616 18028 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.81.126:46037 every 8 connection(s)
I20260812 06:19:03.662487 18031 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:19:03.671743 18031 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9: Bootstrap starting.
I20260812 06:19:03.672685 18031 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:03.673799 18031 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9: No bootstrap required, opened a new log
I20260812 06:19:03.674221 18031 raft_consensus.cc:359] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0d90c310b64d4468976f72e9e741d2c9" member_type: VOTER }
I20260812 06:19:03.674312 18031 raft_consensus.cc:385] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:03.674378 18031 raft_consensus.cc:740] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0d90c310b64d4468976f72e9e741d2c9, State: Initialized, Role: FOLLOWER
I20260812 06:19:03.674552 18031 consensus_queue.cc:260] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9 [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: "0d90c310b64d4468976f72e9e741d2c9" member_type: VOTER }
I20260812 06:19:03.674642 18031 raft_consensus.cc:399] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:03.674717 18031 raft_consensus.cc:493] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:03.674780 18031 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:03.675520 18031 raft_consensus.cc:515] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0d90c310b64d4468976f72e9e741d2c9" member_type: VOTER }
I20260812 06:19:03.675674 18031 leader_election.cc:304] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9 [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: 0d90c310b64d4468976f72e9e741d2c9; no voters: 
I20260812 06:19:03.675947 18031 leader_election.cc:290] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:03.676077 18034 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:03.676396 18034 raft_consensus.cc:697] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9 [term 1 LEADER]: Becoming Leader. State: Replica: 0d90c310b64d4468976f72e9e741d2c9, State: Running, Role: LEADER
I20260812 06:19:03.676489 18031 sys_catalog.cc:565] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:03.676558 18034 consensus_queue.cc:237] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9 [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: "0d90c310b64d4468976f72e9e741d2c9" member_type: VOTER }
I20260812 06:19:03.677064 18035 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "0d90c310b64d4468976f72e9e741d2c9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0d90c310b64d4468976f72e9e741d2c9" member_type: VOTER } }
I20260812 06:19:03.677093 18036 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 0d90c310b64d4468976f72e9e741d2c9. Latest consensus state: current_term: 1 leader_uuid: "0d90c310b64d4468976f72e9e741d2c9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0d90c310b64d4468976f72e9e741d2c9" member_type: VOTER } }
I20260812 06:19:03.677259 18036 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:03.677229 18035 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:03.677996 18041 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:03.678781 18041 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:03.678941 17733 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:03.680652 18041 catalog_manager.cc:1383] Generated new cluster ID: 2c01ab69747e4ddb900782f5bbb446d5
I20260812 06:19:03.680711 18041 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:03.688205 18041 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:03.688740 18041 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:03.693271 18041 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9: Generated new TSK 0
I20260812 06:19:03.693432 18041 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:03.695206 17733 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:03.697311 18057 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:19:03.697444 17733 server_base.cc:1061] running on GCE node
W20260812 06:19:03.697358 18054 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:19:03.697358 18055 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:19:03.697744 17733 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:03.697793 17733 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:19:03.697808 17733 hybrid_clock.cc:648] HybridClock initialized: now 1786515543697808 us; error 0 us; skew 500 ppm
I20260812 06:19:03.698596 17733 webserver.cc:533] Webserver started at http://127.17.81.65:36749/ using document root <none> and password file <none>
I20260812 06:19:03.698748 17733 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:03.698796 17733 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:03.698856 17733 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:03.699278 17733 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/instance:
uuid: "39a0c03e03664862bcb85e794ef5b52f"
format_stamp: "Formatted at 2026-08-12 06:19:03 on dist-test-slave-27sr"
I20260812 06:19:03.700820 17733 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:03.701809 18062 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:19:03.702113 17733 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:03.702203 17733 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root
uuid: "39a0c03e03664862bcb85e794ef5b52f"
format_stamp: "Formatted at 2026-08-12 06:19:03 on dist-test-slave-27sr"
I20260812 06:19:03.702260 17733 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-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:19:03.712425 17733 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:03.712848 17733 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:03.713137 17733 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:03.713646 17733 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:03.713685 17733 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:03.713759 17733 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:03.713798 17733 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:03.718238 17733 rpc_server.cc:307] RPC server started. Bound to: 127.17.81.65:44509
I20260812 06:19:03.718304 18147 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.81.65:44509 every 8 connection(s)
I20260812 06:19:03.728470 18148 heartbeater.cc:344] Connected to a master server at 127.17.81.126:46037
I20260812 06:19:03.728618 18148 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:03.728894 18148 heartbeater.cc:507] Master 127.17.81.126:46037 requested a full tablet report, sending...
I20260812 06:19:03.729655 17987 ts_manager.cc:194] Registered new tserver with Master: 39a0c03e03664862bcb85e794ef5b52f (127.17.81.65:44509)
I20260812 06:19:03.729909 17733 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011135795s
I20260812 06:19:03.730516 17987 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:57662
I20260812 06:19:03.738374 17987 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:57668:
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:19:03.747642 18099 tablet_service.cc:1511] Processing CreateTablet for tablet beb1a0d5445e41bda4c50ca6e0451e9c (DEFAULT_TABLE table=heavy-update-compaction-test [id=8d2f8a1172c141f19d9b90e72c2beb3f]), partition=
I20260812 06:19:03.747995 18099 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet beb1a0d5445e41bda4c50ca6e0451e9c. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:03.749943 18162 tablet_bootstrap.cc:492] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Bootstrap starting.
I20260812 06:19:03.750895 18162 tablet_bootstrap.cc:654] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:03.752143 18162 tablet_bootstrap.cc:492] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: No bootstrap required, opened a new log
I20260812 06:19:03.752244 18162 ts_tablet_manager.cc:1403] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:03.752718 18162 raft_consensus.cc:359] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "39a0c03e03664862bcb85e794ef5b52f" member_type: VOTER last_known_addr { host: "127.17.81.65" port: 44509 } }
I20260812 06:19:03.752839 18162 raft_consensus.cc:385] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:03.752918 18162 raft_consensus.cc:740] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 39a0c03e03664862bcb85e794ef5b52f, State: Initialized, Role: FOLLOWER
I20260812 06:19:03.753070 18162 consensus_queue.cc:260] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f [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: "39a0c03e03664862bcb85e794ef5b52f" member_type: VOTER last_known_addr { host: "127.17.81.65" port: 44509 } }
I20260812 06:19:03.753190 18162 raft_consensus.cc:399] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:03.753247 18162 raft_consensus.cc:493] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:03.753290 18162 raft_consensus.cc:3060] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:03.754057 18162 raft_consensus.cc:515] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "39a0c03e03664862bcb85e794ef5b52f" member_type: VOTER last_known_addr { host: "127.17.81.65" port: 44509 } }
I20260812 06:19:03.754215 18162 leader_election.cc:304] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f [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: 39a0c03e03664862bcb85e794ef5b52f; no voters: 
I20260812 06:19:03.754480 18162 leader_election.cc:290] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:03.754626 18164 raft_consensus.cc:2804] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:03.754915 18162 ts_tablet_manager.cc:1434] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:03.754940 18164 raft_consensus.cc:697] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f [term 1 LEADER]: Becoming Leader. State: Replica: 39a0c03e03664862bcb85e794ef5b52f, State: Running, Role: LEADER
I20260812 06:19:03.754952 18148 heartbeater.cc:499] Master 127.17.81.126:46037 was elected leader, sending a full tablet report...
I20260812 06:19:03.755170 18164 consensus_queue.cc:237] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f [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: "39a0c03e03664862bcb85e794ef5b52f" member_type: VOTER last_known_addr { host: "127.17.81.65" port: 44509 } }
I20260812 06:19:03.756459 17987 catalog_manager.cc:5719] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f reported cstate change: term changed from 0 to 1, leader changed from <none> to 39a0c03e03664862bcb85e794ef5b52f (127.17.81.65). New cstate: current_term: 1 leader_uuid: "39a0c03e03664862bcb85e794ef5b52f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "39a0c03e03664862bcb85e794ef5b52f" member_type: VOTER last_known_addr { host: "127.17.81.65" port: 44509 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:03.819984 17733 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.022s	sys 0.004s
I20260812 06:19:03.969288 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushMRSOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=19.054940
I20260812 06:19:04.125432 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushMRSOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.156s	user 0.105s	sys 0.048s Metrics: {"bytes_written":12307489,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":87,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":750,"drs_written":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41508,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:19:04.126060 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling LogGCOp(beb1a0d5445e41bda4c50ca6e0451e9c): free 20290830 bytes of WAL
I20260812 06:19:04.126313 18069 log_reader.cc:385] T beb1a0d5445e41bda4c50ca6e0451e9c: removed 2 log segments from log reader
I20260812 06:19:04.126361 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000001 (ops 1-6)
I20260812 06:19:04.126391 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000002 (ops 7-10)
I20260812 06:19:04.130483 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: LogGCOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:04.130836 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling UndoDeltaBlockGCOp(beb1a0d5445e41bda4c50ca6e0451e9c): 16411396 bytes on disk
I20260812 06:19:04.131273 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: UndoDeltaBlockGCOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:19:04.131786 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=2.188937
I20260812 06:19:04.147976 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.016s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5970,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.148468 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=1.000000
I20260812 06:19:04.306061 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.157s	user 0.108s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":550,"lbm_read_time_us":9783,"lbm_reads_lt_1ms":460,"lbm_write_time_us":26961,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":315,"threads_started":5,"update_count":2000}
I20260812 06:19:04.306651 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=14.095187
I20260812 06:19:04.363866 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.057s	user 0.024s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19509,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:04.364456 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=2.188937
I20260812 06:19:04.376806 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4499,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.377440 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=1.000000
I20260812 06:19:04.561946 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.184s	user 0.144s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":584,"lbm_read_time_us":12785,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31516,"lbm_writes_lt_1ms":543,"mutex_wait_us":130,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2500}
I20260812 06:19:04.562579 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=14.095187
I20260812 06:19:04.627532 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.065s	user 0.011s	sys 0.035s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21781,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:04.628077 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=2.188937
I20260812 06:19:04.640553 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4256,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.641261 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=1.000000
I20260812 06:19:04.828217 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.187s	user 0.117s	sys 0.068s 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":816,"lbm_read_time_us":13818,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32376,"lbm_writes_lt_1ms":543,"mutex_wait_us":372,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":32640,"update_count":2500}
I20260812 06:19:04.828893 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=14.095187
I20260812 06:19:04.891041 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.062s	user 0.016s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19263,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:04.891670 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=2.188937
I20260812 06:19:04.903447 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4613,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.904166 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=1.000000
I20260812 06:19:05.086169 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.182s	user 0.122s	sys 0.059s 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":252,"lbm_read_time_us":13820,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31747,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2500}
I20260812 06:19:05.086817 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=11.118625
I20260812 06:19:05.134721 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.048s	user 0.024s	sys 0.018s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":19926,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:19:05.135341 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=2.188937
I20260812 06:19:05.171144 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.036s	user 0.015s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":7654,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:05.171698 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=2.188937
I20260812 06:19:05.188421 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.016s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6539,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:05.189137 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=1.000000
I20260812 06:19:05.378988 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.190s	user 0.139s	sys 0.049s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1329,"lbm_read_time_us":14114,"lbm_reads_lt_1ms":573,"lbm_write_time_us":34254,"lbm_writes_lt_1ms":543,"mutex_wait_us":339,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2500}
I20260812 06:19:05.379703 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=14.095187
I20260812 06:19:05.445394 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.065s	user 0.031s	sys 0.033s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24297,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:05.446017 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=2.188937
I20260812 06:19:05.457443 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4395,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:05.458014 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushMRSOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=1.000000
I20260812 06:19:05.489195 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushMRSOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.031s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":296,"dirs.run_wall_time_us":1392,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1436,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:05.489835 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling UndoDeltaBlockGCOp(beb1a0d5445e41bda4c50ca6e0451e9c): 462 bytes on disk
I20260812 06:19:05.490262 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: UndoDeltaBlockGCOp(beb1a0d5445e41bda4c50ca6e0451e9c) 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:19:05.490728 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=1.000000
I20260812 06:19:05.696997 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.206s	user 0.130s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":975,"lbm_read_time_us":11875,"lbm_reads_lt_1ms":564,"lbm_write_time_us":34669,"lbm_writes_lt_1ms":543,"mutex_wait_us":386,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:19:05.697695 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling LogGCOp(beb1a0d5445e41bda4c50ca6e0451e9c): free 120553374 bytes of WAL
I20260812 06:19:05.697960 18069 log_reader.cc:385] T beb1a0d5445e41bda4c50ca6e0451e9c: removed 12 log segments from log reader
I20260812 06:19:05.698032 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000003 (ops 11-15)
I20260812 06:19:05.698103 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000004 (ops 16-20)
I20260812 06:19:05.698148 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000005 (ops 21-24)
I20260812 06:19:05.698225 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000006 (ops 25-29)
I20260812 06:19:05.698276 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000007 (ops 30-34)
I20260812 06:19:05.698349 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000008 (ops 35-39)
I20260812 06:19:05.698396 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000009 (ops 40-44)
I20260812 06:19:05.698446 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000010 (ops 45-48)
I20260812 06:19:05.698501 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000011 (ops 49-53)
I20260812 06:19:05.698549 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000012 (ops 54-58)
I20260812 06:19:05.698596 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000013 (ops 59-63)
I20260812 06:19:05.698668 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000014 (ops 64-68)
I20260812 06:19:05.729261 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: LogGCOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.031s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:05.729817 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=15.087375
I20260812 06:19:05.776495 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.046s	user 0.035s	sys 0.008s Metrics: {"bytes_written":16820121,"delete_count":0,"lbm_write_time_us":19637,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:05.776928 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=2.188937
I20260812 06:19:05.798115 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.021s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3939,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:05.798712 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=2.188937
I20260812 06:19:05.809446 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4052,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:05.809918 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=1.000000
I20260812 06:19:06.021749 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.212s	user 0.121s	sys 0.090s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877185,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":287,"lbm_read_time_us":16081,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36441,"lbm_writes_lt_1ms":643,"mutex_wait_us":54,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":103296,"update_count":3000}
I20260812 06:19:06.022920 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=14.095187
I20260812 06:19:06.087446 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.064s	user 0.019s	sys 0.042s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22820,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:06.088227 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=2.188937
I20260812 06:19:06.099340 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4325,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.099824 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=1.000000
I20260812 06:19:06.293807 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.194s	user 0.153s	sys 0.029s 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":205,"lbm_read_time_us":12921,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30820,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:19:06.294533 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=14.095187
I20260812 06:19:06.370163 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.075s	user 0.034s	sys 0.039s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28654,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:06.370963 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=2.188937
I20260812 06:19:06.391069 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.020s	user 0.010s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7423,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.391727 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=1.000000
I20260812 06:19:06.585882 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.194s	user 0.122s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":692,"lbm_read_time_us":16160,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29331,"lbm_writes_lt_1ms":543,"mutex_wait_us":300,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:19:06.586505 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=14.095187
I20260812 06:19:06.638948 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.052s	user 0.028s	sys 0.012s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19341,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:06.639518 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=2.188937
I20260812 06:19:06.651669 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4404,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.652240 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=1.000000
I20260812 06:19:06.837426 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.185s	user 0.127s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":296,"lbm_read_time_us":12232,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27714,"lbm_writes_lt_1ms":543,"mutex_wait_us":116,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:06.838047 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=14.095187
I20260812 06:19:06.893051 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.055s	user 0.030s	sys 0.015s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":21118,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:06.893608 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=2.188937
I20260812 06:19:06.905179 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4265,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.905776 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=1.000000
I20260812 06:19:07.066788 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.161s	user 0.118s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":263,"lbm_read_time_us":12446,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29696,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20352,"update_count":2500}
I20260812 06:19:07.067617 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=11.118625
I20260812 06:19:07.101781 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.034s	user 0.029s	sys 0.003s Metrics: {"bytes_written":12717740,"delete_count":0,"lbm_write_time_us":14680,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:07.102524 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=2.188937
I20260812 06:19:07.128705 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.026s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4856,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:07.129202 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=2.188937
I20260812 06:19:07.140828 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4461,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.141659 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushMRSOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=1.000000
I20260812 06:19:07.171504 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushMRSOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":258,"dirs.run_wall_time_us":1661,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1539,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31,"spinlock_wait_cycles":7552}
I20260812 06:19:07.172318 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling LogGCOp(beb1a0d5445e41bda4c50ca6e0451e9c): free 121006432 bytes of WAL
I20260812 06:19:07.172606 18069 log_reader.cc:385] T beb1a0d5445e41bda4c50ca6e0451e9c: removed 12 log segments from log reader
I20260812 06:19:07.172676 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000015 (ops 69-73)
I20260812 06:19:07.172715 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000016 (ops 74-78)
I20260812 06:19:07.172748 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000017 (ops 79-83)
I20260812 06:19:07.172785 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000018 (ops 84-88)
I20260812 06:19:07.172809 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000019 (ops 89-93)
I20260812 06:19:07.172832 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000020 (ops 94-98)
I20260812 06:19:07.172861 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000021 (ops 99-103)
I20260812 06:19:07.172887 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000022 (ops 104-108)
I20260812 06:19:07.172919 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000023 (ops 109-112)
I20260812 06:19:07.172955 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000024 (ops 113-117)
I20260812 06:19:07.172984 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000025 (ops 118-122)
I20260812 06:19:07.173012 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000026 (ops 123-127)
I20260812 06:19:07.204236 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: LogGCOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.032s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:19:07.204747 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling UndoDeltaBlockGCOp(beb1a0d5445e41bda4c50ca6e0451e9c): 483 bytes on disk
I20260812 06:19:07.205193 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: UndoDeltaBlockGCOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:19:07.205844 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=3.181125
I20260812 06:19:07.240511 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.035s	user 0.011s	sys 0.016s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6371,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:07.241144 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling LogGCOp(beb1a0d5445e41bda4c50ca6e0451e9c): free 12017949 bytes of WAL
I20260812 06:19:07.241427 18069 log_reader.cc:385] T beb1a0d5445e41bda4c50ca6e0451e9c: removed 1 log segments from log reader
I20260812 06:19:07.241477 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000027 (ops 128-132)
I20260812 06:19:07.244076 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: LogGCOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.003s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:07.244441 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=2.188937
I20260812 06:19:07.254734 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3874,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:07.255280 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=1.000000
I20260812 06:19:07.505751 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.250s	user 0.162s	sys 0.086s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979852,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":218,"lbm_read_time_us":18504,"lbm_reads_lt_1ms":775,"lbm_write_time_us":40865,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":8576,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:19:07.506850 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=15.087375
I20260812 06:19:07.560627 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.054s	user 0.024s	sys 0.028s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":23442,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:07.561344 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=2.188937
I20260812 06:19:07.579754 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.018s	user 0.001s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6014,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:07.580324 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=1.000000
I20260812 06:19:07.790901 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.210s	user 0.136s	sys 0.062s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774675,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1384,"lbm_read_time_us":12785,"lbm_reads_lt_1ms":564,"lbm_write_time_us":35319,"lbm_writes_lt_1ms":543,"mutex_wait_us":415,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:19:07.791697 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=18.063937
I20260812 06:19:07.859987 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.068s	user 0.031s	sys 0.023s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":26700,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:07.860622 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=2.188937
I20260812 06:19:07.871567 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4224,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.872123 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=1.000000
I20260812 06:19:08.076187 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.204s	user 0.128s	sys 0.076s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":124,"lbm_read_time_us":15552,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31785,"lbm_writes_lt_1ms":643,"mutex_wait_us":32,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":22656,"update_count":3000}
I20260812 06:19:08.077023 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=14.095187
I20260812 06:19:08.130038 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.053s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21780,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:08.130739 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=2.188937
I20260812 06:19:08.144280 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.013s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5065,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.144805 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=1.000000
I20260812 06:19:08.333175 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.188s	user 0.128s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":623,"lbm_read_time_us":14466,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30103,"lbm_writes_lt_1ms":543,"mutex_wait_us":92,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18944,"update_count":2500}
I20260812 06:19:08.333706 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=14.095187
I20260812 06:19:08.393873 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.060s	user 0.028s	sys 0.023s Metrics: {"bytes_written":16409907,"delete_count":0,"lbm_write_time_us":24542,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:08.394587 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=2.188937
I20260812 06:19:08.412213 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.017s	user 0.017s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6600,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.414065 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=1.000000
I20260812 06:19:08.596382 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.182s	user 0.130s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1292,"lbm_read_time_us":12689,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32101,"lbm_writes_lt_1ms":543,"mutex_wait_us":373,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2500}
I20260812 06:19:08.597093 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=14.095187
I20260812 06:19:08.665751 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.068s	user 0.039s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24677,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:08.666333 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=2.188937
I20260812 06:19:08.677706 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4232,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.678172 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushMRSOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=1.000000
I20260812 06:19:08.721689 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushMRSOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.043s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":93,"dirs.run_cpu_time_us":261,"dirs.run_wall_time_us":1394,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1487,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:08.722586 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling LogGCOp(beb1a0d5445e41bda4c50ca6e0451e9c): free 108988745 bytes of WAL
I20260812 06:19:08.722852 18069 log_reader.cc:385] T beb1a0d5445e41bda4c50ca6e0451e9c: removed 11 log segments from log reader
I20260812 06:19:08.722945 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000028 (ops 133-137)
I20260812 06:19:08.723001 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000029 (ops 138-142)
I20260812 06:19:08.723058 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000030 (ops 143-146)
I20260812 06:19:08.723102 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000031 (ops 147-151)
I20260812 06:19:08.723142 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000032 (ops 152-156)
I20260812 06:19:08.723181 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000033 (ops 157-161)
I20260812 06:19:08.723220 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000034 (ops 162-166)
I20260812 06:19:08.723259 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000035 (ops 167-171)
I20260812 06:19:08.723299 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000036 (ops 172-176)
I20260812 06:19:08.723337 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000037 (ops 177-181)
I20260812 06:19:08.723376 18069 log.cc:1079] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: Deleting log segment in path: /tmp/dist-test-taskCC1QQr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515538000706-17733-0/minicluster-data/ts-0-root/wals/beb1a0d5445e41bda4c50ca6e0451e9c/wal-000000038 (ops 182-186)
I20260812 06:19:08.747344 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: LogGCOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.025s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:19:08.747855 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=2.188937
I20260812 06:19:08.765478 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.016s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4296,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.765939 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling UndoDeltaBlockGCOp(beb1a0d5445e41bda4c50ca6e0451e9c): 447 bytes on disk
I20260812 06:19:08.766852 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: UndoDeltaBlockGCOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:19:08.767449 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=2.188937
I20260812 06:19:08.778499 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.011s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4215,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.779166 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=1.000000
I20260812 06:19:09.035463 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.256s	user 0.191s	sys 0.052s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979751,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":807,"lbm_read_time_us":15754,"lbm_reads_lt_1ms":774,"lbm_write_time_us":46908,"lbm_writes_lt_1ms":743,"mutex_wait_us":84,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":19712,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:19:09.036258 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=18.063937
I20260812 06:19:09.099591 17733 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.280s	user 1.941s	sys 0.213s
I20260812 06:19:09.103857 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.067s	user 0.032s	sys 0.024s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":27123,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:09.104489 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=2.188937
I20260812 06:19:09.122071 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: FlushDeltaMemStoresOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.017s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7424,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":500}
I20260812 06:19:09.122623 18149 maintenance_manager.cc:419] P 39a0c03e03664862bcb85e794ef5b52f: Scheduling MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c): perf score=1.000000
I20260812 06:19:09.163731 17733 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.064s	user 0.000s	sys 0.000s
I20260812 06:19:09.164335 17733 tablet_server.cc:179] TabletServer@127.17.81.65:0 shutting down...
I20260812 06:19:09.270153 18069 maintenance_manager.cc:643] P 39a0c03e03664862bcb85e794ef5b52f: MajorDeltaCompactionOp(beb1a0d5445e41bda4c50ca6e0451e9c) complete. Timing: real 0.147s	user 0.106s	sys 0.039s Metrics: {"cfile_cache_hit":419,"cfile_cache_hit_bytes":17149282,"cfile_cache_miss":213,"cfile_cache_miss_bytes":11727823,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":558,"lbm_read_time_us":5072,"lbm_reads_lt_1ms":245,"lbm_write_time_us":29627,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":3000}
I20260812 06:19:09.271440 17733 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:09.271670 17733 tablet_replica.cc:333] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f: stopping tablet replica
I20260812 06:19:09.271885 17733 raft_consensus.cc:2243] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:09.272140 17733 raft_consensus.cc:2272] T beb1a0d5445e41bda4c50ca6e0451e9c P 39a0c03e03664862bcb85e794ef5b52f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:09.276383 17733 tablet_server.cc:196] TabletServer@127.17.81.65:0 shutdown complete.
I20260812 06:19:09.323417 17733 master.cc:562] Master@127.17.81.126:46037 shutting down...
I20260812 06:19:09.329064 17733 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:09.329324 17733 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:09.329429 17733 tablet_replica.cc:333] T 00000000000000000000000000000000 P 0d90c310b64d4468976f72e9e741d2c9: stopping tablet replica
I20260812 06:19:09.342538 17733 master.cc:584] Master@127.17.81.126:46037 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5812 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11427 ms total)

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