[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:38.894845 16841 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.16.114.126:45505
I20260812 06:18:38.895987 16841 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:38.896716 16841 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:38.903568 16849 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:38.903537 16846 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:38.903997 16847 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:38.904165 16841 server_base.cc:1061] running on GCE node
I20260812 06:18:38.904652 16841 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:38.904752 16841 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:38.904794 16841 hybrid_clock.cc:648] HybridClock initialized: now 1786515518904791 us; error 0 us; skew 500 ppm
I20260812 06:18:38.906584 16841 webserver.cc:533] Webserver started at http://127.16.114.126:44977/ using document root <none> and password file <none>
I20260812 06:18:38.907088 16841 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:38.907148 16841 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:38.907367 16841 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:38.908985 16841 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/master-0-root/instance:
uuid: "fbc4362946a34ba18e494a260139bbd3"
format_stamp: "Formatted at 2026-08-12 06:18:38 on dist-test-slave-f7th"
I20260812 06:18:38.912802 16841 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:18:38.914786 16854 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:38.916054 16841 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:38.916160 16841 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/master-0-root
uuid: "fbc4362946a34ba18e494a260139bbd3"
format_stamp: "Formatted at 2026-08-12 06:18:38 on dist-test-slave-f7th"
I20260812 06:18:38.916254 16841 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:38.927953 16841 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:38.928527 16841 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:38.928669 16841 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:38.936688 16841 rpc_server.cc:307] RPC server started. Bound to: 127.16.114.126:45505
I20260812 06:18:38.936700 16906 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.16.114.126:45505 every 8 connection(s)
I20260812 06:18:38.939085 16907 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:38.945277 16907 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3: Bootstrap starting.
I20260812 06:18:38.947883 16907 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:38.948921 16907 log.cc:826] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:38.950765 16907 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3: No bootstrap required, opened a new log
I20260812 06:18:38.954105 16907 raft_consensus.cc:359] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fbc4362946a34ba18e494a260139bbd3" member_type: VOTER }
I20260812 06:18:38.954274 16907 raft_consensus.cc:385] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:38.954332 16907 raft_consensus.cc:740] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: fbc4362946a34ba18e494a260139bbd3, State: Initialized, Role: FOLLOWER
I20260812 06:18:38.954958 16907 consensus_queue.cc:260] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3 [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: "fbc4362946a34ba18e494a260139bbd3" member_type: VOTER }
I20260812 06:18:38.955104 16907 raft_consensus.cc:399] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:38.955170 16907 raft_consensus.cc:493] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:38.955288 16907 raft_consensus.cc:3060] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:38.956080 16907 raft_consensus.cc:515] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fbc4362946a34ba18e494a260139bbd3" member_type: VOTER }
I20260812 06:18:38.956499 16907 leader_election.cc:304] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3 [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: fbc4362946a34ba18e494a260139bbd3; no voters: 
I20260812 06:18:38.956777 16907 leader_election.cc:290] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:38.956909 16910 raft_consensus.cc:2804] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:38.957135 16910 raft_consensus.cc:697] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3 [term 1 LEADER]: Becoming Leader. State: Replica: fbc4362946a34ba18e494a260139bbd3, State: Running, Role: LEADER
I20260812 06:18:38.957574 16910 consensus_queue.cc:237] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3 [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: "fbc4362946a34ba18e494a260139bbd3" member_type: VOTER }
I20260812 06:18:38.957803 16907 sys_catalog.cc:565] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:38.959812 16911 sys_catalog.cc:455] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "fbc4362946a34ba18e494a260139bbd3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fbc4362946a34ba18e494a260139bbd3" member_type: VOTER } }
I20260812 06:18:38.959949 16911 sys_catalog.cc:458] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:38.959807 16912 sys_catalog.cc:455] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3 [sys.catalog]: SysCatalogTable state changed. Reason: New leader fbc4362946a34ba18e494a260139bbd3. Latest consensus state: current_term: 1 leader_uuid: "fbc4362946a34ba18e494a260139bbd3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fbc4362946a34ba18e494a260139bbd3" member_type: VOTER } }
I20260812 06:18:38.960062 16912 sys_catalog.cc:458] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:38.960155 16841 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:18:38.962393 16924 catalog_manager.cc:1594] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:18:38.962464 16924 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:18:38.962543 16925 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:38.963476 16925 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:38.968358 16925 catalog_manager.cc:1383] Generated new cluster ID: 20266c1318f94c06becc7dcd029fedf3
I20260812 06:18:38.968422 16925 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:38.988036 16925 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:38.989533 16925 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:38.997151 16925 catalog_manager.cc:6092] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3: Generated new TSK 0
I20260812 06:18:38.997996 16925 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:39.024977 16841 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:39.027971 16930 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:39.027989 16929 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:39.028246 16932 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:39.028292 16841 server_base.cc:1061] running on GCE node
I20260812 06:18:39.028501 16841 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:39.028553 16841 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:39.028592 16841 hybrid_clock.cc:648] HybridClock initialized: now 1786515519028591 us; error 0 us; skew 500 ppm
I20260812 06:18:39.029551 16841 webserver.cc:533] Webserver started at http://127.16.114.65:35907/ using document root <none> and password file <none>
I20260812 06:18:39.029723 16841 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:39.029781 16841 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:39.029866 16841 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:39.030340 16841 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/instance:
uuid: "f26ef43f76594f01b3cea16039313c67"
format_stamp: "Formatted at 2026-08-12 06:18:39 on dist-test-slave-f7th"
I20260812 06:18:39.032321 16841 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:39.033454 16937 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:39.033699 16841 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:39.033779 16841 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root
uuid: "f26ef43f76594f01b3cea16039313c67"
format_stamp: "Formatted at 2026-08-12 06:18:39 on dist-test-slave-f7th"
I20260812 06:18:39.033888 16841 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:39.046206 16841 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:39.046728 16841 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:39.047263 16841 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:39.048290 16841 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:39.048368 16841 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:39.048425 16841 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:39.048496 16841 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:39.054953 16841 rpc_server.cc:307] RPC server started. Bound to: 127.16.114.65:44489
I20260812 06:18:39.055006 17000 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.16.114.65:44489 every 8 connection(s)
I20260812 06:18:39.065096 17001 heartbeater.cc:344] Connected to a master server at 127.16.114.126:45505
I20260812 06:18:39.065336 17001 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:39.065762 17001 heartbeater.cc:507] Master 127.16.114.126:45505 requested a full tablet report, sending...
I20260812 06:18:39.067144 16871 ts_manager.cc:194] Registered new tserver with Master: f26ef43f76594f01b3cea16039313c67 (127.16.114.65:44489)
I20260812 06:18:39.067425 16841 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011746945s
I20260812 06:18:39.068629 16871 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:48042
I20260812 06:18:39.076753 16871 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:48056:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:39.091646 16965 tablet_service.cc:1511] Processing CreateTablet for tablet 3265c03893cb4948a7899e17c38bf166 (DEFAULT_TABLE table=heavy-update-compaction-test [id=a5e4978ac75e430ea1114c57bb72e33a]), partition=
I20260812 06:18:39.092123 16965 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 3265c03893cb4948a7899e17c38bf166. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:39.094749 17013 tablet_bootstrap.cc:492] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Bootstrap starting.
I20260812 06:18:39.095943 17013 tablet_bootstrap.cc:654] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:39.097083 17013 tablet_bootstrap.cc:492] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: No bootstrap required, opened a new log
I20260812 06:18:39.097193 17013 ts_tablet_manager.cc:1403] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:39.097673 17013 raft_consensus.cc:359] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f26ef43f76594f01b3cea16039313c67" member_type: VOTER last_known_addr { host: "127.16.114.65" port: 44489 } }
I20260812 06:18:39.097841 17013 raft_consensus.cc:385] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:39.097894 17013 raft_consensus.cc:740] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f26ef43f76594f01b3cea16039313c67, State: Initialized, Role: FOLLOWER
I20260812 06:18:39.098064 17013 consensus_queue.cc:260] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67 [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: "f26ef43f76594f01b3cea16039313c67" member_type: VOTER last_known_addr { host: "127.16.114.65" port: 44489 } }
I20260812 06:18:39.098160 17013 raft_consensus.cc:399] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:39.098230 17013 raft_consensus.cc:493] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:39.098284 17013 raft_consensus.cc:3060] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:39.099078 17013 raft_consensus.cc:515] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f26ef43f76594f01b3cea16039313c67" member_type: VOTER last_known_addr { host: "127.16.114.65" port: 44489 } }
I20260812 06:18:39.099242 17013 leader_election.cc:304] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67 [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: f26ef43f76594f01b3cea16039313c67; no voters: 
I20260812 06:18:39.099454 17013 leader_election.cc:290] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:39.099543 17015 raft_consensus.cc:2804] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:39.099751 17015 raft_consensus.cc:697] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67 [term 1 LEADER]: Becoming Leader. State: Replica: f26ef43f76594f01b3cea16039313c67, State: Running, Role: LEADER
I20260812 06:18:39.099797 17013 ts_tablet_manager.cc:1434] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:39.100210 17001 heartbeater.cc:499] Master 127.16.114.126:45505 was elected leader, sending a full tablet report...
I20260812 06:18:39.100281 17015 consensus_queue.cc:237] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67 [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: "f26ef43f76594f01b3cea16039313c67" member_type: VOTER last_known_addr { host: "127.16.114.65" port: 44489 } }
I20260812 06:18:39.103396 16871 catalog_manager.cc:5719] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67 reported cstate change: term changed from 0 to 1, leader changed from <none> to f26ef43f76594f01b3cea16039313c67 (127.16.114.65). New cstate: current_term: 1 leader_uuid: "f26ef43f76594f01b3cea16039313c67" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f26ef43f76594f01b3cea16039313c67" member_type: VOTER last_known_addr { host: "127.16.114.65" port: 44489 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:39.172498 16841 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.063s	user 0.021s	sys 0.011s
I20260812 06:18:39.306067 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushMRSOp(3265c03893cb4948a7899e17c38bf166): perf score=19.054940
I20260812 06:18:39.499583 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushMRSOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.193s	user 0.123s	sys 0.052s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":188,"delete_count":0,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":201,"dirs.run_wall_time_us":796,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":48062,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":756,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":106,"threads_started":1,"update_count":1500}
I20260812 06:18:39.500833 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling LogGCOp(3265c03893cb4948a7899e17c38bf166): free 20743880 bytes of WAL
I20260812 06:18:39.501195 16942 log_reader.cc:385] T 3265c03893cb4948a7899e17c38bf166: removed 2 log segments from log reader
I20260812 06:18:39.501318 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000001 (ops 1-6)
I20260812 06:18:39.501681 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000002 (ops 7-11)
I20260812 06:18:39.506420 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: LogGCOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:39.506894 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling UndoDeltaBlockGCOp(3265c03893cb4948a7899e17c38bf166): 16411394 bytes on disk
I20260812 06:18:39.507632 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: UndoDeltaBlockGCOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.001s	user 0.001s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":87,"lbm_reads_lt_1ms":4}
I20260812 06:18:39.508157 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=2.188937
I20260812 06:18:39.525130 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.017s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6332,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.528590 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:39.684909 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.156s	user 0.108s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":495,"lbm_read_time_us":9271,"lbm_reads_lt_1ms":460,"lbm_write_time_us":21577,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"thread_start_us":279,"threads_started":5,"update_count":2000}
I20260812 06:18:39.685431 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=10.126437
I20260812 06:18:39.735073 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.049s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14637,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:39.735666 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=2.188937
I20260812 06:18:39.748847 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.013s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4736,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.749558 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:39.899533 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.150s	user 0.129s	sys 0.012s 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":225,"lbm_read_time_us":9515,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27496,"lbm_writes_lt_1ms":443,"mutex_wait_us":65,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:39.900188 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=14.095187
I20260812 06:18:39.952977 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.050s	user 0.027s	sys 0.019s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20972,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:39.953562 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=2.188937
I20260812 06:18:39.968744 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.015s	user 0.005s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5577,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.969225 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:40.118117 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.149s	user 0.120s	sys 0.026s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1063,"lbm_read_time_us":11246,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25079,"lbm_writes_lt_1ms":543,"mutex_wait_us":472,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:18:40.118752 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=10.126437
I20260812 06:18:40.153023 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.034s	user 0.024s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14247,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:40.153494 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:40.271371 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.118s	user 0.058s	sys 0.057s 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":81,"lbm_read_time_us":8130,"lbm_reads_lt_1ms":363,"lbm_write_time_us":18148,"lbm_writes_lt_1ms":343,"mutex_wait_us":29,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":1500}
I20260812 06:18:40.271931 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=7.149875
I20260812 06:18:40.298789 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.027s	user 0.013s	sys 0.011s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":11204,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:18:40.299275 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=2.188937
I20260812 06:18:40.314610 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4854,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:40.315954 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:40.426237 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.110s	user 0.088s	sys 0.021s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569856,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":649,"lbm_read_time_us":7615,"lbm_reads_lt_1ms":372,"lbm_write_time_us":18510,"lbm_writes_lt_1ms":343,"mutex_wait_us":276,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":1500}
I20260812 06:18:40.426669 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=6.157687
I20260812 06:18:40.456822 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.030s	user 0.018s	sys 0.005s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9587,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:40.457315 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=2.188937
I20260812 06:18:40.468518 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4189,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:40.469022 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:40.588243 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.119s	user 0.085s	sys 0.032s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569865,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":488,"lbm_read_time_us":8153,"lbm_reads_lt_1ms":372,"lbm_write_time_us":19697,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":1500}
I20260812 06:18:40.588757 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=7.149875
I20260812 06:18:40.617993 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.029s	user 0.014s	sys 0.012s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":12189,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:18:40.618505 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=2.188937
I20260812 06:18:40.636248 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.018s	user 0.013s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":7236,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:40.636816 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:40.760568 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.124s	user 0.099s	sys 0.020s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569856,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":487,"lbm_read_time_us":6675,"lbm_reads_lt_1ms":368,"lbm_write_time_us":22471,"lbm_writes_lt_1ms":343,"mutex_wait_us":157,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":1500}
I20260812 06:18:40.761044 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=10.126437
I20260812 06:18:40.809540 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.048s	user 0.023s	sys 0.010s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16374,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:40.810015 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=2.188937
I20260812 06:18:40.822296 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4572,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:40.822728 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushMRSOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:40.858738 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushMRSOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.036s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":206,"dirs.run_wall_time_us":1327,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1566,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:40.859689 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling LogGCOp(3265c03893cb4948a7899e17c38bf166): free 112239310 bytes of WAL
I20260812 06:18:40.860034 16942 log_reader.cc:385] T 3265c03893cb4948a7899e17c38bf166: removed 11 log segments from log reader
I20260812 06:18:40.860105 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000003 (ops 12-16)
I20260812 06:18:40.860158 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000004 (ops 17-20)
I20260812 06:18:40.860199 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000005 (ops 21-25)
I20260812 06:18:40.860235 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000006 (ops 26-30)
I20260812 06:18:40.860281 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000007 (ops 31-35)
I20260812 06:18:40.860319 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000008 (ops 36-40)
I20260812 06:18:40.860357 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000009 (ops 41-45)
I20260812 06:18:40.860392 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000010 (ops 46-50)
I20260812 06:18:40.860430 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000011 (ops 51-55)
I20260812 06:18:40.860468 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000012 (ops 56-60)
I20260812 06:18:40.860505 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000013 (ops 61-65)
I20260812 06:18:40.884996 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: LogGCOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.025s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:18:40.885462 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=3.181125
I20260812 06:18:40.903496 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.018s	user 0.004s	sys 0.012s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7253,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:40.904464 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=2.188937
I20260812 06:18:40.914835 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3859,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:40.915354 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling UndoDeltaBlockGCOp(3265c03893cb4948a7899e17c38bf166): 463 bytes on disk
I20260812 06:18:40.915841 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: UndoDeltaBlockGCOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:18:40.916647 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:41.117152 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.200s	user 0.153s	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":1950,"lbm_read_time_us":11784,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37185,"lbm_writes_lt_1ms":643,"mutex_wait_us":27,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6400,"thread_start_us":71,"threads_started":1,"update_count":3000}
I20260812 06:18:41.117650 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=14.095187
I20260812 06:18:41.166558 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.049s	user 0.033s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23380,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:41.167057 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=2.188937
I20260812 06:18:41.179628 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4598,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.180272 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:41.330523 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.150s	user 0.108s	sys 0.041s 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":620,"lbm_read_time_us":10382,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28484,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:41.331067 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=10.126437
I20260812 06:18:41.375808 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.045s	user 0.015s	sys 0.024s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16718,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:41.376293 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:41.497584 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.121s	user 0.092s	sys 0.028s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569747,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":146,"lbm_read_time_us":7931,"lbm_reads_lt_1ms":363,"lbm_write_time_us":19111,"lbm_writes_lt_1ms":343,"mutex_wait_us":27,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":1500}
I20260812 06:18:41.498377 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=10.126437
I20260812 06:18:41.548975 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.050s	user 0.016s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15324,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:41.549539 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=2.188937
I20260812 06:18:41.564396 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5197,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.564982 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:41.692677 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.127s	user 0.095s	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":492,"lbm_read_time_us":7581,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22105,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:41.693127 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=10.126437
I20260812 06:18:41.729969 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.037s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15249,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:41.730456 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:41.838183 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.108s	user 0.099s	sys 0.008s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569748,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":138,"lbm_read_time_us":6717,"lbm_reads_lt_1ms":363,"lbm_write_time_us":18404,"lbm_writes_lt_1ms":343,"mutex_wait_us":48,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":1500}
I20260812 06:18:41.838644 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=10.126437
I20260812 06:18:41.881580 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.043s	user 0.015s	sys 0.015s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":14180,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:41.882089 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=2.188937
I20260812 06:18:41.896940 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5174,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.897410 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:42.034833 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.137s	user 0.105s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672281,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":248,"lbm_read_time_us":8359,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23842,"lbm_writes_lt_1ms":443,"mutex_wait_us":256,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:18:42.036108 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=10.126437
I20260812 06:18:42.086125 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.050s	user 0.016s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15486,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:42.086728 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=2.188937
I20260812 06:18:42.103889 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.017s	user 0.007s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6465,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.104364 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:42.233716 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.129s	user 0.101s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":186,"lbm_read_time_us":9088,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22984,"lbm_writes_lt_1ms":443,"mutex_wait_us":29,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2000}
I20260812 06:18:42.234310 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=10.126437
I20260812 06:18:42.280030 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.046s	user 0.011s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13566,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:42.280550 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=2.188937
I20260812 06:18:42.291098 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3779,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.291664 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushMRSOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:42.327064 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushMRSOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.035s	user 0.026s	sys 0.005s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":87,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":1437,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1546,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:42.327889 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling LogGCOp(3265c03893cb4948a7899e17c38bf166): free 121006437 bytes of WAL
I20260812 06:18:42.328118 16942 log_reader.cc:385] T 3265c03893cb4948a7899e17c38bf166: removed 12 log segments from log reader
I20260812 06:18:42.328171 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000014 (ops 66-70)
I20260812 06:18:42.328203 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000015 (ops 71-75)
I20260812 06:18:42.328234 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000016 (ops 76-80)
I20260812 06:18:42.328262 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000017 (ops 81-85)
I20260812 06:18:42.328289 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000018 (ops 86-90)
I20260812 06:18:42.328313 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000019 (ops 91-94)
I20260812 06:18:42.328342 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000020 (ops 95-99)
I20260812 06:18:42.328369 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000021 (ops 100-104)
I20260812 06:18:42.328397 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000022 (ops 105-109)
I20260812 06:18:42.328423 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000023 (ops 110-114)
I20260812 06:18:42.328450 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000024 (ops 115-119)
I20260812 06:18:42.328474 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000025 (ops 120-124)
I20260812 06:18:42.354158 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: LogGCOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.026s	user 0.001s	sys 0.024s Metrics: {}
I20260812 06:18:42.354580 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=3.181125
I20260812 06:18:42.370596 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.016s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5272,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:42.371179 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling UndoDeltaBlockGCOp(3265c03893cb4948a7899e17c38bf166): 461 bytes on disk
I20260812 06:18:42.371769 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: UndoDeltaBlockGCOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:18:42.372470 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=2.188937
I20260812 06:18:42.386261 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4746,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:42.386860 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:42.578135 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.191s	user 0.134s	sys 0.051s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":4307,"lbm_read_time_us":12215,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37107,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3584,"thread_start_us":95,"threads_started":1,"update_count":3000}
I20260812 06:18:42.578874 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=14.095187
I20260812 06:18:42.620466 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.041s	user 0.025s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17904,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:42.621028 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=2.188937
I20260812 06:18:42.635440 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5394,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.636029 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:42.809414 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.173s	user 0.113s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":856,"lbm_read_time_us":10489,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33039,"lbm_writes_lt_1ms":543,"mutex_wait_us":284,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:18:42.812196 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=14.095187
I20260812 06:18:42.874117 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.062s	user 0.024s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24832,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:42.874598 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=2.188937
I20260812 06:18:42.889012 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":5246,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.889530 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:43.058333 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.169s	user 0.126s	sys 0.039s 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":583,"lbm_read_time_us":11696,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27872,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:18:43.058928 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=14.095187
I20260812 06:18:43.117095 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.058s	user 0.027s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19666,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:43.117769 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=2.188937
I20260812 06:18:43.131704 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4995,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.132447 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:43.323930 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.191s	user 0.128s	sys 0.057s 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":861,"lbm_read_time_us":13830,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33519,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":303,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2500}
I20260812 06:18:43.324659 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=14.095187
I20260812 06:18:43.387465 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.063s	user 0.032s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24409,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:43.388029 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=2.188937
I20260812 06:18:43.398602 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3861,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.399047 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:43.577545 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.178s	user 0.114s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":876,"lbm_read_time_us":12146,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32420,"lbm_writes_lt_1ms":543,"mutex_wait_us":70,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:43.581071 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=10.126437
I20260812 06:18:43.628340 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.047s	user 0.022s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15082,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:43.628919 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=2.188937
I20260812 06:18:43.644276 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5390,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.644846 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:43.795322 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.150s	user 0.121s	sys 0.018s 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":475,"lbm_read_time_us":10704,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23460,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2000}
I20260812 06:18:43.795982 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=10.126437
I20260812 06:18:43.847923 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.051s	user 0.020s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18915,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:43.848507 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=2.188937
I20260812 06:18:43.863622 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5704,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.864259 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushMRSOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:43.906731 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushMRSOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.042s	user 0.037s	sys 0.000s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":183,"dirs.run_wall_time_us":1243,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2161,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30,"spinlock_wait_cycles":1280}
I20260812 06:18:43.907686 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling LogGCOp(3265c03893cb4948a7899e17c38bf166): free 124710546 bytes of WAL
I20260812 06:18:43.908000 16942 log_reader.cc:385] T 3265c03893cb4948a7899e17c38bf166: removed 12 log segments from log reader
I20260812 06:18:43.908095 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000026 (ops 125-129)
I20260812 06:18:43.908186 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000027 (ops 130-134)
I20260812 06:18:43.908265 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000028 (ops 135-139)
I20260812 06:18:43.908341 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000029 (ops 140-144)
I20260812 06:18:43.908427 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000030 (ops 145-149)
I20260812 06:18:43.908502 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000031 (ops 150-154)
I20260812 06:18:43.908577 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000032 (ops 155-159)
I20260812 06:18:43.908663 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000033 (ops 160-164)
I20260812 06:18:43.908739 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000034 (ops 165-169)
I20260812 06:18:43.908812 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000035 (ops 170-174)
I20260812 06:18:43.908885 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000036 (ops 175-179)
I20260812 06:18:43.908955 16942 log.cc:1079] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/3265c03893cb4948a7899e17c38bf166/wal-000000037 (ops 180-184)
I20260812 06:18:43.935191 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: LogGCOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.027s	user 0.002s	sys 0.025s Metrics: {}
I20260812 06:18:43.935757 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling UndoDeltaBlockGCOp(3265c03893cb4948a7899e17c38bf166): 472 bytes on disk
I20260812 06:18:43.936229 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: UndoDeltaBlockGCOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:18:43.936897 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=6.157687
I20260812 06:18:43.972234 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.035s	user 0.023s	sys 0.004s Metrics: {"bytes_written":8205080,"delete_count":0,"lbm_write_time_us":10903,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:43.972750 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=2.188937
I20260812 06:18:43.987260 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5144,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.988037 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:44.229497 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.241s	user 0.191s	sys 0.046s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979753,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":554,"lbm_read_time_us":17059,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41299,"lbm_writes_lt_1ms":743,"mutex_wait_us":60,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12928,"thread_start_us":88,"threads_started":1,"update_count":3500}
I20260812 06:18:44.230017 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=14.095187
I20260812 06:18:44.254024 16841 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.081s	user 1.773s	sys 0.185s
I20260812 06:18:44.273597 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.043s	user 0.034s	sys 0.007s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20596,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:44.274287 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166): perf score=2.188937
I20260812 06:18:44.289448 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: FlushDeltaMemStoresOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6175,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:44.289983 17002 maintenance_manager.cc:419] P f26ef43f76594f01b3cea16039313c67: Scheduling MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166): perf score=1.000000
I20260812 06:18:44.316012 16841 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.061s	user 0.004s	sys 0.000s
I20260812 06:18:44.316725 16841 tablet_server.cc:179] TabletServer@127.16.114.65:0 shutting down...
I20260812 06:18:44.434633 16942 maintenance_manager.cc:643] P f26ef43f76594f01b3cea16039313c67: MajorDeltaCompactionOp(3265c03893cb4948a7899e17c38bf166) complete. Timing: real 0.144s	user 0.104s	sys 0.040s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4262390,"cfile_cache_miss":502,"cfile_cache_miss_bytes":20512301,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":337,"lbm_read_time_us":9684,"lbm_reads_lt_1ms":518,"lbm_write_time_us":21197,"lbm_writes_lt_1ms":543,"mutex_wait_us":61,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2500}
I20260812 06:18:44.435318 16841 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:44.435782 16841 tablet_replica.cc:333] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67: stopping tablet replica
I20260812 06:18:44.436007 16841 raft_consensus.cc:2243] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:44.436267 16841 raft_consensus.cc:2272] T 3265c03893cb4948a7899e17c38bf166 P f26ef43f76594f01b3cea16039313c67 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:44.452025 16841 tablet_server.cc:196] TabletServer@127.16.114.65:0 shutdown complete.
I20260812 06:18:44.481360 16841 master.cc:562] Master@127.16.114.126:45505 shutting down...
I20260812 06:18:44.485430 16841 raft_consensus.cc:2243] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:44.485592 16841 raft_consensus.cc:2272] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:44.485656 16841 tablet_replica.cc:333] T 00000000000000000000000000000000 P fbc4362946a34ba18e494a260139bbd3: stopping tablet replica
I20260812 06:18:44.497663 16841 master.cc:584] Master@127.16.114.126:45505 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5678 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:44.572656 16841 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.16.114.126:43619
I20260812 06:18:44.573015 16841 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:44.574836 17035 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:44.574890 16841 server_base.cc:1061] running on GCE node
W20260812 06:18:44.574859 17034 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:44.575116 17037 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:44.575306 16841 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:44.575362 16841 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:44.575382 16841 hybrid_clock.cc:648] HybridClock initialized: now 1786515524575382 us; error 0 us; skew 500 ppm
I20260812 06:18:44.576349 16841 webserver.cc:533] Webserver started at http://127.16.114.126:43791/ using document root <none> and password file <none>
I20260812 06:18:44.576529 16841 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:44.576581 16841 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:44.576650 16841 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:44.577090 16841 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/master-0-root/instance:
uuid: "afbd08e52c3a43f39b4ec7eca1e15aed"
format_stamp: "Formatted at 2026-08-12 06:18:44 on dist-test-slave-f7th"
I20260812 06:18:44.578799 16841 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:44.579924 17042 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:44.580185 16841 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:44.580271 16841 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/master-0-root
uuid: "afbd08e52c3a43f39b4ec7eca1e15aed"
format_stamp: "Formatted at 2026-08-12 06:18:44 on dist-test-slave-f7th"
I20260812 06:18:44.580344 16841 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:44.589974 16841 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:44.590317 16841 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:44.594393 16841 rpc_server.cc:307] RPC server started. Bound to: 127.16.114.126:43619
I20260812 06:18:44.603559 17094 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.16.114.126:43619 every 8 connection(s)
I20260812 06:18:44.607045 17095 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:44.609328 17095 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed: Bootstrap starting.
I20260812 06:18:44.610229 17095 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:44.611341 17095 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed: No bootstrap required, opened a new log
I20260812 06:18:44.611801 17095 raft_consensus.cc:359] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "afbd08e52c3a43f39b4ec7eca1e15aed" member_type: VOTER }
I20260812 06:18:44.611900 17095 raft_consensus.cc:385] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:44.611927 17095 raft_consensus.cc:740] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: afbd08e52c3a43f39b4ec7eca1e15aed, State: Initialized, Role: FOLLOWER
I20260812 06:18:44.612056 17095 consensus_queue.cc:260] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed [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: "afbd08e52c3a43f39b4ec7eca1e15aed" member_type: VOTER }
I20260812 06:18:44.612128 17095 raft_consensus.cc:399] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:44.612164 17095 raft_consensus.cc:493] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:44.612200 17095 raft_consensus.cc:3060] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:44.613003 17095 raft_consensus.cc:515] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "afbd08e52c3a43f39b4ec7eca1e15aed" member_type: VOTER }
I20260812 06:18:44.613133 17095 leader_election.cc:304] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed [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: afbd08e52c3a43f39b4ec7eca1e15aed; no voters: 
I20260812 06:18:44.613320 17095 leader_election.cc:290] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:44.613472 17098 raft_consensus.cc:2804] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:44.613710 17098 raft_consensus.cc:697] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed [term 1 LEADER]: Becoming Leader. State: Replica: afbd08e52c3a43f39b4ec7eca1e15aed, State: Running, Role: LEADER
I20260812 06:18:44.613729 17095 sys_catalog.cc:565] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:44.613903 17098 consensus_queue.cc:237] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed [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: "afbd08e52c3a43f39b4ec7eca1e15aed" member_type: VOTER }
I20260812 06:18:44.614355 17099 sys_catalog.cc:455] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "afbd08e52c3a43f39b4ec7eca1e15aed" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "afbd08e52c3a43f39b4ec7eca1e15aed" member_type: VOTER } }
I20260812 06:18:44.614395 17100 sys_catalog.cc:455] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed [sys.catalog]: SysCatalogTable state changed. Reason: New leader afbd08e52c3a43f39b4ec7eca1e15aed. Latest consensus state: current_term: 1 leader_uuid: "afbd08e52c3a43f39b4ec7eca1e15aed" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "afbd08e52c3a43f39b4ec7eca1e15aed" member_type: VOTER } }
I20260812 06:18:44.614518 17099 sys_catalog.cc:458] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:44.614558 17100 sys_catalog.cc:458] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:44.615038 17105 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:44.616076 17105 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:44.616348 16841 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:44.618077 17105 catalog_manager.cc:1383] Generated new cluster ID: 7cdd4fb94e4642458d5b66ccfc7fda4e
I20260812 06:18:44.618160 17105 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:44.642647 17105 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:44.643199 17105 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:44.647943 17105 catalog_manager.cc:6092] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed: Generated new TSK 0
I20260812 06:18:44.648101 17105 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:44.680861 16841 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:44.682796 17116 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:44.682806 17117 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:44.682881 17119 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:44.683049 16841 server_base.cc:1061] running on GCE node
I20260812 06:18:44.683280 16841 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:44.683328 16841 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:44.683349 16841 hybrid_clock.cc:648] HybridClock initialized: now 1786515524683349 us; error 0 us; skew 500 ppm
I20260812 06:18:44.684162 16841 webserver.cc:533] Webserver started at http://127.16.114.65:43457/ using document root <none> and password file <none>
I20260812 06:18:44.684324 16841 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:44.684371 16841 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:44.684445 16841 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:44.684819 16841 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/instance:
uuid: "583a026cff1044939bc621aaab365509"
format_stamp: "Formatted at 2026-08-12 06:18:44 on dist-test-slave-f7th"
I20260812 06:18:44.686229 16841 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:44.687120 17124 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:44.687356 16841 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:44.687422 16841 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root
uuid: "583a026cff1044939bc621aaab365509"
format_stamp: "Formatted at 2026-08-12 06:18:44 on dist-test-slave-f7th"
I20260812 06:18:44.687484 16841 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:44.730252 16841 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:44.730640 16841 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:44.730964 16841 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:44.731419 16841 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:44.731458 16841 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:44.731503 16841 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:44.731534 16841 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:44.735509 16841 rpc_server.cc:307] RPC server started. Bound to: 127.16.114.65:36515
I20260812 06:18:44.735554 17187 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.16.114.65:36515 every 8 connection(s)
I20260812 06:18:44.745136 17188 heartbeater.cc:344] Connected to a master server at 127.16.114.126:43619
I20260812 06:18:44.745265 17188 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:44.745473 17188 heartbeater.cc:507] Master 127.16.114.126:43619 requested a full tablet report, sending...
I20260812 06:18:44.746081 17059 ts_manager.cc:194] Registered new tserver with Master: 583a026cff1044939bc621aaab365509 (127.16.114.65:36515)
I20260812 06:18:44.746930 16841 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010989793s
I20260812 06:18:44.747099 17059 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:49578
I20260812 06:18:44.754061 17059 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:49582:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:44.762943 17152 tablet_service.cc:1511] Processing CreateTablet for tablet 7baa3dae411547a9be55091f5e990422 (DEFAULT_TABLE table=heavy-update-compaction-test [id=311612c9cd1d4e779d80c8f907528064]), partition=
I20260812 06:18:44.763206 17152 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 7baa3dae411547a9be55091f5e990422. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:44.765729 17200 tablet_bootstrap.cc:492] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Bootstrap starting.
I20260812 06:18:44.766523 17200 tablet_bootstrap.cc:654] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:44.767565 17200 tablet_bootstrap.cc:492] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: No bootstrap required, opened a new log
I20260812 06:18:44.767683 17200 ts_tablet_manager.cc:1403] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:44.768074 17200 raft_consensus.cc:359] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "583a026cff1044939bc621aaab365509" member_type: VOTER last_known_addr { host: "127.16.114.65" port: 36515 } }
I20260812 06:18:44.768179 17200 raft_consensus.cc:385] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:44.768261 17200 raft_consensus.cc:740] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 583a026cff1044939bc621aaab365509, State: Initialized, Role: FOLLOWER
I20260812 06:18:44.768401 17200 consensus_queue.cc:260] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509 [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: "583a026cff1044939bc621aaab365509" member_type: VOTER last_known_addr { host: "127.16.114.65" port: 36515 } }
I20260812 06:18:44.768486 17200 raft_consensus.cc:399] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:44.768528 17200 raft_consensus.cc:493] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:44.768576 17200 raft_consensus.cc:3060] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:44.769420 17200 raft_consensus.cc:515] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "583a026cff1044939bc621aaab365509" member_type: VOTER last_known_addr { host: "127.16.114.65" port: 36515 } }
I20260812 06:18:44.769536 17200 leader_election.cc:304] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509 [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: 583a026cff1044939bc621aaab365509; no voters: 
I20260812 06:18:44.769678 17200 leader_election.cc:290] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:44.769815 17202 raft_consensus.cc:2804] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:44.770002 17200 ts_tablet_manager.cc:1434] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:18:44.770025 17202 raft_consensus.cc:697] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509 [term 1 LEADER]: Becoming Leader. State: Replica: 583a026cff1044939bc621aaab365509, State: Running, Role: LEADER
I20260812 06:18:44.770087 17188 heartbeater.cc:499] Master 127.16.114.126:43619 was elected leader, sending a full tablet report...
I20260812 06:18:44.770236 17202 consensus_queue.cc:237] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509 [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: "583a026cff1044939bc621aaab365509" member_type: VOTER last_known_addr { host: "127.16.114.65" port: 36515 } }
I20260812 06:18:44.771489 17059 catalog_manager.cc:5719] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509 reported cstate change: term changed from 0 to 1, leader changed from <none> to 583a026cff1044939bc621aaab365509 (127.16.114.65). New cstate: current_term: 1 leader_uuid: "583a026cff1044939bc621aaab365509" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "583a026cff1044939bc621aaab365509" member_type: VOTER last_known_addr { host: "127.16.114.65" port: 36515 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:44.835582 16841 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.019s	sys 0.007s
I20260812 06:18:44.986496 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushMRSOp(7baa3dae411547a9be55091f5e990422): perf score=19.054940
I20260812 06:18:45.157495 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushMRSOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.171s	user 0.136s	sys 0.032s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":174,"dirs.run_wall_time_us":875,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42011,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:18:45.158366 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling LogGCOp(7baa3dae411547a9be55091f5e990422): free 20743880 bytes of WAL
I20260812 06:18:45.158603 17129 log_reader.cc:385] T 7baa3dae411547a9be55091f5e990422: removed 2 log segments from log reader
I20260812 06:18:45.158663 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000001 (ops 1-6)
I20260812 06:18:45.158706 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000002 (ops 7-11)
I20260812 06:18:45.163262 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: LogGCOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:45.163672 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling UndoDeltaBlockGCOp(7baa3dae411547a9be55091f5e990422): 16411397 bytes on disk
I20260812 06:18:45.164183 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: UndoDeltaBlockGCOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4}
I20260812 06:18:45.164655 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=2.188937
I20260812 06:18:45.186450 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.022s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7325,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.186892 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422): perf score=1.000000
I20260812 06:18:45.326256 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.139s	user 0.094s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":331,"lbm_read_time_us":8388,"lbm_reads_lt_1ms":460,"lbm_write_time_us":25329,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":341,"threads_started":5,"update_count":2000}
I20260812 06:18:45.326833 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=10.126437
I20260812 06:18:45.378674 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.051s	user 0.025s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16294,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:45.379230 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=2.188937
I20260812 06:18:45.396389 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.017s	user 0.013s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6277,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.396971 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422): perf score=1.000000
I20260812 06:18:45.543035 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.146s	user 0.102s	sys 0.044s 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":191,"lbm_read_time_us":10209,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28360,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2000}
I20260812 06:18:45.543655 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=10.126437
I20260812 06:18:45.604875 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.061s	user 0.015s	sys 0.031s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17612,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:45.605338 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=2.188937
I20260812 06:18:45.616917 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4333,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.617326 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422): perf score=1.000000
I20260812 06:18:45.785115 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.168s	user 0.121s	sys 0.039s 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":440,"lbm_read_time_us":11720,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26711,"lbm_writes_lt_1ms":443,"mutex_wait_us":266,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14464,"update_count":2000}
I20260812 06:18:45.785722 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=10.126437
I20260812 06:18:45.834479 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.049s	user 0.024s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16622,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:45.834975 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=2.188937
I20260812 06:18:45.845445 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3855,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.845815 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422): perf score=1.000000
I20260812 06:18:45.983536 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.138s	user 0.090s	sys 0.045s 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":1344,"lbm_read_time_us":8604,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26015,"lbm_writes_lt_1ms":443,"mutex_wait_us":785,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:45.984090 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=10.126437
I20260812 06:18:46.023561 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.037s	user 0.018s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13769,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:46.024191 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422): perf score=1.000000
I20260812 06:18:46.134872 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.111s	user 0.082s	sys 0.021s 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":2690,"dirs.run_cpu_time_us":398,"dirs.run_wall_time_us":2763,"lbm_read_time_us":6851,"lbm_reads_lt_1ms":363,"lbm_write_time_us":18643,"lbm_writes_lt_1ms":343,"mutex_wait_us":1570,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:18:46.135476 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=10.126437
I20260812 06:18:46.177327 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.042s	user 0.018s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14044,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:46.177798 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=2.188937
I20260812 06:18:46.188169 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.010s	user 0.010s	sys 0.000s 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:18:46.188598 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422): perf score=1.000000
I20260812 06:18:46.338956 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.150s	user 0.123s	sys 0.021s 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":281,"lbm_read_time_us":8455,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28162,"lbm_writes_lt_1ms":443,"mutex_wait_us":60,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:18:46.339557 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=10.126437
I20260812 06:18:46.389955 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.050s	user 0.037s	sys 0.006s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18895,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:46.390569 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=2.188937
I20260812 06:18:46.402843 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4656,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:46.403328 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422): perf score=1.000000
I20260812 06:18:46.532051 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.129s	user 0.104s	sys 0.023s 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":370,"lbm_read_time_us":7955,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22882,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2000}
I20260812 06:18:46.532567 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=10.126437
I20260812 06:18:46.564437 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.032s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13584,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:46.565027 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushMRSOp(7baa3dae411547a9be55091f5e990422): perf score=1.000000
I20260812 06:18:46.625080 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushMRSOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.060s	user 0.031s	sys 0.005s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":50,"dirs.run_cpu_time_us":209,"dirs.run_wall_time_us":1359,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1736,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:46.625720 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling LogGCOp(7baa3dae411547a9be55091f5e990422): free 124710294 bytes of WAL
I20260812 06:18:46.625917 17129 log_reader.cc:385] T 7baa3dae411547a9be55091f5e990422: removed 12 log segments from log reader
I20260812 06:18:46.625957 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000003 (ops 12-16)
I20260812 06:18:46.625993 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000004 (ops 17-21)
I20260812 06:18:46.626067 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000005 (ops 22-26)
I20260812 06:18:46.626102 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000006 (ops 27-31)
I20260812 06:18:46.626158 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000007 (ops 32-36)
I20260812 06:18:46.626190 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000008 (ops 37-41)
I20260812 06:18:46.626210 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000009 (ops 42-46)
I20260812 06:18:46.626263 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000010 (ops 47-51)
I20260812 06:18:46.626293 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000011 (ops 52-56)
I20260812 06:18:46.626345 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000012 (ops 57-61)
I20260812 06:18:46.626375 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000013 (ops 62-66)
I20260812 06:18:46.626425 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000014 (ops 67-71)
I20260812 06:18:46.652153 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: LogGCOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.026s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:46.652637 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling UndoDeltaBlockGCOp(7baa3dae411547a9be55091f5e990422): 481 bytes on disk
I20260812 06:18:46.653031 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: UndoDeltaBlockGCOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:18:46.653491 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=6.157687
I20260812 06:18:46.675026 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.021s	user 0.007s	sys 0.012s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8931,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:46.675467 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=2.188937
I20260812 06:18:46.687788 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4502,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:46.688247 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422): perf score=1.000000
I20260812 06:18:46.861408 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.173s	user 0.133s	sys 0.032s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877220,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":409,"lbm_read_time_us":10988,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32678,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2560,"thread_start_us":78,"threads_started":1,"update_count":3000}
I20260812 06:18:46.861989 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=14.095187
I20260812 06:18:46.917096 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.053s	user 0.031s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17912,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:46.917544 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=2.188937
I20260812 06:18:46.929576 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4611,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:46.930146 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422): perf score=1.000000
I20260812 06:18:47.090346 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.160s	user 0.129s	sys 0.028s 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":334,"lbm_read_time_us":10469,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27369,"lbm_writes_lt_1ms":543,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2500}
I20260812 06:18:47.091861 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=12.110812
I20260812 06:18:47.146907 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.054s	user 0.030s	sys 0.020s Metrics: {"bytes_written":13825407,"delete_count":0,"lbm_write_time_us":24094,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":339,"reinsert_count":0,"update_count":1685}
I20260812 06:18:47.147456 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=1.196750
I20260812 06:18:47.167979 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.020s	user 0.010s	sys 0.000s Metrics: {"bytes_written":2584729,"delete_count":0,"lbm_write_time_us":3817,"lbm_writes_lt_1ms":66,"reinsert_count":0,"update_count":315}
I20260812 06:18:47.168433 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=2.188937
I20260812 06:18:47.180509 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4489,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.181106 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422): perf score=1.000000
I20260812 06:18:47.353018 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.172s	user 0.106s	sys 0.066s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774795,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":601,"lbm_read_time_us":11408,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29500,"lbm_writes_lt_1ms":543,"mutex_wait_us":280,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2500}
I20260812 06:18:47.353617 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=10.126437
I20260812 06:18:47.396816 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.043s	user 0.017s	sys 0.022s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15059,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:47.397468 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=2.188937
I20260812 06:18:47.407473 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3652,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.407912 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422): perf score=1.000000
I20260812 06:18:47.564584 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.156s	user 0.106s	sys 0.050s 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":489,"lbm_read_time_us":11732,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26303,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2000}
I20260812 06:18:47.565160 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=10.126437
I20260812 06:18:47.614470 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.049s	user 0.032s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18999,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:47.615160 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=2.188937
I20260812 06:18:47.627463 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4603,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.628031 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422): perf score=1.000000
I20260812 06:18:47.772297 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.143s	user 0.126s	sys 0.004s 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":579,"lbm_read_time_us":10660,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21129,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2000}
I20260812 06:18:47.773290 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=10.126437
I20260812 06:18:47.825839 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.052s	user 0.033s	sys 0.005s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17347,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:47.826377 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=2.188937
I20260812 06:18:47.843007 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6158,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.843580 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422): perf score=1.000000
I20260812 06:18:47.978709 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.135s	user 0.107s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":183,"lbm_read_time_us":10734,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24381,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2000}
I20260812 06:18:47.979260 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=10.126437
I20260812 06:18:48.037096 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.053s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17008,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:48.037624 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=2.188937
I20260812 06:18:48.052938 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5904,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.053519 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushMRSOp(7baa3dae411547a9be55091f5e990422): perf score=1.000000
I20260812 06:18:48.082487 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushMRSOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.029s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":186,"dirs.run_wall_time_us":1362,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1614,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:48.083323 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling LogGCOp(7baa3dae411547a9be55091f5e990422): free 112692378 bytes of WAL
I20260812 06:18:48.083542 17129 log_reader.cc:385] T 7baa3dae411547a9be55091f5e990422: removed 11 log segments from log reader
I20260812 06:18:48.083623 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000015 (ops 72-76)
I20260812 06:18:48.083666 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000016 (ops 77-81)
I20260812 06:18:48.083706 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000017 (ops 82-86)
I20260812 06:18:48.083735 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000018 (ops 87-91)
I20260812 06:18:48.083763 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000019 (ops 92-96)
I20260812 06:18:48.083796 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000020 (ops 97-101)
I20260812 06:18:48.083859 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000021 (ops 102-106)
I20260812 06:18:48.083891 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000022 (ops 107-111)
I20260812 06:18:48.083952 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000023 (ops 112-116)
I20260812 06:18:48.083989 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000024 (ops 117-121)
I20260812 06:18:48.084041 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000025 (ops 122-126)
I20260812 06:18:48.109066 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: LogGCOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.026s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:18:48.109494 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=3.181125
I20260812 06:18:48.128495 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.019s	user 0.011s	sys 0.002s Metrics: {"bytes_written":4512904,"delete_count":0,"lbm_write_time_us":5111,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:48.128947 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling UndoDeltaBlockGCOp(7baa3dae411547a9be55091f5e990422): 447 bytes on disk
I20260812 06:18:48.129328 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: UndoDeltaBlockGCOp(7baa3dae411547a9be55091f5e990422) 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:18:48.129930 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=2.188937
I20260812 06:18:48.159684 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.030s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4748,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:48.160207 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422): perf score=1.000000
I20260812 06:18:48.338335 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: MajorDeltaCompactionOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.178s	user 0.121s	sys 0.049s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877330,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":517,"lbm_read_time_us":12802,"lbm_reads_lt_1ms":666,"lbm_write_time_us":32572,"lbm_writes_lt_1ms":643,"mutex_wait_us":255,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11008,"thread_start_us":73,"threads_started":1,"update_count":3000}
I20260812 06:18:48.338996 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=14.095187
I20260812 06:18:48.461006 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.122s	user 0.029s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18151,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:48.461757 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=10.126437
I20260812 06:18:48.507485 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.046s	user 0.013s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12222,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:48.508181 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=3.181125
I20260812 06:18:48.602450 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.094s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6554,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:48.602967 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=10.126437
I20260812 06:18:48.705091 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.102s	user 0.020s	sys 0.011s Metrics: {"bytes_written":11651105,"delete_count":0,"lbm_write_time_us":14326,"lbm_writes_lt_1ms":287,"reinsert_count":0,"update_count":1420}
I20260812 06:18:48.705744 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=7.149875
I20260812 06:18:48.802428 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.097s	user 0.009s	sys 0.016s Metrics: {"bytes_written":8451227,"delete_count":0,"lbm_write_time_us":11138,"lbm_writes_lt_1ms":209,"reinsert_count":0,"update_count":1030}
I20260812 06:18:48.803236 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=6.157687
I20260812 06:18:48.903869 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.100s	user 0.025s	sys 0.000s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10299,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:48.904327 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=7.149875
I20260812 06:18:48.999719 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.095s	user 0.020s	sys 0.000s Metrics: {"bytes_written":8615324,"delete_count":0,"lbm_write_time_us":8117,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:18:49.000193 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=10.126437
I20260812 06:18:49.105398 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.105s	user 0.009s	sys 0.020s Metrics: {"bytes_written":11897249,"delete_count":0,"lbm_write_time_us":11453,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:18:49.105989 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=7.149875
I20260812 06:18:49.204630 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.098s	user 0.020s	sys 0.005s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":10580,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:18:49.205178 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=9.134250
I20260812 06:18:49.306278 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.101s	user 0.020s	sys 0.004s Metrics: {"bytes_written":11117793,"delete_count":0,"lbm_write_time_us":10982,"lbm_writes_lt_1ms":274,"reinsert_count":0,"update_count":1355}
I20260812 06:18:49.306908 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=7.149875
I20260812 06:18:49.433759 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.127s	user 0.010s	sys 0.008s Metrics: {"bytes_written":8984542,"delete_count":0,"lbm_write_time_us":7981,"lbm_writes_lt_1ms":222,"reinsert_count":0,"update_count":1095}
I20260812 06:18:49.434383 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=10.126437
I20260812 06:18:49.506001 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.071s	user 0.024s	sys 0.006s Metrics: {"bytes_written":12348515,"delete_count":0,"lbm_write_time_us":12720,"lbm_writes_lt_1ms":304,"reinsert_count":0,"update_count":1505}
I20260812 06:18:49.506702 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=6.157687
I20260812 06:18:49.606527 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.100s	user 0.022s	sys 0.000s Metrics: {"bytes_written":8164057,"delete_count":0,"lbm_write_time_us":9311,"lbm_writes_lt_1ms":202,"reinsert_count":0,"update_count":995}
I20260812 06:18:49.607162 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=6.157687
I20260812 06:18:49.627466 16841 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.792s	user 1.783s	sys 0.102s
I20260812 06:18:49.707031 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.100s	user 0.011s	sys 0.007s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":7888,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:49.707774 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422): perf score=2.188937
I20260812 06:18:49.806751 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushDeltaMemStoresOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.099s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4367,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":500}
I20260812 06:18:49.807375 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling FlushMRSOp(7baa3dae411547a9be55091f5e990422): perf score=1.000000
I20260812 06:18:49.908733 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: FlushMRSOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.101s	user 0.021s	sys 0.008s Metrics: {"bytes_written":1521477,"cfile_init":1,"dirs.queue_time_us":211,"drs_written":1,"lbm_read_time_us":33,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1673,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":37,"thread_start_us":94,"threads_started":1}
I20260812 06:18:49.909519 17189 maintenance_manager.cc:419] P 583a026cff1044939bc621aaab365509: Scheduling LogGCOp(7baa3dae411547a9be55091f5e990422): free 148746475 bytes of WAL
I20260812 06:18:49.909782 17129 log_reader.cc:385] T 7baa3dae411547a9be55091f5e990422: removed 14 log segments from log reader
I20260812 06:18:49.909832 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000026 (ops 127-131)
I20260812 06:18:49.909868 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000027 (ops 132-136)
I20260812 06:18:49.909931 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000028 (ops 137-141)
I20260812 06:18:49.909963 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000029 (ops 142-146)
I20260812 06:18:49.909984 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000030 (ops 147-151)
I20260812 06:18:49.910038 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000031 (ops 152-156)
I20260812 06:18:49.910076 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000032 (ops 157-161)
I20260812 06:18:49.910112 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000033 (ops 162-166)
I20260812 06:18:49.910149 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000034 (ops 167-171)
I20260812 06:18:49.910219 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000035 (ops 172-176)
I20260812 06:18:49.910295 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000036 (ops 177-181)
I20260812 06:18:49.910331 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000037 (ops 182-186)
I20260812 06:18:49.910352 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000038 (ops 187-191)
I20260812 06:18:49.910404 17129 log.cc:1079] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: Deleting log segment in path: /tmp/dist-test-taskOrZ1T7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518882825-16841-0/minicluster-data/ts-0-root/wals/7baa3dae411547a9be55091f5e990422/wal-000000039 (ops 192-196)
I20260812 06:18:49.940344 16841 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.312s	user 0.002s	sys 0.000s
I20260812 06:18:49.940804 16841 tablet_server.cc:179] TabletServer@127.16.114.65:0 shutting down...
I20260812 06:18:50.384620 17129 maintenance_manager.cc:643] P 583a026cff1044939bc621aaab365509: LogGCOp(7baa3dae411547a9be55091f5e990422) complete. Timing: real 0.475s	user 0.003s	sys 0.026s Metrics: {}
I20260812 06:18:50.385223 16841 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:50.385512 16841 tablet_replica.cc:333] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509: stopping tablet replica
I20260812 06:18:50.385669 16841 raft_consensus.cc:2243] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:50.385866 16841 raft_consensus.cc:2272] T 7baa3dae411547a9be55091f5e990422 P 583a026cff1044939bc621aaab365509 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:50.443121 16841 tablet_server.cc:196] TabletServer@127.16.114.65:0 shutdown complete.
I20260812 06:18:50.445708 16841 master.cc:562] Master@127.16.114.126:43619 shutting down...
I20260812 06:18:50.450938 16841 raft_consensus.cc:2243] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:50.451095 16841 raft_consensus.cc:2272] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:50.451146 16841 tablet_replica.cc:333] T 00000000000000000000000000000000 P afbd08e52c3a43f39b4ec7eca1e15aed: stopping tablet replica
I20260812 06:18:50.463544 16841 master.cc:584] Master@127.16.114.126:43619 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6082 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11762 ms total)

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