[==========] 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:19:54.118007 28855 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.28.45.254:38607
I20260812 06:19:54.118896 28855 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:19:54.119431 28855 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:54.125339 28861 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:54.125375 28855 server_base.cc:1061] running on GCE node
W20260812 06:19:54.125350 28864 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:54.125628 28862 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:54.126070 28855 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:54.126163 28855 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:54.126191 28855 hybrid_clock.cc:648] HybridClock initialized: now 1786515594126189 us; error 0 us; skew 500 ppm
I20260812 06:19:54.127679 28855 webserver.cc:533] Webserver started at http://127.28.45.254:39097/ using document root <none> and password file <none>
I20260812 06:19:54.128140 28855 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:54.128190 28855 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:54.128368 28855 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:54.129885 28855 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/master-0-root/instance:
uuid: "68be863383c546e8b6754a2a407e982b"
format_stamp: "Formatted at 2026-08-12 06:19:54 on dist-test-slave-49h3"
I20260812 06:19:54.132929 28855 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.001s
I20260812 06:19:54.134804 28871 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:54.135685 28855 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:19:54.135792 28855 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/master-0-root
uuid: "68be863383c546e8b6754a2a407e982b"
format_stamp: "Formatted at 2026-08-12 06:19:54 on dist-test-slave-49h3"
I20260812 06:19:54.135871 28855 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:54.187341 28855 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:54.187981 28855 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:19:54.188138 28855 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:54.195170 28936 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.45.254:38607 every 8 connection(s)
I20260812 06:19:54.195185 28855 rpc_server.cc:307] RPC server started. Bound to: 127.28.45.254:38607
I20260812 06:19:54.197359 28937 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:54.202577 28937 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b: Bootstrap starting.
I20260812 06:19:54.204797 28937 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:54.205680 28937 log.cc:826] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:54.207211 28937 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b: No bootstrap required, opened a new log
I20260812 06:19:54.209836 28937 raft_consensus.cc:359] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "68be863383c546e8b6754a2a407e982b" member_type: VOTER }
I20260812 06:19:54.209988 28937 raft_consensus.cc:385] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:54.210042 28937 raft_consensus.cc:740] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 68be863383c546e8b6754a2a407e982b, State: Initialized, Role: FOLLOWER
I20260812 06:19:54.210592 28937 consensus_queue.cc:260] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b [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: "68be863383c546e8b6754a2a407e982b" member_type: VOTER }
I20260812 06:19:54.210731 28937 raft_consensus.cc:399] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:54.210776 28937 raft_consensus.cc:493] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:54.210866 28937 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:54.211521 28937 raft_consensus.cc:515] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "68be863383c546e8b6754a2a407e982b" member_type: VOTER }
I20260812 06:19:54.211885 28937 leader_election.cc:304] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b [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: 68be863383c546e8b6754a2a407e982b; no voters: 
I20260812 06:19:54.212121 28937 leader_election.cc:290] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:54.212234 28942 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:54.212459 28942 raft_consensus.cc:697] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b [term 1 LEADER]: Becoming Leader. State: Replica: 68be863383c546e8b6754a2a407e982b, State: Running, Role: LEADER
I20260812 06:19:54.212795 28942 consensus_queue.cc:237] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b [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: "68be863383c546e8b6754a2a407e982b" member_type: VOTER }
I20260812 06:19:54.213006 28937 sys_catalog.cc:565] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:54.214620 28944 sys_catalog.cc:455] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b [sys.catalog]: SysCatalogTable state changed. Reason: New leader 68be863383c546e8b6754a2a407e982b. Latest consensus state: current_term: 1 leader_uuid: "68be863383c546e8b6754a2a407e982b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "68be863383c546e8b6754a2a407e982b" member_type: VOTER } }
I20260812 06:19:54.214649 28943 sys_catalog.cc:455] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "68be863383c546e8b6754a2a407e982b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "68be863383c546e8b6754a2a407e982b" member_type: VOTER } }
I20260812 06:19:54.214767 28944 sys_catalog.cc:458] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:54.214767 28943 sys_catalog.cc:458] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:54.215165 28958 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:54.215250 28855 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:54.217223 28958 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:54.221154 28958 catalog_manager.cc:1383] Generated new cluster ID: 60cc63350c3c40078544823042dcef4e
I20260812 06:19:54.221215 28958 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:54.247267 28958 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:54.248415 28958 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:54.255266 28958 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b: Generated new TSK 0
I20260812 06:19:54.255913 28958 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:54.280313 28855 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:54.282797 28969 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:54.282833 28966 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:54.282871 28967 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:54.283046 28855 server_base.cc:1061] running on GCE node
I20260812 06:19:54.283208 28855 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:54.283257 28855 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:54.283270 28855 hybrid_clock.cc:648] HybridClock initialized: now 1786515594283271 us; error 0 us; skew 500 ppm
I20260812 06:19:54.284121 28855 webserver.cc:533] Webserver started at http://127.28.45.193:39645/ using document root <none> and password file <none>
I20260812 06:19:54.284288 28855 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:54.284332 28855 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:54.284402 28855 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:54.284744 28855 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/instance:
uuid: "53284355efe4433db646f0c7cbfe1871"
format_stamp: "Formatted at 2026-08-12 06:19:54 on dist-test-slave-49h3"
I20260812 06:19:54.286194 28855 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:54.287082 28974 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:54.287338 28855 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:54.287407 28855 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root
uuid: "53284355efe4433db646f0c7cbfe1871"
format_stamp: "Formatted at 2026-08-12 06:19:54 on dist-test-slave-49h3"
I20260812 06:19:54.287472 28855 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:54.295934 28855 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:54.296285 28855 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:54.296676 28855 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:54.297521 28855 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:54.297570 28855 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:54.297613 28855 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:54.297643 28855 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:54.303916 28855 rpc_server.cc:307] RPC server started. Bound to: 127.28.45.193:38095
I20260812 06:19:54.303960 29059 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.45.193:38095 every 8 connection(s)
I20260812 06:19:54.317162 29060 heartbeater.cc:344] Connected to a master server at 127.28.45.254:38607
I20260812 06:19:54.317371 29060 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:54.317811 29060 heartbeater.cc:507] Master 127.28.45.254:38607 requested a full tablet report, sending...
I20260812 06:19:54.319115 28895 ts_manager.cc:194] Registered new tserver with Master: 53284355efe4433db646f0c7cbfe1871 (127.28.45.193:38095)
I20260812 06:19:54.319939 28855 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015425432s
I20260812 06:19:54.320324 28895 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:51220
I20260812 06:19:54.328327 28895 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:51226:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:54.341336 29008 tablet_service.cc:1511] Processing CreateTablet for tablet a474f97e70614106b565b62c650bf6ef (DEFAULT_TABLE table=heavy-update-compaction-test [id=69b6a76ead02477ebfad50ace4950b2c]), partition=
I20260812 06:19:54.341737 29008 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet a474f97e70614106b565b62c650bf6ef. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:54.343840 29077 tablet_bootstrap.cc:492] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Bootstrap starting.
I20260812 06:19:54.344960 29077 tablet_bootstrap.cc:654] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:54.346598 29077 tablet_bootstrap.cc:492] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: No bootstrap required, opened a new log
I20260812 06:19:54.346711 29077 ts_tablet_manager.cc:1403] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Time spent bootstrapping tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:19:54.347283 29077 raft_consensus.cc:359] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "53284355efe4433db646f0c7cbfe1871" member_type: VOTER last_known_addr { host: "127.28.45.193" port: 38095 } }
I20260812 06:19:54.347410 29077 raft_consensus.cc:385] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:54.347456 29077 raft_consensus.cc:740] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 53284355efe4433db646f0c7cbfe1871, State: Initialized, Role: FOLLOWER
I20260812 06:19:54.347592 29077 consensus_queue.cc:260] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871 [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: "53284355efe4433db646f0c7cbfe1871" member_type: VOTER last_known_addr { host: "127.28.45.193" port: 38095 } }
I20260812 06:19:54.347729 29077 raft_consensus.cc:399] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:54.347784 29077 raft_consensus.cc:493] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:54.347836 29077 raft_consensus.cc:3060] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:54.348764 29077 raft_consensus.cc:515] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "53284355efe4433db646f0c7cbfe1871" member_type: VOTER last_known_addr { host: "127.28.45.193" port: 38095 } }
I20260812 06:19:54.348920 29077 leader_election.cc:304] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871 [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: 53284355efe4433db646f0c7cbfe1871; no voters: 
I20260812 06:19:54.349129 29077 leader_election.cc:290] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:54.349233 29079 raft_consensus.cc:2804] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:54.349439 29079 raft_consensus.cc:697] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871 [term 1 LEADER]: Becoming Leader. State: Replica: 53284355efe4433db646f0c7cbfe1871, State: Running, Role: LEADER
I20260812 06:19:54.349499 29077 ts_tablet_manager.cc:1434] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:19:54.349649 29079 consensus_queue.cc:237] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871 [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: "53284355efe4433db646f0c7cbfe1871" member_type: VOTER last_known_addr { host: "127.28.45.193" port: 38095 } }
I20260812 06:19:54.349725 29060 heartbeater.cc:499] Master 127.28.45.254:38607 was elected leader, sending a full tablet report...
I20260812 06:19:54.352453 28895 catalog_manager.cc:5719] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871 reported cstate change: term changed from 0 to 1, leader changed from <none> to 53284355efe4433db646f0c7cbfe1871 (127.28.45.193). New cstate: current_term: 1 leader_uuid: "53284355efe4433db646f0c7cbfe1871" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "53284355efe4433db646f0c7cbfe1871" member_type: VOTER last_known_addr { host: "127.28.45.193" port: 38095 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:54.416020 28855 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.019s	sys 0.012s
I20260812 06:19:54.555102 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushMRSOp(a474f97e70614106b565b62c650bf6ef): perf score=19.054940
I20260812 06:19:54.717769 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushMRSOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.162s	user 0.134s	sys 0.024s Metrics: {"bytes_written":11979298,"cfile_init":1,"compiler_manager_pool.queue_time_us":225,"delete_count":0,"dirs.queue_time_us":2707,"dirs.run_cpu_time_us":178,"dirs.run_wall_time_us":947,"drs_written":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41751,"lbm_writes_lt_1ms":759,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":329088,"thread_start_us":115,"threads_started":1,"update_count":1460}
I20260812 06:19:54.719087 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling LogGCOp(a474f97e70614106b565b62c650bf6ef): free 20743880 bytes of WAL
I20260812 06:19:54.719448 28982 log_reader.cc:385] T a474f97e70614106b565b62c650bf6ef: removed 2 log segments from log reader
I20260812 06:19:54.719570 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000001 (ops 1-6)
I20260812 06:19:54.719678 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000002 (ops 7-11)
I20260812 06:19:54.725135 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: LogGCOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.006s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:54.725627 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=2.188937
I20260812 06:19:54.745658 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.019s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4020609,"delete_count":0,"lbm_write_time_us":6353,"lbm_writes_lt_1ms":101,"reinsert_count":0,"update_count":490}
I20260812 06:19:54.746142 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling UndoDeltaBlockGCOp(a474f97e70614106b565b62c650bf6ef): 16821647 bytes on disk
I20260812 06:19:54.749387 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: UndoDeltaBlockGCOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:19:54.749843 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:54.888657 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.139s	user 0.092s	sys 0.043s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20303030,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":310,"lbm_read_time_us":8382,"lbm_reads_lt_1ms":450,"lbm_write_time_us":22545,"lbm_writes_lt_1ms":433,"mutex_wait_us":85,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":282,"threads_started":5,"update_count":1950}
I20260812 06:19:54.889176 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=10.126437
I20260812 06:19:54.930007 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.041s	user 0.015s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13613,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:54.930450 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=2.188937
I20260812 06:19:54.940222 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3645,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.940577 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:55.058440 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.118s	user 0.097s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":522,"lbm_read_time_us":7822,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23259,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":630272,"update_count":2000}
I20260812 06:19:55.058943 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=10.126437
I20260812 06:19:55.109251 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.050s	user 0.014s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":25440,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:55.109776 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=2.188937
I20260812 06:19:55.119655 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3733,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.120108 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:55.234941 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.115s	user 0.085s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":234,"lbm_read_time_us":9669,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20149,"lbm_writes_lt_1ms":443,"mutex_wait_us":3,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.235392 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=10.126437
I20260812 06:19:55.278621 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.043s	user 0.023s	sys 0.019s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15619,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:55.279102 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=2.188937
I20260812 06:19:55.288815 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3687,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.289201 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:55.424593 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.135s	user 0.101s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713274,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":637,"lbm_read_time_us":10509,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20877,"lbm_writes_lt_1ms":443,"mutex_wait_us":310,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":742400,"update_count":2000}
I20260812 06:19:55.425211 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=10.126437
I20260812 06:19:55.465381 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.040s	user 0.014s	sys 0.011s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":12238,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:55.465874 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=2.188937
I20260812 06:19:55.475620 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3702,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.476161 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:55.593348 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.117s	user 0.097s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":161,"lbm_read_time_us":9549,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21019,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":39040,"update_count":2000}
I20260812 06:19:55.593819 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=10.126437
I20260812 06:19:55.632556 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.039s	user 0.021s	sys 0.007s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13790,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:55.633021 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=2.188937
I20260812 06:19:55.642618 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3614,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.643006 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:55.760056 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.117s	user 0.100s	sys 0.015s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":160,"lbm_read_time_us":7739,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22393,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.760565 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=10.126437
I20260812 06:19:55.797058 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.036s	user 0.015s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13018,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:55.797562 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=2.188937
I20260812 06:19:55.807041 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3646,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.807437 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:55.917372 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.110s	user 0.089s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1498,"lbm_read_time_us":8317,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20384,"lbm_writes_lt_1ms":443,"mutex_wait_us":472,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.917893 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=10.126437
I20260812 06:19:55.968061 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.050s	user 0.017s	sys 0.030s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18290,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:55.968573 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=2.188937
I20260812 06:19:55.978587 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3744,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.979020 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushMRSOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:56.018625 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushMRSOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.039s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":225,"dirs.run_wall_time_us":1188,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1442,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:56.019611 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling LogGCOp(a474f97e70614106b565b62c650bf6ef): free 133024368 bytes of WAL
I20260812 06:19:56.019860 28982 log_reader.cc:385] T a474f97e70614106b565b62c650bf6ef: removed 13 log segments from log reader
I20260812 06:19:56.019912 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000003 (ops 12-16)
I20260812 06:19:56.019940 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000004 (ops 17-20)
I20260812 06:19:56.019959 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000005 (ops 21-25)
I20260812 06:19:56.019991 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000006 (ops 26-30)
I20260812 06:19:56.020023 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000007 (ops 31-35)
I20260812 06:19:56.020056 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000008 (ops 36-40)
I20260812 06:19:56.020088 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000009 (ops 41-45)
I20260812 06:19:56.020118 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000010 (ops 46-50)
I20260812 06:19:56.020150 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000011 (ops 51-55)
I20260812 06:19:56.020181 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000012 (ops 56-60)
I20260812 06:19:56.020244 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000013 (ops 61-65)
I20260812 06:19:56.020277 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000014 (ops 66-70)
I20260812 06:19:56.020308 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000015 (ops 71-75)
I20260812 06:19:56.047843 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: LogGCOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:56.048259 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=3.181125
I20260812 06:19:56.065241 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.017s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6567,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:56.065676 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=2.188937
I20260812 06:19:56.074615 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.009s	user 0.006s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3215,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:56.075131 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling UndoDeltaBlockGCOp(a474f97e70614106b565b62c650bf6ef): 482 bytes on disk
I20260812 06:19:56.075732 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: UndoDeltaBlockGCOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:19:56.076284 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:56.262409 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.186s	user 0.124s	sys 0.060s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918321,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":627,"lbm_read_time_us":11726,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32169,"lbm_writes_lt_1ms":643,"mutex_wait_us":328,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":70,"threads_started":1,"update_count":3000}
I20260812 06:19:56.262877 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=14.095187
I20260812 06:19:56.301358 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.038s	user 0.027s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":16911,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.301805 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:56.452359 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.150s	user 0.114s	sys 0.033s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713154,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1026,"lbm_read_time_us":11033,"lbm_reads_lt_1ms":467,"lbm_write_time_us":26219,"lbm_writes_lt_1ms":443,"mutex_wait_us":293,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:19:56.453164 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=11.118625
I20260812 06:19:56.483856 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.031s	user 0.021s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12414,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:56.484534 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=2.188937
I20260812 06:19:56.507154 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.022s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4978,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:56.507668 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=2.188937
I20260812 06:19:56.517472 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3690,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.517882 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:56.693461 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.175s	user 0.100s	sys 0.064s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":948,"lbm_read_time_us":11446,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28693,"lbm_writes_lt_1ms":543,"mutex_wait_us":326,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2500}
I20260812 06:19:56.693971 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=14.095187
I20260812 06:19:56.742759 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.049s	user 0.033s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18594,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.743304 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=2.188937
I20260812 06:19:56.753401 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3692,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.753887 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:56.907032 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.153s	user 0.135s	sys 0.017s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":801,"lbm_read_time_us":12058,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29254,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":63104,"update_count":2500}
I20260812 06:19:56.907622 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=10.126437
I20260812 06:19:56.949208 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.041s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15194,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.949717 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=2.188937
I20260812 06:19:56.959549 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3791,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.960114 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:57.080292 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.120s	user 0.084s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":573,"lbm_read_time_us":9400,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21959,"lbm_writes_lt_1ms":443,"mutex_wait_us":68,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":2000}
I20260812 06:19:57.080762 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=10.126437
I20260812 06:19:57.123023 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.042s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15546,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:57.123509 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=2.188937
I20260812 06:19:57.133152 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3664,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.133671 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:57.246701 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.113s	user 0.092s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":606,"lbm_read_time_us":7771,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21452,"lbm_writes_lt_1ms":443,"mutex_wait_us":310,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2000}
I20260812 06:19:57.247175 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=10.126437
I20260812 06:19:57.301851 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.055s	user 0.033s	sys 0.014s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16242,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:57.302387 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=2.188937
I20260812 06:19:57.312304 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3745,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.312785 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushMRSOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:57.341406 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushMRSOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.028s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":221,"dirs.run_wall_time_us":1235,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1269,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:57.342191 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling UndoDeltaBlockGCOp(a474f97e70614106b565b62c650bf6ef): 447 bytes on disk
I20260812 06:19:57.342630 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: UndoDeltaBlockGCOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:19:57.343150 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:57.482290 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.139s	user 0.084s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":878,"lbm_read_time_us":8266,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22021,"lbm_writes_lt_1ms":443,"mutex_wait_us":276,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2000}
I20260812 06:19:57.482873 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling LogGCOp(a474f97e70614106b565b62c650bf6ef): free 115943188 bytes of WAL
I20260812 06:19:57.483070 28982 log_reader.cc:385] T a474f97e70614106b565b62c650bf6ef: removed 11 log segments from log reader
I20260812 06:19:57.483114 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000016 (ops 76-80)
I20260812 06:19:57.483155 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000017 (ops 81-85)
I20260812 06:19:57.483188 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000018 (ops 86-90)
I20260812 06:19:57.483222 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000019 (ops 91-95)
I20260812 06:19:57.483253 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000020 (ops 96-100)
I20260812 06:19:57.483283 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000021 (ops 101-105)
I20260812 06:19:57.483311 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000022 (ops 106-110)
I20260812 06:19:57.483341 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000023 (ops 111-115)
I20260812 06:19:57.483371 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000024 (ops 116-120)
I20260812 06:19:57.483394 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000025 (ops 121-125)
I20260812 06:19:57.483421 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000026 (ops 126-130)
I20260812 06:19:57.506826 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: LogGCOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.024s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:19:57.507306 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=15.087375
I20260812 06:19:57.557989 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.051s	user 0.039s	sys 0.008s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":20672,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:57.558485 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=2.188937
I20260812 06:19:57.582199 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.024s	user 0.009s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6130,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.582599 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=2.188937
I20260812 06:19:57.591538 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.009s	user 0.006s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3348,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:57.591915 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:57.784005 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.192s	user 0.120s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918202,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":200,"lbm_read_time_us":13068,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32886,"lbm_writes_lt_1ms":643,"mutex_wait_us":4,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":3000}
I20260812 06:19:57.784490 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=14.095187
I20260812 06:19:57.839738 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.055s	user 0.036s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18807,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.840281 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=2.188937
I20260812 06:19:57.855026 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5567,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.855469 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:58.027756 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.172s	user 0.099s	sys 0.073s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":186,"lbm_read_time_us":13494,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29147,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:19:58.028447 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=11.118625
I20260812 06:19:58.055814 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.027s	user 0.017s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":11511,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:58.056372 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=2.188937
I20260812 06:19:58.071336 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.015s	user 0.003s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4565,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:58.071799 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:58.196064 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.124s	user 0.090s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713264,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":721,"lbm_read_time_us":7035,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22346,"lbm_writes_lt_1ms":443,"mutex_wait_us":303,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:19:58.196520 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=11.118625
I20260812 06:19:58.224936 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.028s	user 0.021s	sys 0.004s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":11594,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:58.225488 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=2.188937
I20260812 06:19:58.239904 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5296,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:58.240480 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:58.356556 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.116s	user 0.092s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":945,"lbm_read_time_us":9558,"lbm_reads_lt_1ms":472,"lbm_write_time_us":19589,"lbm_writes_lt_1ms":443,"mutex_wait_us":251,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2000}
I20260812 06:19:58.357086 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=10.126437
I20260812 06:19:58.399247 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.042s	user 0.023s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17242,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:58.399781 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=2.188937
I20260812 06:19:58.412847 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5031,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.413292 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:58.535656 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.122s	user 0.094s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":197,"lbm_read_time_us":8870,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23585,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.536231 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=10.126437
I20260812 06:19:58.581866 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.045s	user 0.026s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14556,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:58.582353 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=2.188937
I20260812 06:19:58.592010 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3728,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.592404 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:58.733410 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.141s	user 0.104s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":217,"lbm_read_time_us":10468,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20983,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2000}
I20260812 06:19:58.734097 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=10.126437
I20260812 06:19:58.779065 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.045s	user 0.020s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17327,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:58.779558 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=2.188937
I20260812 06:19:58.794150 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.014s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5307,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.794785 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushMRSOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:58.823375 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushMRSOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.028s	user 0.023s	sys 0.003s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":37,"dirs.run_cpu_time_us":184,"dirs.run_wall_time_us":1057,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1562,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:58.824150 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling LogGCOp(a474f97e70614106b565b62c650bf6ef): free 121459753 bytes of WAL
I20260812 06:19:58.824342 28982 log_reader.cc:385] T a474f97e70614106b565b62c650bf6ef: removed 12 log segments from log reader
I20260812 06:19:58.824380 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000027 (ops 131-135)
I20260812 06:19:58.824411 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000028 (ops 136-140)
I20260812 06:19:58.824486 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000029 (ops 141-145)
I20260812 06:19:58.824514 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000030 (ops 146-150)
I20260812 06:19:58.824558 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000031 (ops 151-155)
I20260812 06:19:58.824587 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000032 (ops 156-160)
I20260812 06:19:58.824628 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000033 (ops 161-165)
I20260812 06:19:58.824657 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000034 (ops 166-170)
I20260812 06:19:58.824713 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000035 (ops 171-175)
I20260812 06:19:58.824744 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000036 (ops 176-180)
I20260812 06:19:58.824765 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000037 (ops 181-185)
I20260812 06:19:58.824815 28982 log.cc:1079] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/a474f97e70614106b565b62c650bf6ef/wal-000000038 (ops 186-190)
I20260812 06:19:58.847000 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: LogGCOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.023s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:19:58.847447 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=3.181125
I20260812 06:19:58.860687 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.013s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4307780,"delete_count":0,"lbm_write_time_us":3882,"lbm_writes_lt_1ms":108,"reinsert_count":0,"update_count":525}
I20260812 06:19:58.861148 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=2.188937
I20260812 06:19:58.877350 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.016s	user 0.009s	sys 0.003s Metrics: {"bytes_written":3897533,"delete_count":0,"lbm_write_time_us":3401,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:19:58.877951 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:59.013145 28855 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.597s	user 1.558s	sys 0.192s
I20260812 06:19:59.053597 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.175s	user 0.099s	sys 0.076s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918329,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":14117,"lbm_reads_lt_1ms":670,"lbm_write_time_us":29818,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:59.054199 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef): perf score=10.126437
I20260812 06:19:59.080011 28855 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.066s	user 0.002s	sys 0.000s
I20260812 06:19:59.080711 28855 tablet_server.cc:179] TabletServer@127.28.45.193:0 shutting down...
I20260812 06:19:59.083436 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: FlushDeltaMemStoresOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.029s	user 0.015s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12152,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:59.083951 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling UndoDeltaBlockGCOp(a474f97e70614106b565b62c650bf6ef): 482 bytes on disk
I20260812 06:19:59.084465 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: UndoDeltaBlockGCOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4}
I20260812 06:19:59.085130 29061 maintenance_manager.cc:419] P 53284355efe4433db646f0c7cbfe1871: Scheduling MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef): perf score=1.000000
I20260812 06:19:59.177258 28982 maintenance_manager.cc:643] P 53284355efe4433db646f0c7cbfe1871: MajorDeltaCompactionOp(a474f97e70614106b565b62c650bf6ef) complete. Timing: real 0.092s	user 0.068s	sys 0.024s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16610741,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":226,"lbm_read_time_us":7069,"lbm_reads_lt_1ms":367,"lbm_write_time_us":15195,"lbm_writes_lt_1ms":343,"mutex_wait_us":37,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":1500}
I20260812 06:19:59.178009 28855 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:59.178426 28855 tablet_replica.cc:333] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871: stopping tablet replica
I20260812 06:19:59.178658 28855 raft_consensus.cc:2243] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:59.178898 28855 raft_consensus.cc:2272] T a474f97e70614106b565b62c650bf6ef P 53284355efe4433db646f0c7cbfe1871 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:59.193883 28855 tablet_server.cc:196] TabletServer@127.28.45.193:0 shutdown complete.
I20260812 06:19:59.211350 28855 master.cc:562] Master@127.28.45.254:38607 shutting down...
I20260812 06:19:59.214424 28855 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:59.214597 28855 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:59.214665 28855 tablet_replica.cc:333] T 00000000000000000000000000000000 P 68be863383c546e8b6754a2a407e982b: stopping tablet replica
I20260812 06:19:59.226523 28855 master.cc:584] Master@127.28.45.254:38607 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5184 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:59.302809 28855 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.28.45.254:43103
I20260812 06:19:59.303185 28855 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:59.305063 29098 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:59.305068 29095 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:59.305078 29096 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:59.305132 28855 server_base.cc:1061] running on GCE node
I20260812 06:19:59.305438 28855 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:59.305508 28855 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:59.305529 28855 hybrid_clock.cc:648] HybridClock initialized: now 1786515599305529 us; error 0 us; skew 500 ppm
I20260812 06:19:59.306264 28855 webserver.cc:533] Webserver started at http://127.28.45.254:34265/ using document root <none> and password file <none>
I20260812 06:19:59.306416 28855 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:59.306461 28855 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:59.306536 28855 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:59.306903 28855 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/master-0-root/instance:
uuid: "608f6493ab914351b32979a3f3a2f582"
format_stamp: "Formatted at 2026-08-12 06:19:59 on dist-test-slave-49h3"
I20260812 06:19:59.308279 28855 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:59.309120 29105 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:59.309366 28855 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:59.309434 28855 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/master-0-root
uuid: "608f6493ab914351b32979a3f3a2f582"
format_stamp: "Formatted at 2026-08-12 06:19:59 on dist-test-slave-49h3"
I20260812 06:19:59.309525 28855 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:59.315613 28855 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:59.315886 28855 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:59.319445 28855 rpc_server.cc:307] RPC server started. Bound to: 127.28.45.254:43103
I20260812 06:19:59.329779 29168 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.45.254:43103 every 8 connection(s)
I20260812 06:19:59.332882 29169 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:59.334576 29169 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582: Bootstrap starting.
I20260812 06:19:59.335287 29169 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:59.336158 29169 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582: No bootstrap required, opened a new log
I20260812 06:19:59.336589 29169 raft_consensus.cc:359] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "608f6493ab914351b32979a3f3a2f582" member_type: VOTER }
I20260812 06:19:59.336673 29169 raft_consensus.cc:385] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:59.336704 29169 raft_consensus.cc:740] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 608f6493ab914351b32979a3f3a2f582, State: Initialized, Role: FOLLOWER
I20260812 06:19:59.336851 29169 consensus_queue.cc:260] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582 [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: "608f6493ab914351b32979a3f3a2f582" member_type: VOTER }
I20260812 06:19:59.336925 29169 raft_consensus.cc:399] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:59.336958 29169 raft_consensus.cc:493] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:59.337007 29169 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:59.337639 29169 raft_consensus.cc:515] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "608f6493ab914351b32979a3f3a2f582" member_type: VOTER }
I20260812 06:19:59.337770 29169 leader_election.cc:304] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582 [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: 608f6493ab914351b32979a3f3a2f582; no voters: 
I20260812 06:19:59.337930 29169 leader_election.cc:290] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:59.338025 29172 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:59.338208 29172 raft_consensus.cc:697] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582 [term 1 LEADER]: Becoming Leader. State: Replica: 608f6493ab914351b32979a3f3a2f582, State: Running, Role: LEADER
I20260812 06:19:59.338357 29169 sys_catalog.cc:565] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:59.338339 29172 consensus_queue.cc:237] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582 [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: "608f6493ab914351b32979a3f3a2f582" member_type: VOTER }
I20260812 06:19:59.338749 29173 sys_catalog.cc:455] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "608f6493ab914351b32979a3f3a2f582" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "608f6493ab914351b32979a3f3a2f582" member_type: VOTER } }
I20260812 06:19:59.338775 29175 sys_catalog.cc:455] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 608f6493ab914351b32979a3f3a2f582. Latest consensus state: current_term: 1 leader_uuid: "608f6493ab914351b32979a3f3a2f582" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "608f6493ab914351b32979a3f3a2f582" member_type: VOTER } }
I20260812 06:19:59.338840 29173 sys_catalog.cc:458] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:59.338858 29175 sys_catalog.cc:458] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:59.339510 29179 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:59.340376 29179 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:59.340539 28855 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:59.342087 29179 catalog_manager.cc:1383] Generated new cluster ID: 043cc2dea714450dbc071012085bb1bb
I20260812 06:19:59.342135 29179 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:59.351835 29179 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:59.352304 29179 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:59.359141 29179 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582: Generated new TSK 0
I20260812 06:19:59.359293 29179 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:59.372668 28855 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:59.374362 29194 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:19:59.374421 29196 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:59.374410 29193 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:59.374492 28855 server_base.cc:1061] running on GCE node
I20260812 06:19:59.374769 28855 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:59.374809 28855 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:59.374828 28855 hybrid_clock.cc:648] HybridClock initialized: now 1786515599374828 us; error 0 us; skew 500 ppm
I20260812 06:19:59.375622 28855 webserver.cc:533] Webserver started at http://127.28.45.193:33189/ using document root <none> and password file <none>
I20260812 06:19:59.375775 28855 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:59.375825 28855 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:59.375900 28855 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:59.376253 28855 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/instance:
uuid: "1b3355beb79c43f9beb052a0a8deeea6"
format_stamp: "Formatted at 2026-08-12 06:19:59 on dist-test-slave-49h3"
I20260812 06:19:59.377621 28855 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:59.378460 29202 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:59.378669 28855 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:59.378732 28855 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root
uuid: "1b3355beb79c43f9beb052a0a8deeea6"
format_stamp: "Formatted at 2026-08-12 06:19:59 on dist-test-slave-49h3"
I20260812 06:19:59.378795 28855 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:59.394953 28855 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:59.395246 28855 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:59.395494 28855 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:59.395891 28855 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:59.395926 28855 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:59.395965 28855 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:59.395992 28855 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:59.399793 28855 rpc_server.cc:307] RPC server started. Bound to: 127.28.45.193:37991
I20260812 06:19:59.399820 29281 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.45.193:37991 every 8 connection(s)
I20260812 06:19:59.406910 29282 heartbeater.cc:344] Connected to a master server at 127.28.45.254:43103
I20260812 06:19:59.407008 29282 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:59.407207 29282 heartbeater.cc:507] Master 127.28.45.254:43103 requested a full tablet report, sending...
I20260812 06:19:59.407876 29127 ts_manager.cc:194] Registered new tserver with Master: 1b3355beb79c43f9beb052a0a8deeea6 (127.28.45.193:37991)
I20260812 06:19:59.408572 29127 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:40472
I20260812 06:19:59.408913 28855 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008758064s
I20260812 06:19:59.415225 29127 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:40486:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:59.423051 29243 tablet_service.cc:1511] Processing CreateTablet for tablet 664e2d66329e417ca12c012af6c219ea (DEFAULT_TABLE table=heavy-update-compaction-test [id=4736f26bf0914884b4f7e8a52f1d9e64]), partition=
I20260812 06:19:59.423295 29243 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 664e2d66329e417ca12c012af6c219ea. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:59.425050 29298 tablet_bootstrap.cc:492] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Bootstrap starting.
I20260812 06:19:59.426018 29298 tablet_bootstrap.cc:654] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:59.426990 29298 tablet_bootstrap.cc:492] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: No bootstrap required, opened a new log
I20260812 06:19:59.427062 29298 ts_tablet_manager.cc:1403] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:19:59.427433 29298 raft_consensus.cc:359] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1b3355beb79c43f9beb052a0a8deeea6" member_type: VOTER last_known_addr { host: "127.28.45.193" port: 37991 } }
I20260812 06:19:59.427515 29298 raft_consensus.cc:385] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:59.427546 29298 raft_consensus.cc:740] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1b3355beb79c43f9beb052a0a8deeea6, State: Initialized, Role: FOLLOWER
I20260812 06:19:59.427680 29298 consensus_queue.cc:260] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6 [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: "1b3355beb79c43f9beb052a0a8deeea6" member_type: VOTER last_known_addr { host: "127.28.45.193" port: 37991 } }
I20260812 06:19:59.427757 29298 raft_consensus.cc:399] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:59.427793 29298 raft_consensus.cc:493] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:59.427840 29298 raft_consensus.cc:3060] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:59.428592 29298 raft_consensus.cc:515] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1b3355beb79c43f9beb052a0a8deeea6" member_type: VOTER last_known_addr { host: "127.28.45.193" port: 37991 } }
I20260812 06:19:59.428743 29298 leader_election.cc:304] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6 [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: 1b3355beb79c43f9beb052a0a8deeea6; no voters: 
I20260812 06:19:59.428928 29298 leader_election.cc:290] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:59.429031 29301 raft_consensus.cc:2804] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:59.429250 29298 ts_tablet_manager.cc:1434] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:59.429283 29301 raft_consensus.cc:697] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6 [term 1 LEADER]: Becoming Leader. State: Replica: 1b3355beb79c43f9beb052a0a8deeea6, State: Running, Role: LEADER
I20260812 06:19:59.429275 29282 heartbeater.cc:499] Master 127.28.45.254:43103 was elected leader, sending a full tablet report...
I20260812 06:19:59.429487 29301 consensus_queue.cc:237] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6 [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: "1b3355beb79c43f9beb052a0a8deeea6" member_type: VOTER last_known_addr { host: "127.28.45.193" port: 37991 } }
I20260812 06:19:59.430721 29127 catalog_manager.cc:5719] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6 reported cstate change: term changed from 0 to 1, leader changed from <none> to 1b3355beb79c43f9beb052a0a8deeea6 (127.28.45.193). New cstate: current_term: 1 leader_uuid: "1b3355beb79c43f9beb052a0a8deeea6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1b3355beb79c43f9beb052a0a8deeea6" member_type: VOTER last_known_addr { host: "127.28.45.193" port: 37991 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:59.482955 28855 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.049s	user 0.013s	sys 0.009s
I20260812 06:19:59.650764 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushMRSOp(664e2d66329e417ca12c012af6c219ea): perf score=23.023690
I20260812 06:19:59.800092 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushMRSOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.149s	user 0.110s	sys 0.036s Metrics: {"bytes_written":13210025,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":38,"dirs.run_cpu_time_us":220,"dirs.run_wall_time_us":773,"drs_written":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38126,"lbm_writes_lt_1ms":879,"mutex_wait_us":136,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1610}
I20260812 06:19:59.800693 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling LogGCOp(664e2d66329e417ca12c012af6c219ea): free 20743880 bytes of WAL
I20260812 06:19:59.800916 29208 log_reader.cc:385] T 664e2d66329e417ca12c012af6c219ea: removed 2 log segments from log reader
I20260812 06:19:59.800963 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000001 (ops 1-6)
I20260812 06:19:59.800992 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000002 (ops 7-11)
I20260812 06:19:59.804502 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: LogGCOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:59.804832 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=2.188937
I20260812 06:19:59.815955 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3610359,"delete_count":0,"lbm_write_time_us":3318,"lbm_writes_lt_1ms":91,"reinsert_count":0,"update_count":440}
I20260812 06:19:59.816419 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=2.188937
I20260812 06:19:59.825099 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.009s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3300,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:59.825399 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea): perf score=1.000000
I20260812 06:19:59.975797 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.150s	user 0.105s	sys 0.045s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815784,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1185,"lbm_read_time_us":11242,"lbm_reads_lt_1ms":573,"lbm_write_time_us":25739,"lbm_writes_lt_1ms":543,"mutex_wait_us":321,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"thread_start_us":267,"threads_started":5,"update_count":2500}
I20260812 06:19:59.976236 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=14.095187
I20260812 06:20:00.023495 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.047s	user 0.036s	sys 0.007s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19641,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.024015 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling UndoDeltaBlockGCOp(664e2d66329e417ca12c012af6c219ea): 20513813 bytes on disk
I20260812 06:20:00.024422 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: UndoDeltaBlockGCOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:20:00.024863 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=2.188937
I20260812 06:20:00.035302 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3651,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.035725 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea): perf score=1.000000
I20260812 06:20:00.197790 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.162s	user 0.117s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":119,"lbm_read_time_us":9660,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29249,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2500}
I20260812 06:20:00.198410 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=14.095187
I20260812 06:20:00.238894 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.040s	user 0.035s	sys 0.004s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17924,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.239439 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea): perf score=1.000000
I20260812 06:20:00.404024 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.164s	user 0.090s	sys 0.065s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713154,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":86,"lbm_read_time_us":12391,"lbm_reads_lt_1ms":467,"lbm_write_time_us":25892,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":56960,"update_count":2000}
I20260812 06:20:00.404554 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=14.095187
I20260812 06:20:00.452266 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.048s	user 0.040s	sys 0.000s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19151,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.452720 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=2.188937
I20260812 06:20:00.463387 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3883,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.463846 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea): perf score=1.000000
I20260812 06:20:00.635718 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.172s	user 0.080s	sys 0.082s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":155,"lbm_read_time_us":12113,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25259,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:20:00.636243 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=14.095187
I20260812 06:20:00.685717 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.049s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19359,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.686205 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=2.188937
I20260812 06:20:00.697960 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4676,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.698613 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea): perf score=1.000000
I20260812 06:20:00.848404 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.150s	user 0.113s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1056,"lbm_read_time_us":10437,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28509,"lbm_writes_lt_1ms":543,"mutex_wait_us":273,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:20:00.848961 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=11.118625
I20260812 06:20:00.879457 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.030s	user 0.017s	sys 0.011s Metrics: {"bytes_written":12717739,"delete_count":0,"lbm_write_time_us":12411,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:00.879900 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=2.188937
I20260812 06:20:00.890803 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3830,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:00.891261 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushMRSOp(664e2d66329e417ca12c012af6c219ea): perf score=1.000000
I20260812 06:20:00.944365 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushMRSOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.053s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":241,"dirs.run_wall_time_us":1263,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1497,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:00.945079 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling LogGCOp(664e2d66329e417ca12c012af6c219ea): free 112239265 bytes of WAL
I20260812 06:20:00.945303 29208 log_reader.cc:385] T 664e2d66329e417ca12c012af6c219ea: removed 11 log segments from log reader
I20260812 06:20:00.945350 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000003 (ops 12-16)
I20260812 06:20:00.945390 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000004 (ops 17-21)
I20260812 06:20:00.945422 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000005 (ops 22-26)
I20260812 06:20:00.945468 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000006 (ops 27-31)
I20260812 06:20:00.945501 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000007 (ops 32-36)
I20260812 06:20:00.945531 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000008 (ops 37-41)
I20260812 06:20:00.945561 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000009 (ops 42-46)
I20260812 06:20:00.945591 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000010 (ops 47-50)
I20260812 06:20:00.945622 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000011 (ops 51-55)
I20260812 06:20:00.945652 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000012 (ops 56-60)
I20260812 06:20:00.945679 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000013 (ops 61-65)
I20260812 06:20:00.968353 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: LogGCOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.023s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:20:00.968771 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=7.149875
I20260812 06:20:01.004073 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.035s	user 0.021s	sys 0.011s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":11109,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:20:01.004557 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling LogGCOp(664e2d66329e417ca12c012af6c219ea): free 8767174 bytes of WAL
I20260812 06:20:01.004750 29208 log_reader.cc:385] T 664e2d66329e417ca12c012af6c219ea: removed 1 log segments from log reader
I20260812 06:20:01.004796 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000014 (ops 66-70)
I20260812 06:20:01.006358 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: LogGCOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:01.006646 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling UndoDeltaBlockGCOp(664e2d66329e417ca12c012af6c219ea): 462 bytes on disk
I20260812 06:20:01.007002 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: UndoDeltaBlockGCOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:20:01.007412 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=2.188937
I20260812 06:20:01.016386 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.009s	user 0.006s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3299,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:01.016739 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea): perf score=1.000000
I20260812 06:20:01.235488 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.219s	user 0.149s	sys 0.068s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020733,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":293,"lbm_read_time_us":15004,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38819,"lbm_writes_lt_1ms":743,"mutex_wait_us":65,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":76,"threads_started":1,"update_count":3500}
I20260812 06:20:01.235984 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=15.087375
I20260812 06:20:01.283567 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.047s	user 0.034s	sys 0.011s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":20417,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:01.284116 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=2.188937
I20260812 06:20:01.297988 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.014s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3966,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:01.298408 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea): perf score=1.000000
I20260812 06:20:01.461437 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.163s	user 0.091s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815670,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":295,"lbm_read_time_us":11674,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27880,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:01.462137 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=14.095187
I20260812 06:20:01.510946 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.049s	user 0.029s	sys 0.018s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17705,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:01.511391 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=2.188937
I20260812 06:20:01.523721 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4226,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.524127 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea): perf score=1.000000
I20260812 06:20:01.690138 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.166s	user 0.106s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":119,"lbm_read_time_us":11592,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26812,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":52608,"update_count":2500}
I20260812 06:20:01.692800 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=14.095187
I20260812 06:20:01.746477 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.053s	user 0.030s	sys 0.022s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18530,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:01.746982 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=2.188937
I20260812 06:20:01.759830 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.013s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4639,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.760332 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea): perf score=1.000000
I20260812 06:20:01.932636 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.172s	user 0.088s	sys 0.080s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":108,"lbm_read_time_us":11928,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27184,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:20:01.933154 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=14.095187
I20260812 06:20:01.979621 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.046s	user 0.035s	sys 0.007s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":19567,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:01.980232 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=2.188937
I20260812 06:20:01.995180 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5616,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.995760 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea): perf score=1.000000
I20260812 06:20:02.171442 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.176s	user 0.112s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815681,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":211,"lbm_read_time_us":11953,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26429,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2500}
I20260812 06:20:02.171887 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=14.095187
I20260812 06:20:02.222908 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.051s	user 0.021s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21455,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.223444 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=2.188937
I20260812 06:20:02.233942 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3733,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.234442 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea): perf score=1.000000
I20260812 06:20:02.377178 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.143s	user 0.112s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":190,"lbm_read_time_us":10921,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27162,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2500}
I20260812 06:20:02.377862 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=11.118625
I20260812 06:20:02.411361 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.033s	user 0.014s	sys 0.017s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13698,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:02.411938 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=2.188937
I20260812 06:20:02.426468 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.014s	user 0.003s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5292,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:02.427007 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushMRSOp(664e2d66329e417ca12c012af6c219ea): perf score=1.000000
I20260812 06:20:02.476145 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushMRSOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.049s	user 0.024s	sys 0.002s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":160,"dirs.run_wall_time_us":1290,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1651,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:02.476826 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling LogGCOp(664e2d66329e417ca12c012af6c219ea): free 132571329 bytes of WAL
I20260812 06:20:02.477057 29208 log_reader.cc:385] T 664e2d66329e417ca12c012af6c219ea: removed 13 log segments from log reader
I20260812 06:20:02.477115 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000015 (ops 71-75)
I20260812 06:20:02.477159 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000016 (ops 76-80)
I20260812 06:20:02.477191 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000017 (ops 81-85)
I20260812 06:20:02.477217 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000018 (ops 86-90)
I20260812 06:20:02.477253 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000019 (ops 91-94)
I20260812 06:20:02.477281 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000020 (ops 95-99)
I20260812 06:20:02.477308 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000021 (ops 100-104)
I20260812 06:20:02.477334 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000022 (ops 105-109)
I20260812 06:20:02.477365 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000023 (ops 110-114)
I20260812 06:20:02.477396 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000024 (ops 115-119)
I20260812 06:20:02.477422 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000025 (ops 120-124)
I20260812 06:20:02.477476 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000026 (ops 125-128)
I20260812 06:20:02.477509 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000027 (ops 129-133)
I20260812 06:20:02.504670 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: LogGCOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:02.505070 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=7.149875
I20260812 06:20:02.537674 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.032s	user 0.025s	sys 0.007s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":8916,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:20:02.538084 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling UndoDeltaBlockGCOp(664e2d66329e417ca12c012af6c219ea): 492 bytes on disk
I20260812 06:20:02.538470 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: UndoDeltaBlockGCOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:20:02.538975 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=2.188937
I20260812 06:20:02.548024 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3391,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:02.548360 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea): perf score=1.000000
I20260812 06:20:02.759270 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.211s	user 0.141s	sys 0.067s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020729,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":78,"lbm_read_time_us":14253,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37230,"lbm_writes_lt_1ms":743,"mutex_wait_us":2,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2304,"thread_start_us":71,"threads_started":1,"update_count":3500}
I20260812 06:20:02.759819 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=15.087375
I20260812 06:20:02.809562 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.048s	user 0.041s	sys 0.008s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":21242,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:02.810097 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=2.188937
I20260812 06:20:02.822499 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3810,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:02.822958 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea): perf score=1.000000
I20260812 06:20:02.995716 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.173s	user 0.124s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815672,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1038,"lbm_read_time_us":13005,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27341,"lbm_writes_lt_1ms":543,"mutex_wait_us":492,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16128,"update_count":2500}
I20260812 06:20:02.996330 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=14.095187
I20260812 06:20:03.046511 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.050s	user 0.030s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":16586,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.047122 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=2.188937
I20260812 06:20:03.062753 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.015s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5889,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.063190 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea): perf score=1.000000
I20260812 06:20:03.232067 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.169s	user 0.111s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":844,"lbm_read_time_us":11099,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25116,"lbm_writes_lt_1ms":543,"mutex_wait_us":256,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2500}
I20260812 06:20:03.232646 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=14.095187
I20260812 06:20:03.288053 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.055s	user 0.035s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18909,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.288614 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=2.188937
I20260812 06:20:03.298568 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3747,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.299044 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea): perf score=1.000000
I20260812 06:20:03.475919 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.177s	user 0.103s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":744,"lbm_read_time_us":11923,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26647,"lbm_writes_lt_1ms":543,"mutex_wait_us":282,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:20:03.476435 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=14.095187
I20260812 06:20:03.527086 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.050s	user 0.026s	sys 0.021s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":21425,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.527578 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=2.188937
I20260812 06:20:03.537667 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3604,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.538218 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea): perf score=1.000000
I20260812 06:20:03.730255 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.191s	user 0.138s	sys 0.042s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815681,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":230,"lbm_read_time_us":11946,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29466,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2500}
I20260812 06:20:03.730849 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=14.095187
I20260812 06:20:03.775046 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.044s	user 0.015s	sys 0.022s Metrics: {"bytes_written":16409907,"delete_count":0,"lbm_write_time_us":16707,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.775566 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=2.188937
I20260812 06:20:03.787066 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4215,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.787648 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea): perf score=1.000000
I20260812 06:20:03.942389 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.154s	user 0.115s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":172,"lbm_read_time_us":9393,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28114,"lbm_writes_lt_1ms":543,"mutex_wait_us":18,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2500}
I20260812 06:20:03.943014 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=14.095187
I20260812 06:20:03.989856 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.047s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19236,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.990338 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=2.188937
I20260812 06:20:04.002151 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4461,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.002615 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushMRSOp(664e2d66329e417ca12c012af6c219ea): perf score=1.000000
I20260812 06:20:04.035293 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushMRSOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.033s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":207,"dirs.run_wall_time_us":1243,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1611,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:04.036055 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling LogGCOp(664e2d66329e417ca12c012af6c219ea): free 133024646 bytes of WAL
I20260812 06:20:04.036298 29208 log_reader.cc:385] T 664e2d66329e417ca12c012af6c219ea: removed 13 log segments from log reader
I20260812 06:20:04.036346 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000028 (ops 134-138)
I20260812 06:20:04.036440 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000029 (ops 139-142)
I20260812 06:20:04.036480 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000030 (ops 143-147)
I20260812 06:20:04.036502 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000031 (ops 148-152)
I20260812 06:20:04.036531 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000032 (ops 153-157)
I20260812 06:20:04.036592 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000033 (ops 158-162)
I20260812 06:20:04.036631 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000034 (ops 163-167)
I20260812 06:20:04.036684 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000035 (ops 168-172)
I20260812 06:20:04.036716 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000036 (ops 173-177)
I20260812 06:20:04.036777 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000037 (ops 178-182)
I20260812 06:20:04.036814 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000038 (ops 183-187)
I20260812 06:20:04.036870 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000039 (ops 188-192)
I20260812 06:20:04.036901 29208 log.cc:1079] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: Deleting log segment in path: /tmp/dist-test-taskPOXk_9/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515594107957-28855-0/minicluster-data/ts-0-root/wals/664e2d66329e417ca12c012af6c219ea/wal-000000040 (ops 193-197)
I20260812 06:20:04.063459 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: LogGCOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:04.063946 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling UndoDeltaBlockGCOp(664e2d66329e417ca12c012af6c219ea): 493 bytes on disk
I20260812 06:20:04.064363 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: UndoDeltaBlockGCOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:20:04.064980 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea): perf score=6.157687
I20260812 06:20:04.067770 28855 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.585s	user 1.644s	sys 0.183s
I20260812 06:20:04.080799 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: FlushDeltaMemStoresOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":7507665,"delete_count":0,"lbm_write_time_us":6849,"lbm_writes_lt_1ms":186,"reinsert_count":0,"update_count":915}
I20260812 06:20:04.081167 29283 maintenance_manager.cc:419] P 1b3355beb79c43f9beb052a0a8deeea6: Scheduling MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea): perf score=1.000000
I20260812 06:20:04.124789 28855 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.057s	user 0.000s	sys 0.000s
I20260812 06:20:04.125387 28855 tablet_server.cc:179] TabletServer@127.28.45.193:0 shutting down...
I20260812 06:20:04.225921 29208 maintenance_manager.cc:643] P 1b3355beb79c43f9beb052a0a8deeea6: MajorDeltaCompactionOp(664e2d66329e417ca12c012af6c219ea) complete. Timing: real 0.145s	user 0.103s	sys 0.040s Metrics: {"cfile_cache_hit":402,"cfile_cache_hit_bytes":16411199,"cfile_cache_miss":314,"cfile_cache_miss_bytes":15912016,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":756,"lbm_read_time_us":5884,"lbm_reads_lt_1ms":346,"lbm_write_time_us":30724,"lbm_writes_lt_1ms":726,"mutex_wait_us":293,"peak_mem_usage":85190681,"reinsert_count":0,"spinlock_wait_cycles":6784,"thread_start_us":71,"threads_started":1,"update_count":3415}
I20260812 06:20:04.227699 28855 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:04.227928 28855 tablet_replica.cc:333] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6: stopping tablet replica
I20260812 06:20:04.228083 28855 raft_consensus.cc:2243] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:04.228256 28855 raft_consensus.cc:2272] T 664e2d66329e417ca12c012af6c219ea P 1b3355beb79c43f9beb052a0a8deeea6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:04.241814 28855 tablet_server.cc:196] TabletServer@127.28.45.193:0 shutdown complete.
I20260812 06:20:04.281404 28855 master.cc:562] Master@127.28.45.254:43103 shutting down...
I20260812 06:20:04.284363 28855 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:04.284523 28855 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:04.284572 28855 tablet_replica.cc:333] T 00000000000000000000000000000000 P 608f6493ab914351b32979a3f3a2f582: stopping tablet replica
I20260812 06:20:04.296530 28855 master.cc:584] Master@127.28.45.254:43103 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5065 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10251 ms total)

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