[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:16:49.714335 14409 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.14.18.126:37067
I20260812 06:16:49.715389 14409 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:16:49.716037 14409 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:49.722605 14419 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:49.722605 14417 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:49.722797 14416 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:49.722863 14409 server_base.cc:1061] running on GCE node
I20260812 06:16:49.723364 14409 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:49.723472 14409 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:49.723517 14409 hybrid_clock.cc:648] HybridClock initialized: now 1786515409723514 us; error 0 us; skew 500 ppm
I20260812 06:16:49.725375 14409 webserver.cc:533] Webserver started at http://127.14.18.126:38399/ using document root <none> and password file <none>
I20260812 06:16:49.725939 14409 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:49.726006 14409 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:49.726246 14409 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:49.727982 14409 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/master-0-root/instance:
uuid: "ca4e79635f104fff9a980d3cbf02e779"
format_stamp: "Formatted at 2026-08-12 06:16:49 on dist-test-slave-1l3l"
I20260812 06:16:49.731452 14409 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:49.733522 14425 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:49.734510 14409 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:16:49.734632 14409 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/master-0-root
uuid: "ca4e79635f104fff9a980d3cbf02e779"
format_stamp: "Formatted at 2026-08-12 06:16:49 on dist-test-slave-1l3l"
I20260812 06:16:49.734724 14409 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:49.747002 14409 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:49.747684 14409 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:16:49.747897 14409 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:49.755769 14409 rpc_server.cc:307] RPC server started. Bound to: 127.14.18.126:37067
I20260812 06:16:49.755774 14525 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.18.126:37067 every 8 connection(s)
I20260812 06:16:49.758178 14527 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:49.763929 14527 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779: Bootstrap starting.
I20260812 06:16:49.766368 14527 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:49.767295 14527 log.cc:826] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:49.769073 14527 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779: No bootstrap required, opened a new log
I20260812 06:16:49.771919 14527 raft_consensus.cc:359] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ca4e79635f104fff9a980d3cbf02e779" member_type: VOTER }
I20260812 06:16:49.772095 14527 raft_consensus.cc:385] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:49.772137 14527 raft_consensus.cc:740] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ca4e79635f104fff9a980d3cbf02e779, State: Initialized, Role: FOLLOWER
I20260812 06:16:49.772773 14527 consensus_queue.cc:260] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779 [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: "ca4e79635f104fff9a980d3cbf02e779" member_type: VOTER }
I20260812 06:16:49.772927 14527 raft_consensus.cc:399] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:49.772979 14527 raft_consensus.cc:493] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:49.773075 14527 raft_consensus.cc:3060] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:49.773871 14527 raft_consensus.cc:515] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ca4e79635f104fff9a980d3cbf02e779" member_type: VOTER }
I20260812 06:16:49.774286 14527 leader_election.cc:304] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779 [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: ca4e79635f104fff9a980d3cbf02e779; no voters: 
I20260812 06:16:49.774605 14527 leader_election.cc:290] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:49.774763 14533 raft_consensus.cc:2804] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:49.774982 14533 raft_consensus.cc:697] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779 [term 1 LEADER]: Becoming Leader. State: Replica: ca4e79635f104fff9a980d3cbf02e779, State: Running, Role: LEADER
I20260812 06:16:49.775426 14533 consensus_queue.cc:237] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779 [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: "ca4e79635f104fff9a980d3cbf02e779" member_type: VOTER }
I20260812 06:16:49.775662 14527 sys_catalog.cc:565] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:49.777457 14534 sys_catalog.cc:455] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "ca4e79635f104fff9a980d3cbf02e779" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ca4e79635f104fff9a980d3cbf02e779" member_type: VOTER } }
I20260812 06:16:49.777618 14534 sys_catalog.cc:458] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:49.777894 14536 sys_catalog.cc:455] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779 [sys.catalog]: SysCatalogTable state changed. Reason: New leader ca4e79635f104fff9a980d3cbf02e779. Latest consensus state: current_term: 1 leader_uuid: "ca4e79635f104fff9a980d3cbf02e779" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ca4e79635f104fff9a980d3cbf02e779" member_type: VOTER } }
I20260812 06:16:49.777992 14536 sys_catalog.cc:458] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:49.777993 14409 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:16:49.780112 14555 catalog_manager.cc:1594] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:16:49.780184 14555 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:16:49.780242 14552 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:49.781028 14552 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:49.786378 14552 catalog_manager.cc:1383] Generated new cluster ID: 652b06fed73c491caf71ef2ffbdca9c1
I20260812 06:16:49.786446 14552 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:49.807757 14552 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:49.808714 14552 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:49.817842 14552 catalog_manager.cc:6092] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779: Generated new TSK 0
I20260812 06:16:49.818574 14552 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:49.843030 14409 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:49.846262 14563 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:49.846303 14560 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:49.846524 14561 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:49.846565 14409 server_base.cc:1061] running on GCE node
I20260812 06:16:49.846810 14409 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:49.846854 14409 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:49.846875 14409 hybrid_clock.cc:648] HybridClock initialized: now 1786515409846874 us; error 0 us; skew 500 ppm
I20260812 06:16:49.847888 14409 webserver.cc:533] Webserver started at http://127.14.18.65:37021/ using document root <none> and password file <none>
I20260812 06:16:49.848066 14409 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:49.848124 14409 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:49.848223 14409 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:49.848632 14409 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/instance:
uuid: "d1f10cb9a0044b73bdb0b3d83d006474"
format_stamp: "Formatted at 2026-08-12 06:16:49 on dist-test-slave-1l3l"
I20260812 06:16:49.850167 14409 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:49.851167 14568 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:49.851397 14409 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:49.851469 14409 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root
uuid: "d1f10cb9a0044b73bdb0b3d83d006474"
format_stamp: "Formatted at 2026-08-12 06:16:49 on dist-test-slave-1l3l"
I20260812 06:16:49.851552 14409 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:49.892171 14409 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:49.892668 14409 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:49.893142 14409 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:49.894063 14409 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:49.894120 14409 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:49.894167 14409 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:49.894197 14409 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:49.900300 14409 rpc_server.cc:307] RPC server started. Bound to: 127.14.18.65:42701
I20260812 06:16:49.900328 14678 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.18.65:42701 every 8 connection(s)
I20260812 06:16:49.910609 14680 heartbeater.cc:344] Connected to a master server at 127.14.18.126:37067
I20260812 06:16:49.910861 14680 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:49.911324 14680 heartbeater.cc:507] Master 127.14.18.126:37067 requested a full tablet report, sending...
I20260812 06:16:49.912810 14447 ts_manager.cc:194] Registered new tserver with Master: d1f10cb9a0044b73bdb0b3d83d006474 (127.14.18.65:42701)
I20260812 06:16:49.913259 14409 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012338737s
I20260812 06:16:49.914038 14447 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:54892
I20260812 06:16:49.923969 14447 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:54902:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:16:49.938025 14616 tablet_service.cc:1511] Processing CreateTablet for tablet 11af133f17854b40be08b70673f1ea53 (DEFAULT_TABLE table=heavy-update-compaction-test [id=4e52d24f4e714d1b810ba7b7d92eebb7]), partition=
I20260812 06:16:49.938517 14616 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 11af133f17854b40be08b70673f1ea53. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:49.940824 14699 tablet_bootstrap.cc:492] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Bootstrap starting.
I20260812 06:16:49.941900 14699 tablet_bootstrap.cc:654] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:49.942903 14699 tablet_bootstrap.cc:492] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: No bootstrap required, opened a new log
I20260812 06:16:49.943010 14699 ts_tablet_manager.cc:1403] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:16:49.943413 14699 raft_consensus.cc:359] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d1f10cb9a0044b73bdb0b3d83d006474" member_type: VOTER last_known_addr { host: "127.14.18.65" port: 42701 } }
I20260812 06:16:49.943521 14699 raft_consensus.cc:385] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:49.943553 14699 raft_consensus.cc:740] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d1f10cb9a0044b73bdb0b3d83d006474, State: Initialized, Role: FOLLOWER
I20260812 06:16:49.943692 14699 consensus_queue.cc:260] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474 [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: "d1f10cb9a0044b73bdb0b3d83d006474" member_type: VOTER last_known_addr { host: "127.14.18.65" port: 42701 } }
I20260812 06:16:49.943815 14699 raft_consensus.cc:399] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:49.943861 14699 raft_consensus.cc:493] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:49.943909 14699 raft_consensus.cc:3060] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:49.944602 14699 raft_consensus.cc:515] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d1f10cb9a0044b73bdb0b3d83d006474" member_type: VOTER last_known_addr { host: "127.14.18.65" port: 42701 } }
I20260812 06:16:49.944738 14699 leader_election.cc:304] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474 [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: d1f10cb9a0044b73bdb0b3d83d006474; no voters: 
I20260812 06:16:49.944957 14699 leader_election.cc:290] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:49.945348 14699 ts_tablet_manager.cc:1434] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:16:49.945542 14680 heartbeater.cc:499] Master 127.14.18.126:37067 was elected leader, sending a full tablet report...
I20260812 06:16:49.945573 14703 raft_consensus.cc:2804] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:49.945674 14703 raft_consensus.cc:697] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474 [term 1 LEADER]: Becoming Leader. State: Replica: d1f10cb9a0044b73bdb0b3d83d006474, State: Running, Role: LEADER
I20260812 06:16:49.945796 14703 consensus_queue.cc:237] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474 [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: "d1f10cb9a0044b73bdb0b3d83d006474" member_type: VOTER last_known_addr { host: "127.14.18.65" port: 42701 } }
I20260812 06:16:49.948695 14447 catalog_manager.cc:5719] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474 reported cstate change: term changed from 0 to 1, leader changed from <none> to d1f10cb9a0044b73bdb0b3d83d006474 (127.14.18.65). New cstate: current_term: 1 leader_uuid: "d1f10cb9a0044b73bdb0b3d83d006474" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d1f10cb9a0044b73bdb0b3d83d006474" member_type: VOTER last_known_addr { host: "127.14.18.65" port: 42701 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:50.012754 14409 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.019s	sys 0.004s
I20260812 06:16:50.151510 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushMRSOp(11af133f17854b40be08b70673f1ea53): perf score=19.054940
I20260812 06:16:50.311026 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushMRSOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.159s	user 0.117s	sys 0.036s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":206,"delete_count":0,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":954,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41788,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":132,"threads_started":1,"update_count":1500}
I20260812 06:16:50.312057 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53): perf score=1.000000
I20260812 06:16:50.424803 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.113s	user 0.092s	sys 0.016s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":529,"lbm_read_time_us":6443,"lbm_reads_lt_1ms":363,"lbm_write_time_us":19496,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":3456,"thread_start_us":282,"threads_started":5,"update_count":1500}
I20260812 06:16:50.425320 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling LogGCOp(11af133f17854b40be08b70673f1ea53): free 20743880 bytes of WAL
I20260812 06:16:50.425594 14573 log_reader.cc:385] T 11af133f17854b40be08b70673f1ea53: removed 2 log segments from log reader
I20260812 06:16:50.425663 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000001 (ops 1-6)
I20260812 06:16:50.425717 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000002 (ops 7-11)
I20260812 06:16:50.430428 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: LogGCOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:16:50.430801 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=10.126437
I20260812 06:16:50.471413 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.040s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15116,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:50.471961 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling UndoDeltaBlockGCOp(11af133f17854b40be08b70673f1ea53): 16411395 bytes on disk
I20260812 06:16:50.472427 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: UndoDeltaBlockGCOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:16:50.472832 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=2.188937
I20260812 06:16:50.484133 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.011s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3813,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.484592 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53): perf score=1.000000
I20260812 06:16:50.603875 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.119s	user 0.103s	sys 0.015s 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":718,"lbm_read_time_us":7582,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21172,"lbm_writes_lt_1ms":443,"mutex_wait_us":68,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14592,"update_count":2000}
I20260812 06:16:50.604418 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=10.126437
I20260812 06:16:50.633879 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.029s	user 0.015s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12309,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:50.634482 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53): perf score=1.000000
I20260812 06:16:50.771346 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.137s	user 0.077s	sys 0.053s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":135,"lbm_read_time_us":9519,"lbm_reads_lt_1ms":363,"lbm_write_time_us":19593,"lbm_writes_lt_1ms":343,"mutex_wait_us":31,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":54272,"update_count":1500}
I20260812 06:16:50.771883 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=10.126437
I20260812 06:16:50.814216 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.042s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13986,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:50.814765 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=2.188937
I20260812 06:16:50.825387 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3856,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.826014 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53): perf score=1.000000
I20260812 06:16:50.952749 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.127s	user 0.091s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":163,"lbm_read_time_us":8264,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23807,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2000}
I20260812 06:16:50.953233 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=10.126437
I20260812 06:16:50.990965 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.038s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13816,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:50.991568 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=2.188937
I20260812 06:16:51.001976 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3812,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:51.002606 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53): perf score=1.000000
I20260812 06:16:51.126813 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.124s	user 0.084s	sys 0.040s 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":297,"lbm_read_time_us":8296,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24239,"lbm_writes_lt_1ms":443,"mutex_wait_us":58,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2000}
I20260812 06:16:51.127322 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=10.126437
I20260812 06:16:51.174207 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.047s	user 0.011s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12713,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":1500}
I20260812 06:16:51.174937 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=2.188937
I20260812 06:16:51.186305 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4134,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:51.186787 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53): perf score=1.000000
I20260812 06:16:51.333846 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.147s	user 0.103s	sys 0.040s 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":1011,"lbm_read_time_us":10077,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24868,"lbm_writes_lt_1ms":443,"mutex_wait_us":336,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2000}
I20260812 06:16:51.334437 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=10.126437
I20260812 06:16:51.381760 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.047s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15248,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:51.382257 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=2.188937
I20260812 06:16:51.393246 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3968,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:51.393958 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53): perf score=1.000000
I20260812 06:16:51.516763 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.123s	user 0.103s	sys 0.019s 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":1025,"lbm_read_time_us":8130,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25513,"lbm_writes_lt_1ms":443,"mutex_wait_us":316,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":23296,"update_count":2000}
I20260812 06:16:51.517261 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=10.126437
I20260812 06:16:51.562892 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.045s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16597,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:51.563508 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=2.188937
I20260812 06:16:51.574880 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3966,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:51.575519 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushMRSOp(11af133f17854b40be08b70673f1ea53): perf score=1.000000
I20260812 06:16:51.601363 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushMRSOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.026s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":46,"dirs.run_cpu_time_us":279,"dirs.run_wall_time_us":1410,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1460,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:16:51.602250 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling LogGCOp(11af133f17854b40be08b70673f1ea53): free 124710294 bytes of WAL
I20260812 06:16:51.602458 14573 log_reader.cc:385] T 11af133f17854b40be08b70673f1ea53: removed 12 log segments from log reader
I20260812 06:16:51.602497 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000003 (ops 12-16)
I20260812 06:16:51.602537 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000004 (ops 17-21)
I20260812 06:16:51.602568 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000005 (ops 22-26)
I20260812 06:16:51.602600 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000006 (ops 27-31)
I20260812 06:16:51.602632 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000007 (ops 32-36)
I20260812 06:16:51.602663 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000008 (ops 37-41)
I20260812 06:16:51.602694 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000009 (ops 42-46)
I20260812 06:16:51.602725 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000010 (ops 47-51)
I20260812 06:16:51.602754 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000011 (ops 52-56)
I20260812 06:16:51.602785 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000012 (ops 57-61)
I20260812 06:16:51.602815 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000013 (ops 62-66)
I20260812 06:16:51.602846 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000014 (ops 67-71)
I20260812 06:16:51.626394 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: LogGCOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.024s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:16:51.626888 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling UndoDeltaBlockGCOp(11af133f17854b40be08b70673f1ea53): 472 bytes on disk
I20260812 06:16:51.627367 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: UndoDeltaBlockGCOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:16:51.627990 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=3.181125
I20260812 06:16:51.646272 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.018s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6849,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:51.646839 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=2.188937
I20260812 06:16:51.661130 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.014s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4973,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:51.661753 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53): perf score=1.000000
I20260812 06:16:51.840245 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.178s	user 0.127s	sys 0.044s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":98,"lbm_read_time_us":13305,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33253,"lbm_writes_lt_1ms":643,"mutex_wait_us":40,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:16:51.841233 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=14.095187
I20260812 06:16:51.885984 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.044s	user 0.026s	sys 0.012s Metrics: {"bytes_written":16409907,"delete_count":0,"lbm_write_time_us":17902,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:51.886575 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=2.188937
I20260812 06:16:51.902201 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5771,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:51.902769 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53): perf score=1.000000
I20260812 06:16:52.044811 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.142s	user 0.110s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774694,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":907,"lbm_read_time_us":9631,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28298,"lbm_writes_lt_1ms":543,"mutex_wait_us":260,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:16:52.048882 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=11.118625
I20260812 06:16:52.083647 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.035s	user 0.016s	sys 0.016s Metrics: {"bytes_written":13251052,"delete_count":0,"lbm_write_time_us":14804,"lbm_writes_lt_1ms":326,"reinsert_count":0,"update_count":1615}
I20260812 06:16:52.084375 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=1.196750
I20260812 06:16:52.097371 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3159080,"delete_count":0,"lbm_write_time_us":4328,"lbm_writes_lt_1ms":80,"reinsert_count":0,"update_count":385}
I20260812 06:16:52.097882 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53): perf score=1.000000
I20260812 06:16:52.238634 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.141s	user 0.098s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672260,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":471,"lbm_read_time_us":9133,"lbm_reads_lt_1ms":468,"lbm_write_time_us":23232,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2000}
I20260812 06:16:52.239310 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=11.118625
I20260812 06:16:52.280864 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.041s	user 0.034s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14102,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:52.281409 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=2.188937
I20260812 06:16:52.298118 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.017s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4127,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:52.298653 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53): perf score=1.000000
I20260812 06:16:52.441027 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.142s	user 0.090s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":871,"lbm_read_time_us":10171,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21115,"lbm_writes_lt_1ms":443,"mutex_wait_us":66,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:52.441682 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=11.118625
I20260812 06:16:52.502029 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.060s	user 0.012s	sys 0.031s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":21436,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":1550}
I20260812 06:16:52.502588 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=6.157687
I20260812 06:16:52.527951 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.025s	user 0.021s	sys 0.000s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8576,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:16:52.528518 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53): perf score=1.000000
I20260812 06:16:52.670821 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.142s	user 0.089s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774695,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":962,"lbm_read_time_us":8824,"lbm_reads_lt_1ms":564,"lbm_write_time_us":25580,"lbm_writes_lt_1ms":543,"mutex_wait_us":327,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:16:52.671450 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=14.095187
I20260812 06:16:52.723328 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.052s	user 0.025s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23100,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:16:52.723996 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=2.188937
I20260812 06:16:52.739207 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.015s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4644,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:52.739784 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53): perf score=1.000000
I20260812 06:16:52.888680 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.149s	user 0.117s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":238,"lbm_read_time_us":10061,"lbm_reads_lt_1ms":568,"lbm_write_time_us":27620,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2500}
I20260812 06:16:52.889326 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=11.118625
I20260812 06:16:52.925669 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.036s	user 0.027s	sys 0.007s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":14650,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:52.926288 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=2.188937
I20260812 06:16:52.952708 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.026s	user 0.001s	sys 0.011s 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:16:52.953284 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=2.188937
I20260812 06:16:52.964253 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3940,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:52.964790 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushMRSOp(11af133f17854b40be08b70673f1ea53): perf score=1.000000
I20260812 06:16:52.994315 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushMRSOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.029s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":220,"dirs.run_wall_time_us":1492,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1604,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:16:52.995154 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling LogGCOp(11af133f17854b40be08b70673f1ea53): free 124257262 bytes of WAL
I20260812 06:16:52.995424 14573 log_reader.cc:385] T 11af133f17854b40be08b70673f1ea53: removed 12 log segments from log reader
I20260812 06:16:52.995476 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000015 (ops 72-76)
I20260812 06:16:52.995513 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000016 (ops 77-81)
I20260812 06:16:52.995548 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000017 (ops 82-86)
I20260812 06:16:52.995581 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000018 (ops 87-91)
I20260812 06:16:52.995613 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000019 (ops 92-96)
I20260812 06:16:52.995643 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000020 (ops 97-100)
I20260812 06:16:52.995673 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000021 (ops 101-105)
I20260812 06:16:52.995736 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000022 (ops 106-111)
I20260812 06:16:52.995776 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000023 (ops 112-116)
I20260812 06:16:52.995798 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000024 (ops 117-121)
I20260812 06:16:52.995814 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000025 (ops 122-126)
I20260812 06:16:52.995836 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000026 (ops 127-130)
I20260812 06:16:53.019299 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: LogGCOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.024s	user 0.002s	sys 0.019s Metrics: {}
I20260812 06:16:53.019785 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling UndoDeltaBlockGCOp(11af133f17854b40be08b70673f1ea53): 473 bytes on disk
I20260812 06:16:53.020323 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: UndoDeltaBlockGCOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:16:53.020943 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=3.181125
I20260812 06:16:53.039173 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.018s	user 0.000s	sys 0.012s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5369,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:53.039820 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=2.188937
I20260812 06:16:53.058797 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.018s	user 0.000s	sys 0.015s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3693,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:53.059526 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53): perf score=1.000000
I20260812 06:16:53.261736 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.202s	user 0.150s	sys 0.051s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979853,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":351,"lbm_read_time_us":14447,"lbm_reads_lt_1ms":775,"lbm_write_time_us":34467,"lbm_writes_lt_1ms":743,"mutex_wait_us":51,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":77,"threads_started":1,"update_count":3500}
I20260812 06:16:53.262414 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=14.095187
I20260812 06:16:53.321601 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.059s	user 0.033s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21329,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:53.322294 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=2.188937
I20260812 06:16:53.338203 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.016s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6029,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.338750 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53): perf score=1.000000
I20260812 06:16:53.516985 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.178s	user 0.094s	sys 0.072s 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":766,"lbm_read_time_us":12050,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27500,"lbm_writes_lt_1ms":543,"mutex_wait_us":335,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2500}
I20260812 06:16:53.517552 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=14.095187
I20260812 06:16:53.574890 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.057s	user 0.027s	sys 0.027s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19425,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:53.575671 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=2.188937
I20260812 06:16:53.587579 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4509,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.588111 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53): perf score=1.000000
I20260812 06:16:53.747061 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.159s	user 0.103s	sys 0.052s 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":246,"lbm_read_time_us":12296,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25342,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:53.747905 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=10.126437
I20260812 06:16:53.783581 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.035s	user 0.015s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13774,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:53.785383 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=2.188937
I20260812 06:16:53.798198 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.013s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4965,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.798715 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53): perf score=1.000000
I20260812 06:16:53.932682 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.134s	user 0.090s	sys 0.043s 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":99,"lbm_read_time_us":9085,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26227,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":2000}
I20260812 06:16:53.936123 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=10.126437
I20260812 06:16:53.967018 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.031s	user 0.018s	sys 0.009s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":12823,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:53.967665 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=2.188937
I20260812 06:16:53.979621 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4134,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.980144 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53): perf score=1.000000
I20260812 06:16:54.102474 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.122s	user 0.095s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":240,"lbm_read_time_us":8802,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23563,"lbm_writes_lt_1ms":443,"mutex_wait_us":34,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2000}
I20260812 06:16:54.103142 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=10.126437
I20260812 06:16:54.142023 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.039s	user 0.018s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13488,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:54.142566 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=2.188937
I20260812 06:16:54.153380 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3682,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.154006 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53): perf score=1.000000
I20260812 06:16:54.274698 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.120s	user 0.089s	sys 0.032s 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":771,"lbm_read_time_us":7637,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24690,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:54.275305 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=10.126437
I20260812 06:16:54.327234 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.052s	user 0.023s	sys 0.014s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14446,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:54.327955 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=2.188937
I20260812 06:16:54.338594 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3814,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.339181 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushMRSOp(11af133f17854b40be08b70673f1ea53): perf score=1.000000
I20260812 06:16:54.381778 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushMRSOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.042s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":1397,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1366,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:54.382651 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling LogGCOp(11af133f17854b40be08b70673f1ea53): free 112239554 bytes of WAL
I20260812 06:16:54.382910 14573 log_reader.cc:385] T 11af133f17854b40be08b70673f1ea53: removed 11 log segments from log reader
I20260812 06:16:54.382961 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000027 (ops 131-135)
I20260812 06:16:54.382998 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000028 (ops 136-140)
I20260812 06:16:54.383033 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000029 (ops 141-144)
I20260812 06:16:54.383064 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000030 (ops 145-149)
I20260812 06:16:54.383095 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000031 (ops 150-154)
I20260812 06:16:54.383127 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000032 (ops 155-159)
I20260812 06:16:54.383157 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000033 (ops 160-164)
I20260812 06:16:54.383188 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000034 (ops 165-169)
I20260812 06:16:54.383220 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000035 (ops 170-174)
I20260812 06:16:54.383251 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000036 (ops 175-179)
I20260812 06:16:54.383282 14573 log.cc:1079] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/11af133f17854b40be08b70673f1ea53/wal-000000037 (ops 180-184)
I20260812 06:16:54.403542 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: LogGCOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.021s	user 0.002s	sys 0.015s Metrics: {}
I20260812 06:16:54.404026 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=2.188937
I20260812 06:16:54.422487 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.018s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4792,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.422951 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling UndoDeltaBlockGCOp(11af133f17854b40be08b70673f1ea53): 446 bytes on disk
I20260812 06:16:54.423449 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: UndoDeltaBlockGCOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:16:54.424171 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=2.188937
I20260812 06:16:54.434306 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3714,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.434978 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53): perf score=1.000000
I20260812 06:16:54.623345 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.188s	user 0.120s	sys 0.068s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877339,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1052,"lbm_read_time_us":12728,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31009,"lbm_writes_lt_1ms":643,"mutex_wait_us":350,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":24576,"thread_start_us":88,"threads_started":1,"update_count":3000}
I20260812 06:16:54.624011 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=14.095187
I20260812 06:16:54.679826 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.055s	user 0.020s	sys 0.025s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20001,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:54.680361 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53): perf score=2.188937
I20260812 06:16:54.690553 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: FlushDeltaMemStoresOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3604,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.691015 14681 maintenance_manager.cc:419] P d1f10cb9a0044b73bdb0b3d83d006474: Scheduling MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53): perf score=1.000000
I20260812 06:16:54.722225 14409 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.709s	user 1.708s	sys 0.131s
I20260812 06:16:54.792569 14409 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.070s	user 0.000s	sys 0.003s
I20260812 06:16:54.793190 14409 tablet_server.cc:179] TabletServer@127.14.18.65:0 shutting down...
I20260812 06:16:54.838441 14573 maintenance_manager.cc:643] P d1f10cb9a0044b73bdb0b3d83d006474: MajorDeltaCompactionOp(11af133f17854b40be08b70673f1ea53) complete. Timing: real 0.147s	user 0.111s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":298,"lbm_read_time_us":11196,"lbm_reads_lt_1ms":568,"lbm_write_time_us":24120,"lbm_writes_lt_1ms":543,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":32768,"update_count":2500}
I20260812 06:16:54.839251 14409 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:54.839771 14409 tablet_replica.cc:333] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474: stopping tablet replica
I20260812 06:16:54.840011 14409 raft_consensus.cc:2243] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:54.840236 14409 raft_consensus.cc:2272] T 11af133f17854b40be08b70673f1ea53 P d1f10cb9a0044b73bdb0b3d83d006474 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:54.856998 14409 tablet_server.cc:196] TabletServer@127.14.18.65:0 shutdown complete.
I20260812 06:16:54.885072 14409 master.cc:562] Master@127.14.18.126:37067 shutting down...
I20260812 06:16:54.888376 14409 raft_consensus.cc:2243] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:54.888559 14409 raft_consensus.cc:2272] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:54.888635 14409 tablet_replica.cc:333] T 00000000000000000000000000000000 P ca4e79635f104fff9a980d3cbf02e779: stopping tablet replica
I20260812 06:16:54.901023 14409 master.cc:584] Master@127.14.18.126:37067 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5265 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:54.990669 14409 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.14.18.126:36043
I20260812 06:16:54.991098 14409 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:54.993599 14731 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:54.993826 14735 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:54.993836 14732 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:54.993997 14409 server_base.cc:1061] running on GCE node
I20260812 06:16:54.994160 14409 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:54.994199 14409 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:54.994215 14409 hybrid_clock.cc:648] HybridClock initialized: now 1786515414994214 us; error 0 us; skew 500 ppm
I20260812 06:16:54.995046 14409 webserver.cc:533] Webserver started at http://127.14.18.126:45185/ using document root <none> and password file <none>
I20260812 06:16:54.995203 14409 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:54.995260 14409 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:54.995337 14409 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:54.995800 14409 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/master-0-root/instance:
uuid: "02278eb9d56f403b9435d3efc40bb5d3"
format_stamp: "Formatted at 2026-08-12 06:16:54 on dist-test-slave-1l3l"
I20260812 06:16:54.997283 14409 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:54.998159 14740 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:54.998383 14409 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:54.998450 14409 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/master-0-root
uuid: "02278eb9d56f403b9435d3efc40bb5d3"
format_stamp: "Formatted at 2026-08-12 06:16:54 on dist-test-slave-1l3l"
I20260812 06:16:54.998524 14409 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:55.008850 14409 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:55.009248 14409 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:55.013491 14409 rpc_server.cc:307] RPC server started. Bound to: 127.14.18.126:36043
I20260812 06:16:55.018101 14827 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.18.126:36043 every 8 connection(s)
I20260812 06:16:55.018625 14828 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:55.020542 14828 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3: Bootstrap starting.
I20260812 06:16:55.021387 14828 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:55.022415 14828 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3: No bootstrap required, opened a new log
I20260812 06:16:55.022837 14828 raft_consensus.cc:359] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "02278eb9d56f403b9435d3efc40bb5d3" member_type: VOTER }
I20260812 06:16:55.022927 14828 raft_consensus.cc:385] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:55.022959 14828 raft_consensus.cc:740] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 02278eb9d56f403b9435d3efc40bb5d3, State: Initialized, Role: FOLLOWER
I20260812 06:16:55.023100 14828 consensus_queue.cc:260] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3 [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: "02278eb9d56f403b9435d3efc40bb5d3" member_type: VOTER }
I20260812 06:16:55.023177 14828 raft_consensus.cc:399] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:55.023217 14828 raft_consensus.cc:493] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:55.023267 14828 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:55.024067 14828 raft_consensus.cc:515] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "02278eb9d56f403b9435d3efc40bb5d3" member_type: VOTER }
I20260812 06:16:55.024214 14828 leader_election.cc:304] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3 [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: 02278eb9d56f403b9435d3efc40bb5d3; no voters: 
I20260812 06:16:55.024389 14828 leader_election.cc:290] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:55.024561 14831 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:55.024828 14831 raft_consensus.cc:697] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3 [term 1 LEADER]: Becoming Leader. State: Replica: 02278eb9d56f403b9435d3efc40bb5d3, State: Running, Role: LEADER
I20260812 06:16:55.024880 14828 sys_catalog.cc:565] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:55.025002 14831 consensus_queue.cc:237] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3 [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: "02278eb9d56f403b9435d3efc40bb5d3" member_type: VOTER }
I20260812 06:16:55.025449 14831 sys_catalog.cc:455] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 02278eb9d56f403b9435d3efc40bb5d3. Latest consensus state: current_term: 1 leader_uuid: "02278eb9d56f403b9435d3efc40bb5d3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "02278eb9d56f403b9435d3efc40bb5d3" member_type: VOTER } }
I20260812 06:16:55.025470 14833 sys_catalog.cc:455] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "02278eb9d56f403b9435d3efc40bb5d3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "02278eb9d56f403b9435d3efc40bb5d3" member_type: VOTER } }
I20260812 06:16:55.025615 14833 sys_catalog.cc:458] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:55.025878 14831 sys_catalog.cc:458] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:55.026115 14845 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:55.027048 14845 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:55.027290 14409 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:55.029235 14845 catalog_manager.cc:1383] Generated new cluster ID: 5b714d84b57342c9ae11012d9449ed9d
I20260812 06:16:55.029312 14845 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:55.038877 14845 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:55.039455 14845 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:55.047443 14845 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3: Generated new TSK 0
I20260812 06:16:55.047634 14845 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:55.059899 14409 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:55.062043 14865 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:55.062014 14872 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:55.062137 14409 server_base.cc:1061] running on GCE node
W20260812 06:16:55.062094 14866 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:55.062453 14409 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:55.062510 14409 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:55.062525 14409 hybrid_clock.cc:648] HybridClock initialized: now 1786515415062525 us; error 0 us; skew 500 ppm
I20260812 06:16:55.063340 14409 webserver.cc:533] Webserver started at http://127.14.18.65:42691/ using document root <none> and password file <none>
I20260812 06:16:55.063519 14409 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:55.063575 14409 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:55.063637 14409 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:55.064064 14409 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/instance:
uuid: "4c5aacc45cd04276acbc1d0c326d9d55"
format_stamp: "Formatted at 2026-08-12 06:16:55 on dist-test-slave-1l3l"
I20260812 06:16:55.065546 14409 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.001s
I20260812 06:16:55.066444 14883 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:55.066651 14409 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:55.066723 14409 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root
uuid: "4c5aacc45cd04276acbc1d0c326d9d55"
format_stamp: "Formatted at 2026-08-12 06:16:55 on dist-test-slave-1l3l"
I20260812 06:16:55.066794 14409 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:55.081197 14409 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:55.081676 14409 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:55.082003 14409 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:55.082507 14409 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:55.082548 14409 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:55.082597 14409 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:55.082623 14409 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:55.087095 14409 rpc_server.cc:307] RPC server started. Bound to: 127.14.18.65:40923
I20260812 06:16:55.087136 14988 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.18.65:40923 every 8 connection(s)
I20260812 06:16:55.095805 14990 heartbeater.cc:344] Connected to a master server at 127.14.18.126:36043
I20260812 06:16:55.095940 14990 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:55.096225 14990 heartbeater.cc:507] Master 127.14.18.126:36043 requested a full tablet report, sending...
I20260812 06:16:55.096899 14765 ts_manager.cc:194] Registered new tserver with Master: 4c5aacc45cd04276acbc1d0c326d9d55 (127.14.18.65:40923)
I20260812 06:16:55.097517 14409 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009979814s
I20260812 06:16:55.097769 14765 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:43814
I20260812 06:16:55.105988 14765 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:43818:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:16:55.115635 14926 tablet_service.cc:1511] Processing CreateTablet for tablet 5617a12c57ec49f6b0c5a66a9ffe46c2 (DEFAULT_TABLE table=heavy-update-compaction-test [id=94826611fe6c4ad9a39f17076b0993da]), partition=
I20260812 06:16:55.115958 14926 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 5617a12c57ec49f6b0c5a66a9ffe46c2. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:55.118332 15008 tablet_bootstrap.cc:492] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Bootstrap starting.
I20260812 06:16:55.119267 15008 tablet_bootstrap.cc:654] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:55.120436 15008 tablet_bootstrap.cc:492] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: No bootstrap required, opened a new log
I20260812 06:16:55.120554 15008 ts_tablet_manager.cc:1403] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:55.121098 15008 raft_consensus.cc:359] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4c5aacc45cd04276acbc1d0c326d9d55" member_type: VOTER last_known_addr { host: "127.14.18.65" port: 40923 } }
I20260812 06:16:55.121196 15008 raft_consensus.cc:385] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:55.121217 15008 raft_consensus.cc:740] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4c5aacc45cd04276acbc1d0c326d9d55, State: Initialized, Role: FOLLOWER
I20260812 06:16:55.121347 15008 consensus_queue.cc:260] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55 [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: "4c5aacc45cd04276acbc1d0c326d9d55" member_type: VOTER last_known_addr { host: "127.14.18.65" port: 40923 } }
I20260812 06:16:55.121420 15008 raft_consensus.cc:399] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:55.121456 15008 raft_consensus.cc:493] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:55.121506 15008 raft_consensus.cc:3060] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:55.122265 15008 raft_consensus.cc:515] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4c5aacc45cd04276acbc1d0c326d9d55" member_type: VOTER last_known_addr { host: "127.14.18.65" port: 40923 } }
I20260812 06:16:55.122403 15008 leader_election.cc:304] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55 [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: 4c5aacc45cd04276acbc1d0c326d9d55; no voters: 
I20260812 06:16:55.122613 15008 leader_election.cc:290] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:55.122721 15010 raft_consensus.cc:2804] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:55.122946 14990 heartbeater.cc:499] Master 127.14.18.126:36043 was elected leader, sending a full tablet report...
I20260812 06:16:55.122949 15010 raft_consensus.cc:697] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55 [term 1 LEADER]: Becoming Leader. State: Replica: 4c5aacc45cd04276acbc1d0c326d9d55, State: Running, Role: LEADER
I20260812 06:16:55.123163 15008 ts_tablet_manager.cc:1434] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:55.123127 15010 consensus_queue.cc:237] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55 [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: "4c5aacc45cd04276acbc1d0c326d9d55" member_type: VOTER last_known_addr { host: "127.14.18.65" port: 40923 } }
I20260812 06:16:55.124562 14765 catalog_manager.cc:5719] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55 reported cstate change: term changed from 0 to 1, leader changed from <none> to 4c5aacc45cd04276acbc1d0c326d9d55 (127.14.18.65). New cstate: current_term: 1 leader_uuid: "4c5aacc45cd04276acbc1d0c326d9d55" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4c5aacc45cd04276acbc1d0c326d9d55" member_type: VOTER last_known_addr { host: "127.14.18.65" port: 40923 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:55.183524 14409 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.014s	sys 0.008s
I20260812 06:16:55.338040 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushMRSOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=19.054940
I20260812 06:16:55.489080 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushMRSOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.151s	user 0.102s	sys 0.047s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":203,"dirs.run_wall_time_us":807,"drs_written":1,"lbm_read_time_us":104,"lbm_reads_lt_1ms":4,"lbm_write_time_us":35680,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:16:55.489852 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling LogGCOp(5617a12c57ec49f6b0c5a66a9ffe46c2): free 20743880 bytes of WAL
I20260812 06:16:55.490136 14890 log_reader.cc:385] T 5617a12c57ec49f6b0c5a66a9ffe46c2: removed 2 log segments from log reader
I20260812 06:16:55.490188 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000001 (ops 1-6)
I20260812 06:16:55.490221 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000002 (ops 7-11)
I20260812 06:16:55.493808 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: LogGCOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:16:55.494186 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=2.188937
I20260812 06:16:55.505678 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3877,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.506196 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling UndoDeltaBlockGCOp(5617a12c57ec49f6b0c5a66a9ffe46c2): 16411394 bytes on disk
I20260812 06:16:55.506636 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: UndoDeltaBlockGCOp(5617a12c57ec49f6b0c5a66a9ffe46c2) 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:16:55.507074 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=1.000000
I20260812 06:16:55.657021 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.150s	user 0.114s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":423,"lbm_read_time_us":9882,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22766,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":391,"threads_started":5,"update_count":2000}
I20260812 06:16:55.657567 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=10.126437
I20260812 06:16:55.686586 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.029s	user 0.014s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12380,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:55.687090 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=2.188937
I20260812 06:16:55.703274 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.016s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6218,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.703848 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=1.000000
I20260812 06:16:55.838340 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.134s	user 0.109s	sys 0.025s 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":295,"lbm_read_time_us":10715,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23327,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2000}
I20260812 06:16:55.839119 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=10.126437
I20260812 06:16:55.880820 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.042s	user 0.012s	sys 0.019s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13785,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:55.881304 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=2.188937
I20260812 06:16:55.891491 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3694,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.892163 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=1.000000
I20260812 06:16:56.009632 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.117s	user 0.094s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1084,"lbm_read_time_us":8455,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21690,"lbm_writes_lt_1ms":443,"mutex_wait_us":316,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:16:56.010228 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=10.126437
I20260812 06:16:56.056516 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.046s	user 0.028s	sys 0.017s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":21567,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:16:56.057143 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=2.188937
I20260812 06:16:56.069304 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4337,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.070173 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=1.000000
I20260812 06:16:56.189072 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.119s	user 0.097s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":664,"lbm_read_time_us":7657,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23648,"lbm_writes_lt_1ms":443,"mutex_wait_us":318,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":26112,"update_count":2000}
I20260812 06:16:56.189666 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=10.126437
I20260812 06:16:56.237905 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.048s	user 0.031s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14872,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:56.238525 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=2.188937
I20260812 06:16:56.254168 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5841,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.254731 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=1.000000
I20260812 06:16:56.404760 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.150s	user 0.077s	sys 0.072s 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":858,"lbm_read_time_us":11493,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23514,"lbm_writes_lt_1ms":443,"mutex_wait_us":298,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:56.405362 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=10.126437
I20260812 06:16:56.446419 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.041s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15187,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:56.447096 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=2.188937
I20260812 06:16:56.460956 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5242,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.461393 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=1.000000
I20260812 06:16:56.585253 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.124s	user 0.108s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":215,"lbm_read_time_us":9631,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24078,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":26496,"update_count":2000}
I20260812 06:16:56.585827 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=10.126437
I20260812 06:16:56.622936 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.037s	user 0.020s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14405,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:56.623507 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=2.188937
I20260812 06:16:56.638810 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5457,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.639532 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushMRSOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=1.000000
I20260812 06:16:56.666062 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushMRSOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.026s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":102,"dirs.run_cpu_time_us":240,"dirs.run_wall_time_us":1421,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1408,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:56.666738 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling LogGCOp(5617a12c57ec49f6b0c5a66a9ffe46c2): free 112239310 bytes of WAL
I20260812 06:16:56.666994 14890 log_reader.cc:385] T 5617a12c57ec49f6b0c5a66a9ffe46c2: removed 11 log segments from log reader
I20260812 06:16:56.667044 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000003 (ops 12-16)
I20260812 06:16:56.667073 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000004 (ops 17-21)
I20260812 06:16:56.667093 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000005 (ops 22-26)
I20260812 06:16:56.667124 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000006 (ops 27-31)
I20260812 06:16:56.667156 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000007 (ops 32-36)
I20260812 06:16:56.667187 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000008 (ops 37-41)
I20260812 06:16:56.667218 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000009 (ops 42-46)
I20260812 06:16:56.667249 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000010 (ops 47-50)
I20260812 06:16:56.667280 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000011 (ops 51-55)
I20260812 06:16:56.667311 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000012 (ops 56-60)
I20260812 06:16:56.667342 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000013 (ops 61-65)
I20260812 06:16:56.688642 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: LogGCOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.022s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:16:56.689127 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=3.181125
I20260812 06:16:56.707396 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.018s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4494,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:56.707901 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling UndoDeltaBlockGCOp(5617a12c57ec49f6b0c5a66a9ffe46c2): 447 bytes on disk
I20260812 06:16:56.708318 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: UndoDeltaBlockGCOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:16:56.708787 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=2.188937
I20260812 06:16:56.718418 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3340,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:56.718933 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=1.000000
I20260812 06:16:56.885970 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.167s	user 0.142s	sys 0.025s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":198,"lbm_read_time_us":13478,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31136,"lbm_writes_lt_1ms":643,"mutex_wait_us":47,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11520,"thread_start_us":92,"threads_started":1,"update_count":3000}
I20260812 06:16:56.886530 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=14.095187
I20260812 06:16:56.935137 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.048s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21475,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:56.935742 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=2.188937
I20260812 06:16:56.947199 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4160,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.947636 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=1.000000
I20260812 06:16:57.093161 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.145s	user 0.106s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":838,"lbm_read_time_us":11417,"lbm_reads_lt_1ms":568,"lbm_write_time_us":28306,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":49024,"update_count":2500}
I20260812 06:16:57.093758 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=11.118625
I20260812 06:16:57.127985 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.034s	user 0.027s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13987,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:57.128643 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=2.188937
I20260812 06:16:57.153484 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.025s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":5463,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:16:57.154016 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=2.188937
I20260812 06:16:57.164120 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3938559,"delete_count":0,"lbm_write_time_us":3648,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:16:57.164630 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=1.000000
I20260812 06:16:57.315816 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.151s	user 0.093s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774803,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":928,"lbm_read_time_us":10484,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29930,"lbm_writes_lt_1ms":543,"mutex_wait_us":580,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:16:57.316468 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=11.118625
I20260812 06:16:57.346325 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.030s	user 0.023s	sys 0.004s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":12734,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:57.346796 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=2.188937
I20260812 06:16:57.362849 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.016s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4934,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:57.363476 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=1.000000
I20260812 06:16:57.489168 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.126s	user 0.089s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":171,"lbm_read_time_us":9589,"lbm_reads_lt_1ms":468,"lbm_write_time_us":22680,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17536,"update_count":2000}
I20260812 06:16:57.490000 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=10.126437
I20260812 06:16:57.534780 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.044s	user 0.030s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14619,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:57.535526 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=2.188937
I20260812 06:16:57.551035 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5815,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.551626 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=1.000000
I20260812 06:16:57.694437 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.143s	user 0.094s	sys 0.049s 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":219,"lbm_read_time_us":10763,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22748,"lbm_writes_lt_1ms":443,"mutex_wait_us":57,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2000}
I20260812 06:16:57.695050 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=10.126437
I20260812 06:16:57.730212 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.035s	user 0.012s	sys 0.017s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12990,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:57.730759 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=2.188937
I20260812 06:16:57.741592 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3948,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.742275 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=1.000000
I20260812 06:16:57.861794 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.119s	user 0.091s	sys 0.028s 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":278,"lbm_read_time_us":8149,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22675,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":36480,"update_count":2000}
I20260812 06:16:57.862313 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=10.126437
I20260812 06:16:57.900768 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.038s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14147,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:57.901240 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=2.188937
I20260812 06:16:57.911381 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3750,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.911976 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushMRSOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=1.000000
I20260812 06:16:57.940364 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushMRSOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.028s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":1279,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1527,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:57.941100 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling LogGCOp(5617a12c57ec49f6b0c5a66a9ffe46c2): free 112239324 bytes of WAL
I20260812 06:16:57.941341 14890 log_reader.cc:385] T 5617a12c57ec49f6b0c5a66a9ffe46c2: removed 11 log segments from log reader
I20260812 06:16:57.941401 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000014 (ops 66-70)
I20260812 06:16:57.941449 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000015 (ops 71-74)
I20260812 06:16:57.941483 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000016 (ops 75-79)
I20260812 06:16:57.941514 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000017 (ops 80-84)
I20260812 06:16:57.941541 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000018 (ops 85-89)
I20260812 06:16:57.941576 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000019 (ops 90-94)
I20260812 06:16:57.941606 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000020 (ops 95-99)
I20260812 06:16:57.941635 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000021 (ops 100-104)
I20260812 06:16:57.941663 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000022 (ops 105-109)
I20260812 06:16:57.941692 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000023 (ops 110-114)
I20260812 06:16:57.941725 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000024 (ops 115-119)
I20260812 06:16:57.967283 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: LogGCOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.026s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:16:57.967832 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling UndoDeltaBlockGCOp(5617a12c57ec49f6b0c5a66a9ffe46c2): 447 bytes on disk
I20260812 06:16:57.968297 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: UndoDeltaBlockGCOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:16:57.968936 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=3.181125
I20260812 06:16:57.982789 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.014s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4098,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:57.983278 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=2.188937
I20260812 06:16:57.992653 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3321,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:57.993276 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=1.000000
I20260812 06:16:58.157007 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.163s	user 0.127s	sys 0.031s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":293,"lbm_read_time_us":11514,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31928,"lbm_writes_lt_1ms":643,"mutex_wait_us":30,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9088,"thread_start_us":86,"threads_started":1,"update_count":3000}
I20260812 06:16:58.157582 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=14.095187
I20260812 06:16:58.216373 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.059s	user 0.032s	sys 0.020s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":23826,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:58.216974 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=2.188937
I20260812 06:16:58.232304 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5722,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.232877 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=1.000000
I20260812 06:16:58.444664 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.212s	user 0.097s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1013,"lbm_read_time_us":13256,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":571,"lbm_write_time_us":29041,"lbm_writes_lt_1ms":543,"mutex_wait_us":517,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22144,"update_count":2500}
I20260812 06:16:58.445282 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=18.063937
I20260812 06:16:58.541667 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.096s	user 0.041s	sys 0.007s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":21285,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:58.542142 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=6.157687
I20260812 06:16:58.635586 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.093s	user 0.017s	sys 0.008s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":10966,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:58.636264 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=6.157687
I20260812 06:16:58.732980 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.097s	user 0.019s	sys 0.000s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8389,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:58.733561 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=7.149875
I20260812 06:16:58.830716 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.097s	user 0.021s	sys 0.002s Metrics: {"bytes_written":9230684,"delete_count":0,"lbm_write_time_us":10365,"lbm_writes_lt_1ms":228,"reinsert_count":0,"update_count":1125}
I20260812 06:16:58.831236 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=9.134250
I20260812 06:16:58.931257 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.100s	user 0.016s	sys 0.012s Metrics: {"bytes_written":11281895,"delete_count":0,"lbm_write_time_us":12322,"lbm_writes_lt_1ms":278,"reinsert_count":0,"update_count":1375}
I20260812 06:16:58.932430 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=7.149875
I20260812 06:16:59.030206 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.098s	user 0.009s	sys 0.008s Metrics: {"bytes_written":8615322,"delete_count":0,"lbm_write_time_us":7762,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:59.030916 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=10.126437
I20260812 06:16:59.134385 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.103s	user 0.018s	sys 0.016s Metrics: {"bytes_written":11897249,"delete_count":0,"lbm_write_time_us":14441,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:16:59.135022 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=7.149875
I20260812 06:16:59.237001 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.102s	user 0.016s	sys 0.003s Metrics: {"bytes_written":8574299,"delete_count":0,"lbm_write_time_us":8072,"lbm_writes_lt_1ms":212,"reinsert_count":0,"update_count":1045}
I20260812 06:16:59.237808 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=10.126437
I20260812 06:16:59.339596 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.102s	user 0.018s	sys 0.008s Metrics: {"bytes_written":11528037,"delete_count":0,"lbm_write_time_us":11618,"lbm_writes_lt_1ms":284,"reinsert_count":0,"update_count":1405}
I20260812 06:16:59.342059 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=7.149875
I20260812 06:16:59.438930 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.096s	user 0.011s	sys 0.007s Metrics: {"bytes_written":9025568,"delete_count":0,"lbm_write_time_us":8036,"lbm_writes_lt_1ms":223,"reinsert_count":0,"update_count":1100}
I20260812 06:16:59.439634 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=10.126437
I20260812 06:16:59.537551 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.098s	user 0.018s	sys 0.008s Metrics: {"bytes_written":11610082,"delete_count":0,"lbm_write_time_us":11738,"lbm_writes_lt_1ms":286,"reinsert_count":0,"update_count":1415}
I20260812 06:16:59.538138 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=7.149875
I20260812 06:16:59.588366 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.050s	user 0.023s	sys 0.004s Metrics: {"bytes_written":8492254,"delete_count":0,"lbm_write_time_us":11388,"lbm_writes_lt_1ms":210,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":1035}
I20260812 06:16:59.588912 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=2.188937
I20260812 06:16:59.621694 14409 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.438s	user 1.700s	sys 0.072s
I20260812 06:16:59.689105 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.100s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6231,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.689707 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=2.188937
I20260812 06:16:59.788020 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushDeltaMemStoresOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.098s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5875,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":500}
I20260812 06:16:59.788547 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling FlushMRSOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=1.000000
I20260812 06:16:59.889551 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: FlushMRSOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.101s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1644370,"cfile_init":1,"dirs.queue_time_us":225,"dirs.run_cpu_time_us":234,"dirs.run_wall_time_us":73588,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2339,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":40,"thread_start_us":86,"threads_started":1}
I20260812 06:16:59.890254 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling LogGCOp(5617a12c57ec49f6b0c5a66a9ffe46c2): free 166280734 bytes of WAL
I20260812 06:16:59.890494 14890 log_reader.cc:385] T 5617a12c57ec49f6b0c5a66a9ffe46c2: removed 16 log segments from log reader
I20260812 06:16:59.890539 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000025 (ops 120-124)
I20260812 06:16:59.890580 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000026 (ops 125-129)
I20260812 06:16:59.890610 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000027 (ops 130-134)
I20260812 06:16:59.890662 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000028 (ops 135-139)
I20260812 06:16:59.890699 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000029 (ops 140-144)
I20260812 06:16:59.890726 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000030 (ops 145-149)
I20260812 06:16:59.890786 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000031 (ops 150-154)
I20260812 06:16:59.890825 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000032 (ops 155-159)
I20260812 06:16:59.890851 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000033 (ops 160-164)
I20260812 06:16:59.890882 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000034 (ops 165-169)
I20260812 06:16:59.890940 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000035 (ops 170-174)
I20260812 06:16:59.890983 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000036 (ops 175-179)
I20260812 06:16:59.891013 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000037 (ops 180-184)
I20260812 06:16:59.891064 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000038 (ops 185-189)
I20260812 06:16:59.891098 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000039 (ops 190-194)
I20260812 06:16:59.891155 14890 log.cc:1079] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: Deleting log segment in path: /tmp/dist-test-taskOFa9Ue/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515409703437-14409-0/minicluster-data/ts-0-root/wals/5617a12c57ec49f6b0c5a66a9ffe46c2/wal-000000040 (ops 195-199)
I20260812 06:16:59.919255 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: LogGCOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.029s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:16:59.919732 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling UndoDeltaBlockGCOp(5617a12c57ec49f6b0c5a66a9ffe46c2): 583 bytes on disk
I20260812 06:16:59.920189 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: UndoDeltaBlockGCOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:16:59.920739 14991 maintenance_manager.cc:419] P 4c5aacc45cd04276acbc1d0c326d9d55: Scheduling MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2): perf score=1.000000
I20260812 06:16:59.949509 14409 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.327s	user 0.002s	sys 0.000s
I20260812 06:16:59.950007 14409 tablet_server.cc:179] TabletServer@127.14.18.65:0 shutting down...
I20260812 06:17:00.700280 14890 maintenance_manager.cc:643] P 4c5aacc45cd04276acbc1d0c326d9d55: MajorDeltaCompactionOp(5617a12c57ec49f6b0c5a66a9ffe46c2) complete. Timing: real 0.779s	user 0.403s	sys 0.328s Metrics: {"cfile_cache_hit":2121,"cfile_cache_hit_bytes":90016391,"cfile_cache_miss":1223,"cfile_cache_miss_bytes":49627316,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":14,"delta_iterators_relevant":14,"dirs.queue_time_us":1038,"lbm_read_time_us":19458,"lbm_reads_lt_1ms":1239,"lbm_write_time_us":160588,"lbm_writes_lt_1ms":3346,"peak_mem_usage":411059916,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":337,"threads_started":6,"update_count":16500}
I20260812 06:17:00.700891 14409 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:00.701162 14409 tablet_replica.cc:333] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55: stopping tablet replica
I20260812 06:17:00.701294 14409 raft_consensus.cc:2243] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:00.701453 14409 raft_consensus.cc:2272] T 5617a12c57ec49f6b0c5a66a9ffe46c2 P 4c5aacc45cd04276acbc1d0c326d9d55 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:00.714669 14409 tablet_server.cc:196] TabletServer@127.14.18.65:0 shutdown complete.
I20260812 06:17:01.650715 14409 master.cc:562] Master@127.14.18.126:36043 shutting down...
I20260812 06:17:01.653848 14409 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:01.654043 14409 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:01.654110 14409 tablet_replica.cc:333] T 00000000000000000000000000000000 P 02278eb9d56f403b9435d3efc40bb5d3: stopping tablet replica
I20260812 06:17:01.666365 14409 master.cc:584] Master@127.14.18.126:36043 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6758 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12025 ms total)

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