[==========] 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:49.995735 10282 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.10.190:38481
I20260812 06:19:49.996655 10282 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:49.997220 10282 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:50.003459 10289 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:50.003508 10294 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:50.003484 10282 server_base.cc:1061] running on GCE node
W20260812 06:19:50.003703 10290 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:50.004181 10282 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:50.004292 10282 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:50.004333 10282 hybrid_clock.cc:648] HybridClock initialized: now 1786515590004331 us; error 0 us; skew 500 ppm
I20260812 06:19:50.006065 10282 webserver.cc:533] Webserver started at http://127.10.10.190:34655/ using document root <none> and password file <none>
I20260812 06:19:50.006595 10282 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:50.006659 10282 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:50.006875 10282 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:50.008428 10282 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/master-0-root/instance:
uuid: "a6f46724183e4a68b93255c6df963908"
format_stamp: "Formatted at 2026-08-12 06:19:50 on dist-test-slave-bqcl"
I20260812 06:19:50.011729 10282 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:19:50.013638 10302 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:50.014676 10282 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:50.014793 10282 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/master-0-root
uuid: "a6f46724183e4a68b93255c6df963908"
format_stamp: "Formatted at 2026-08-12 06:19:50 on dist-test-slave-bqcl"
I20260812 06:19:50.014887 10282 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-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:50.036973 10282 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:50.037542 10282 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:50.037703 10282 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:50.045111 10282 rpc_server.cc:307] RPC server started. Bound to: 127.10.10.190:38481
I20260812 06:19:50.045138 10388 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.10.190:38481 every 8 connection(s)
I20260812 06:19:50.047252 10389 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:50.052398 10389 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908: Bootstrap starting.
I20260812 06:19:50.054634 10389 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:50.055476 10389 log.cc:826] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:50.057075 10389 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908: No bootstrap required, opened a new log
I20260812 06:19:50.059716 10389 raft_consensus.cc:359] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a6f46724183e4a68b93255c6df963908" member_type: VOTER }
I20260812 06:19:50.059873 10389 raft_consensus.cc:385] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:50.059912 10389 raft_consensus.cc:740] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a6f46724183e4a68b93255c6df963908, State: Initialized, Role: FOLLOWER
I20260812 06:19:50.060426 10389 consensus_queue.cc:260] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908 [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: "a6f46724183e4a68b93255c6df963908" member_type: VOTER }
I20260812 06:19:50.060565 10389 raft_consensus.cc:399] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:50.060611 10389 raft_consensus.cc:493] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:50.060695 10389 raft_consensus.cc:3060] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:50.061394 10389 raft_consensus.cc:515] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a6f46724183e4a68b93255c6df963908" member_type: VOTER }
I20260812 06:19:50.061764 10389 leader_election.cc:304] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908 [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: a6f46724183e4a68b93255c6df963908; no voters: 
I20260812 06:19:50.062052 10389 leader_election.cc:290] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:50.062170 10396 raft_consensus.cc:2804] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:50.062386 10396 raft_consensus.cc:697] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908 [term 1 LEADER]: Becoming Leader. State: Replica: a6f46724183e4a68b93255c6df963908, State: Running, Role: LEADER
I20260812 06:19:50.062794 10396 consensus_queue.cc:237] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908 [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: "a6f46724183e4a68b93255c6df963908" member_type: VOTER }
I20260812 06:19:50.062978 10389 sys_catalog.cc:565] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:50.064512 10398 sys_catalog.cc:455] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "a6f46724183e4a68b93255c6df963908" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a6f46724183e4a68b93255c6df963908" member_type: VOTER } }
I20260812 06:19:50.064498 10399 sys_catalog.cc:455] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908 [sys.catalog]: SysCatalogTable state changed. Reason: New leader a6f46724183e4a68b93255c6df963908. Latest consensus state: current_term: 1 leader_uuid: "a6f46724183e4a68b93255c6df963908" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a6f46724183e4a68b93255c6df963908" member_type: VOTER } }
I20260812 06:19:50.064633 10398 sys_catalog.cc:458] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:50.064633 10399 sys_catalog.cc:458] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:50.064970 10420 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:50.065140 10282 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:50.067186 10420 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:50.071106 10420 catalog_manager.cc:1383] Generated new cluster ID: 3f6565136c8d4df3916ddece5b403112
I20260812 06:19:50.071171 10420 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:50.077121 10420 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:50.077841 10420 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:50.084358 10420 catalog_manager.cc:6092] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908: Generated new TSK 0
I20260812 06:19:50.084879 10420 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:50.097584 10282 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:50.100368 10432 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:50.100412 10282 server_base.cc:1061] running on GCE node
W20260812 06:19:50.100471 10436 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:50.100368 10431 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:50.100755 10282 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:50.100811 10282 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:50.100831 10282 hybrid_clock.cc:648] HybridClock initialized: now 1786515590100831 us; error 0 us; skew 500 ppm
I20260812 06:19:50.101763 10282 webserver.cc:533] Webserver started at http://127.10.10.129:44273/ using document root <none> and password file <none>
I20260812 06:19:50.101917 10282 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:50.101969 10282 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:50.102049 10282 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:50.102458 10282 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/instance:
uuid: "da40ed74749d4cdba248bca60eb27b6c"
format_stamp: "Formatted at 2026-08-12 06:19:50 on dist-test-slave-bqcl"
I20260812 06:19:50.104132 10282 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:50.105113 10450 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:50.105376 10282 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:50.105451 10282 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root
uuid: "da40ed74749d4cdba248bca60eb27b6c"
format_stamp: "Formatted at 2026-08-12 06:19:50 on dist-test-slave-bqcl"
I20260812 06:19:50.105515 10282 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-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:50.116031 10282 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:50.116427 10282 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:50.116876 10282 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:50.118208 10282 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:50.118274 10282 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:50.118328 10282 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:50.118357 10282 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:50.124812 10282 rpc_server.cc:307] RPC server started. Bound to: 127.10.10.129:36233
I20260812 06:19:50.124874 10559 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.10.129:36233 every 8 connection(s)
I20260812 06:19:50.134363 10561 heartbeater.cc:344] Connected to a master server at 127.10.10.190:38481
I20260812 06:19:50.134573 10561 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:50.134941 10561 heartbeater.cc:507] Master 127.10.10.190:38481 requested a full tablet report, sending...
I20260812 06:19:50.136188 10335 ts_manager.cc:194] Registered new tserver with Master: da40ed74749d4cdba248bca60eb27b6c (127.10.10.129:36233)
I20260812 06:19:50.136632 10282 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011138507s
I20260812 06:19:50.137533 10335 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:53726
I20260812 06:19:50.145651 10335 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:53734:
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:50.159723 10488 tablet_service.cc:1511] Processing CreateTablet for tablet 2ba4afe0024c46b5919cfe909ccab427 (DEFAULT_TABLE table=heavy-update-compaction-test [id=f421208ac3bf4e1ea92b5e8b9d9bcfc8]), partition=
I20260812 06:19:50.160110 10488 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 2ba4afe0024c46b5919cfe909ccab427. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:50.162089 10584 tablet_bootstrap.cc:492] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Bootstrap starting.
I20260812 06:19:50.163115 10584 tablet_bootstrap.cc:654] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:50.164137 10584 tablet_bootstrap.cc:492] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: No bootstrap required, opened a new log
I20260812 06:19:50.164235 10584 ts_tablet_manager.cc:1403] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:50.164618 10584 raft_consensus.cc:359] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "da40ed74749d4cdba248bca60eb27b6c" member_type: VOTER last_known_addr { host: "127.10.10.129" port: 36233 } }
I20260812 06:19:50.164717 10584 raft_consensus.cc:385] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:50.164750 10584 raft_consensus.cc:740] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: da40ed74749d4cdba248bca60eb27b6c, State: Initialized, Role: FOLLOWER
I20260812 06:19:50.164909 10584 consensus_queue.cc:260] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c [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: "da40ed74749d4cdba248bca60eb27b6c" member_type: VOTER last_known_addr { host: "127.10.10.129" port: 36233 } }
I20260812 06:19:50.165005 10584 raft_consensus.cc:399] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:50.165048 10584 raft_consensus.cc:493] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:50.165096 10584 raft_consensus.cc:3060] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:50.165782 10584 raft_consensus.cc:515] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "da40ed74749d4cdba248bca60eb27b6c" member_type: VOTER last_known_addr { host: "127.10.10.129" port: 36233 } }
I20260812 06:19:50.165907 10584 leader_election.cc:304] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c [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: da40ed74749d4cdba248bca60eb27b6c; no voters: 
I20260812 06:19:50.166090 10584 leader_election.cc:290] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:50.166260 10589 raft_consensus.cc:2804] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:50.166462 10589 raft_consensus.cc:697] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c [term 1 LEADER]: Becoming Leader. State: Replica: da40ed74749d4cdba248bca60eb27b6c, State: Running, Role: LEADER
I20260812 06:19:50.166513 10584 ts_tablet_manager.cc:1434] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:50.166997 10561 heartbeater.cc:499] Master 127.10.10.190:38481 was elected leader, sending a full tablet report...
I20260812 06:19:50.167114 10589 consensus_queue.cc:237] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c [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: "da40ed74749d4cdba248bca60eb27b6c" member_type: VOTER last_known_addr { host: "127.10.10.129" port: 36233 } }
I20260812 06:19:50.169497 10335 catalog_manager.cc:5719] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c reported cstate change: term changed from 0 to 1, leader changed from <none> to da40ed74749d4cdba248bca60eb27b6c (127.10.10.129). New cstate: current_term: 1 leader_uuid: "da40ed74749d4cdba248bca60eb27b6c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "da40ed74749d4cdba248bca60eb27b6c" member_type: VOTER last_known_addr { host: "127.10.10.129" port: 36233 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:50.244212 10282 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.065s	user 0.015s	sys 0.017s
I20260812 06:19:50.376031 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushMRSOp(2ba4afe0024c46b5919cfe909ccab427): perf score=19.054940
I20260812 06:19:50.522109 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushMRSOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.146s	user 0.102s	sys 0.039s Metrics: {"bytes_written":12307489,"cfile_init":1,"compiler_manager_pool.queue_time_us":333,"delete_count":0,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":197,"dirs.run_wall_time_us":758,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36973,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":156,"threads_started":1,"update_count":1500}
I20260812 06:19:50.523377 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:50.631523 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.108s	user 0.094s	sys 0.012s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569745,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":448,"lbm_read_time_us":7059,"lbm_reads_lt_1ms":363,"lbm_write_time_us":18160,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"thread_start_us":274,"threads_started":5,"update_count":1500}
I20260812 06:19:50.631956 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling LogGCOp(2ba4afe0024c46b5919cfe909ccab427): free 20743880 bytes of WAL
I20260812 06:19:50.632200 10457 log_reader.cc:385] T 2ba4afe0024c46b5919cfe909ccab427: removed 2 log segments from log reader
I20260812 06:19:50.632256 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000001 (ops 1-6)
I20260812 06:19:50.632313 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000002 (ops 7-11)
I20260812 06:19:50.637315 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: LogGCOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:50.637637 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling UndoDeltaBlockGCOp(2ba4afe0024c46b5919cfe909ccab427): 16411392 bytes on disk
I20260812 06:19:50.638051 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: UndoDeltaBlockGCOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4}
I20260812 06:19:50.638437 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=10.126437
I20260812 06:19:50.672952 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.034s	user 0.027s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13560,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:50.673406 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=2.188937
I20260812 06:19:50.683048 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3566,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.683480 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:50.803977 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.120s	user 0.093s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":649,"lbm_read_time_us":8616,"lbm_reads_lt_1ms":472,"lbm_write_time_us":19823,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:50.804468 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=10.126437
I20260812 06:19:50.852619 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.048s	user 0.015s	sys 0.028s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":20148,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:50.853055 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:50.963621 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.110s	user 0.079s	sys 0.031s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569745,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":236,"lbm_read_time_us":7591,"lbm_reads_lt_1ms":363,"lbm_write_time_us":15653,"lbm_writes_lt_1ms":343,"mutex_wait_us":49,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":1500}
I20260812 06:19:50.964113 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=10.126437
I20260812 06:19:51.005600 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.040s	user 0.013s	sys 0.024s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17421,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.006155 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=2.188937
I20260812 06:19:51.017247 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4368,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.017822 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:51.139454 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.121s	user 0.093s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":860,"lbm_read_time_us":8879,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21576,"lbm_writes_lt_1ms":443,"mutex_wait_us":281,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16384,"update_count":2000}
I20260812 06:19:51.139963 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=10.126437
I20260812 06:19:51.181398 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.041s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":20605,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.181918 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=2.188937
I20260812 06:19:51.192515 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4153,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.192962 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:51.310601 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.117s	user 0.098s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":598,"lbm_read_time_us":8102,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22980,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:51.311041 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=10.126437
I20260812 06:19:51.353611 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.042s	user 0.024s	sys 0.014s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13344,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.354168 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=2.188937
I20260812 06:19:51.363736 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3695,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.364135 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:51.502672 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.138s	user 0.102s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":551,"lbm_read_time_us":10809,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21841,"lbm_writes_lt_1ms":443,"mutex_wait_us":257,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:51.503299 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=10.126437
I20260812 06:19:51.544312 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.041s	user 0.025s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13142,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.544731 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=2.188937
I20260812 06:19:51.554551 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3741,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.554953 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:51.667950 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.113s	user 0.088s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":114,"lbm_read_time_us":7677,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20119,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:51.668480 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=10.126437
I20260812 06:19:51.707520 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.039s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18136,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.708076 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=2.188937
I20260812 06:19:51.720789 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4834,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.721280 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushMRSOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:51.750617 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushMRSOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.029s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":224,"dirs.run_wall_time_us":1290,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1648,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:51.751391 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling LogGCOp(2ba4afe0024c46b5919cfe909ccab427): free 121006433 bytes of WAL
I20260812 06:19:51.751636 10457 log_reader.cc:385] T 2ba4afe0024c46b5919cfe909ccab427: removed 12 log segments from log reader
I20260812 06:19:51.751690 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000003 (ops 12-16)
I20260812 06:19:51.751722 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000004 (ops 17-21)
I20260812 06:19:51.751763 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000005 (ops 22-26)
I20260812 06:19:51.751803 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000006 (ops 27-31)
I20260812 06:19:51.751828 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000007 (ops 32-36)
I20260812 06:19:51.751855 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000008 (ops 37-41)
I20260812 06:19:51.751892 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000009 (ops 42-46)
I20260812 06:19:51.751922 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000010 (ops 47-51)
I20260812 06:19:51.751958 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000011 (ops 52-56)
I20260812 06:19:51.752004 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000012 (ops 57-60)
I20260812 06:19:51.752043 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000013 (ops 61-65)
I20260812 06:19:51.752081 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000014 (ops 66-70)
I20260812 06:19:51.774267 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: LogGCOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.023s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:51.774859 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling UndoDeltaBlockGCOp(2ba4afe0024c46b5919cfe909ccab427): 482 bytes on disk
I20260812 06:19:51.775499 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: UndoDeltaBlockGCOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:19:51.776062 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=5.165500
I20260812 06:19:51.791782 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":6687183,"delete_count":0,"lbm_write_time_us":6392,"lbm_writes_lt_1ms":166,"reinsert_count":0,"update_count":815}
I20260812 06:19:51.792313 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:51.803282 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.011s	user 0.003s	sys 0.004s Metrics: {"bytes_written":1518077,"delete_count":0,"lbm_write_time_us":2342,"lbm_writes_lt_1ms":40,"reinsert_count":0,"update_count":185}
I20260812 06:19:51.803723 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:51.964596 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.161s	user 0.132s	sys 0.026s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877276,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1454,"lbm_read_time_us":11718,"lbm_reads_lt_1ms":670,"lbm_write_time_us":31343,"lbm_writes_lt_1ms":643,"mutex_wait_us":725,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":30976,"thread_start_us":88,"threads_started":1,"update_count":3000}
I20260812 06:19:51.965078 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=14.095187
I20260812 06:19:52.013422 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.048s	user 0.036s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20239,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:52.013871 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=2.188937
I20260812 06:19:52.023610 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3785,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.024113 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:52.170677 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.146s	user 0.102s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":164,"lbm_read_time_us":9196,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26024,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2500}
I20260812 06:19:52.171168 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=14.095187
I20260812 06:19:52.213534 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.042s	user 0.020s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17695,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:52.214000 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:52.352344 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.138s	user 0.098s	sys 0.033s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":91,"lbm_read_time_us":9007,"lbm_reads_lt_1ms":463,"lbm_write_time_us":21881,"lbm_writes_lt_1ms":443,"mutex_wait_us":35,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:52.352844 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=14.095187
I20260812 06:19:52.394634 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.042s	user 0.018s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16694,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:52.395102 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=2.188937
I20260812 06:19:52.405383 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3877,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.405980 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:52.572115 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.166s	user 0.109s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":313,"lbm_read_time_us":9978,"lbm_reads_lt_1ms":572,"lbm_write_time_us":23744,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:52.572880 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=14.095187
I20260812 06:19:52.617017 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.044s	user 0.025s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19464,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:52.617522 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=2.188937
I20260812 06:19:52.632893 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5758,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.633381 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:52.778182 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.145s	user 0.115s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":209,"lbm_read_time_us":10229,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26441,"lbm_writes_lt_1ms":543,"mutex_wait_us":17,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:19:52.778697 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=11.118625
I20260812 06:19:52.812848 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.034s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14069,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:52.813284 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=2.188937
I20260812 06:19:52.825344 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4485,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:52.825883 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:52.944639 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.119s	user 0.094s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":447,"lbm_read_time_us":7400,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21870,"lbm_writes_lt_1ms":443,"mutex_wait_us":312,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":118400,"update_count":2000}
I20260812 06:19:52.945309 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=10.126437
I20260812 06:19:52.984928 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.039s	user 0.027s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15483,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:52.985507 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=2.188937
I20260812 06:19:52.999918 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5030,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.000463 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushMRSOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:53.026844 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushMRSOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.026s	user 0.022s	sys 0.004s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":199,"dirs.run_wall_time_us":1207,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1378,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:53.027593 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling LogGCOp(2ba4afe0024c46b5919cfe909ccab427): free 124257201 bytes of WAL
I20260812 06:19:53.027817 10457 log_reader.cc:385] T 2ba4afe0024c46b5919cfe909ccab427: removed 12 log segments from log reader
I20260812 06:19:53.027874 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000015 (ops 71-75)
I20260812 06:19:53.027915 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000016 (ops 76-80)
I20260812 06:19:53.027951 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000017 (ops 81-85)
I20260812 06:19:53.027972 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000018 (ops 86-90)
I20260812 06:19:53.027999 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000019 (ops 91-95)
I20260812 06:19:53.028025 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000020 (ops 96-100)
I20260812 06:19:53.028045 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000021 (ops 101-105)
I20260812 06:19:53.028075 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000022 (ops 106-110)
I20260812 06:19:53.028107 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000023 (ops 111-115)
I20260812 06:19:53.028134 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000024 (ops 116-120)
I20260812 06:19:53.028162 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000025 (ops 121-124)
I20260812 06:19:53.028188 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000026 (ops 125-129)
I20260812 06:19:53.053001 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: LogGCOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:19:53.053351 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=3.181125
I20260812 06:19:53.068216 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.015s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4029,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:53.068665 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling UndoDeltaBlockGCOp(2ba4afe0024c46b5919cfe909ccab427): 447 bytes on disk
I20260812 06:19:53.069092 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: UndoDeltaBlockGCOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:19:53.069583 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=2.188937
I20260812 06:19:53.084017 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4952,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:53.084460 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:53.237246 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.153s	user 0.112s	sys 0.040s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":818,"lbm_read_time_us":10473,"lbm_reads_lt_1ms":674,"lbm_write_time_us":29366,"lbm_writes_lt_1ms":643,"mutex_wait_us":64,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":73,"threads_started":1,"update_count":3000}
I20260812 06:19:53.238755 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=14.095187
I20260812 06:19:53.282265 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.043s	user 0.021s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17881,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:53.282783 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=2.188937
I20260812 06:19:53.292493 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3860,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.292956 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:53.436818 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.144s	user 0.119s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1024,"lbm_read_time_us":11027,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25016,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":385920,"update_count":2500}
I20260812 06:19:53.437418 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=12.110812
I20260812 06:19:53.472482 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.035s	user 0.024s	sys 0.009s Metrics: {"bytes_written":13866408,"delete_count":0,"lbm_write_time_us":15223,"lbm_writes_lt_1ms":341,"reinsert_count":0,"update_count":1690}
I20260812 06:19:53.473042 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.196750
I20260812 06:19:53.487569 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.014s	user 0.009s	sys 0.000s Metrics: {"bytes_written":2543704,"delete_count":0,"lbm_write_time_us":3796,"lbm_writes_lt_1ms":65,"reinsert_count":0,"update_count":310}
I20260812 06:19:53.488104 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:53.638248 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.150s	user 0.115s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672240,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":765,"lbm_read_time_us":9900,"lbm_reads_lt_1ms":464,"lbm_write_time_us":20865,"lbm_writes_lt_1ms":443,"mutex_wait_us":18,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2000}
I20260812 06:19:53.638940 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=14.095187
I20260812 06:19:53.687742 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.049s	user 0.031s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19812,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:53.688299 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=2.188937
I20260812 06:19:53.704921 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3966,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.705368 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:53.881161 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.176s	user 0.122s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":347,"lbm_read_time_us":11051,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27402,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":2500}
I20260812 06:19:53.881623 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=14.095187
I20260812 06:19:53.933328 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.052s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24775,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:53.933866 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=2.188937
I20260812 06:19:53.951180 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.017s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6165,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.951633 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:54.115255 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.163s	user 0.097s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":882,"lbm_read_time_us":10313,"lbm_reads_lt_1ms":568,"lbm_write_time_us":24011,"lbm_writes_lt_1ms":543,"mutex_wait_us":240,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:19:54.115793 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=14.095187
I20260812 06:19:54.161319 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.045s	user 0.031s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19762,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.161875 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=2.188937
I20260812 06:19:54.172618 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3922,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.174901 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:54.319073 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.144s	user 0.111s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":231,"lbm_read_time_us":9909,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26830,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2500}
I20260812 06:19:54.319613 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=14.095187
I20260812 06:19:54.367087 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.047s	user 0.022s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19998,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.367520 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=2.188937
I20260812 06:19:54.377053 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3708,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.377707 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushMRSOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:54.410238 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushMRSOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.032s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":44,"dirs.run_cpu_time_us":190,"dirs.run_wall_time_us":1140,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1351,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:54.410966 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling LogGCOp(2ba4afe0024c46b5919cfe909ccab427): free 124257567 bytes of WAL
I20260812 06:19:54.411206 10457 log_reader.cc:385] T 2ba4afe0024c46b5919cfe909ccab427: removed 12 log segments from log reader
I20260812 06:19:54.411257 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000027 (ops 130-134)
I20260812 06:19:54.411293 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000028 (ops 135-139)
I20260812 06:19:54.411324 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000029 (ops 140-144)
I20260812 06:19:54.411355 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000030 (ops 145-149)
I20260812 06:19:54.411381 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000031 (ops 150-154)
I20260812 06:19:54.411409 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000032 (ops 155-159)
I20260812 06:19:54.411440 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000033 (ops 160-164)
I20260812 06:19:54.411469 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000034 (ops 165-169)
I20260812 06:19:54.411525 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000035 (ops 170-174)
I20260812 06:19:54.411558 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000036 (ops 175-178)
I20260812 06:19:54.411583 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000037 (ops 179-183)
I20260812 06:19:54.411612 10457 log.cc:1079] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/2ba4afe0024c46b5919cfe909ccab427/wal-000000038 (ops 184-188)
I20260812 06:19:54.431798 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: LogGCOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.021s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:19:54.432233 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=3.181125
I20260812 06:19:54.448659 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6786,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:54.449043 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling UndoDeltaBlockGCOp(2ba4afe0024c46b5919cfe909ccab427): 483 bytes on disk
I20260812 06:19:54.449383 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: UndoDeltaBlockGCOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:19:54.449857 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=2.188937
I20260812 06:19:54.466102 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3264,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:54.466549 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:54.662392 10282 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.418s	user 1.635s	sys 0.132s
I20260812 06:19:54.681625 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.215s	user 0.126s	sys 0.086s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979738,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":15901,"lbm_reads_lt_1ms":770,"lbm_write_time_us":35099,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":3500}
I20260812 06:19:54.682184 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427): perf score=14.095187
I20260812 06:19:54.732887 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: FlushDeltaMemStoresOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.051s	user 0.037s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22172,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.733543 10562 maintenance_manager.cc:419] P da40ed74749d4cdba248bca60eb27b6c: Scheduling MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427): perf score=1.000000
I20260812 06:19:54.772599 10282 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.110s	user 0.002s	sys 0.000s
I20260812 06:19:54.773219 10282 tablet_server.cc:179] TabletServer@127.10.10.129:0 shutting down...
I20260812 06:19:54.863047 10457 maintenance_manager.cc:643] P da40ed74749d4cdba248bca60eb27b6c: MajorDeltaCompactionOp(2ba4afe0024c46b5919cfe909ccab427) complete. Timing: real 0.129s	user 0.075s	sys 0.053s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672156,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":225,"lbm_read_time_us":8823,"lbm_reads_lt_1ms":467,"lbm_write_time_us":19393,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":66,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":29184,"update_count":2000}
I20260812 06:19:54.863746 10282 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:54.864140 10282 tablet_replica.cc:333] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c: stopping tablet replica
I20260812 06:19:54.864372 10282 raft_consensus.cc:2243] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:54.864635 10282 raft_consensus.cc:2272] T 2ba4afe0024c46b5919cfe909ccab427 P da40ed74749d4cdba248bca60eb27b6c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:54.879634 10282 tablet_server.cc:196] TabletServer@127.10.10.129:0 shutdown complete.
I20260812 06:19:54.901576 10282 master.cc:562] Master@127.10.10.190:38481 shutting down...
I20260812 06:19:54.904887 10282 raft_consensus.cc:2243] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:54.905056 10282 raft_consensus.cc:2272] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:54.905130 10282 tablet_replica.cc:333] T 00000000000000000000000000000000 P a6f46724183e4a68b93255c6df963908: stopping tablet replica
I20260812 06:19:54.917201 10282 master.cc:584] Master@127.10.10.190:38481 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (4991 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:54.986897 10282 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.10.190:42213
I20260812 06:19:54.987272 10282 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:54.989084 10629 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.989126 10620 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.989270 10282 server_base.cc:1061] running on GCE node
W20260812 06:19:54.989310 10623 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.989566 10282 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:54.989609 10282 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.989624 10282 hybrid_clock.cc:648] HybridClock initialized: now 1786515594989623 us; error 0 us; skew 500 ppm
I20260812 06:19:54.990484 10282 webserver.cc:533] Webserver started at http://127.10.10.190:43847/ using document root <none> and password file <none>
I20260812 06:19:54.990628 10282 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:54.990675 10282 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:54.990757 10282 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:54.991117 10282 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/master-0-root/instance:
uuid: "5bea3a2b25e842d385eb3edae294147d"
format_stamp: "Formatted at 2026-08-12 06:19:54 on dist-test-slave-bqcl"
I20260812 06:19:54.992542 10282 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:54.993371 10638 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.993567 10282 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:54.993637 10282 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/master-0-root
uuid: "5bea3a2b25e842d385eb3edae294147d"
format_stamp: "Formatted at 2026-08-12 06:19:54 on dist-test-slave-bqcl"
I20260812 06:19:54.993703 10282 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-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:55.012390 10282 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:55.012702 10282 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:55.016541 10282 rpc_server.cc:307] RPC server started. Bound to: 127.10.10.190:42213
I20260812 06:19:55.031520 10748 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.10.190:42213 every 8 connection(s)
I20260812 06:19:55.031976 10749 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:55.033700 10749 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d: Bootstrap starting.
I20260812 06:19:55.034480 10749 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:55.035503 10749 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d: No bootstrap required, opened a new log
I20260812 06:19:55.035902 10749 raft_consensus.cc:359] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5bea3a2b25e842d385eb3edae294147d" member_type: VOTER }
I20260812 06:19:55.035989 10749 raft_consensus.cc:385] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:55.036026 10749 raft_consensus.cc:740] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5bea3a2b25e842d385eb3edae294147d, State: Initialized, Role: FOLLOWER
I20260812 06:19:55.036172 10749 consensus_queue.cc:260] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d [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: "5bea3a2b25e842d385eb3edae294147d" member_type: VOTER }
I20260812 06:19:55.036257 10749 raft_consensus.cc:399] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:55.036298 10749 raft_consensus.cc:493] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:55.036346 10749 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:55.037024 10749 raft_consensus.cc:515] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5bea3a2b25e842d385eb3edae294147d" member_type: VOTER }
I20260812 06:19:55.037148 10749 leader_election.cc:304] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d [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: 5bea3a2b25e842d385eb3edae294147d; no voters: 
I20260812 06:19:55.037318 10749 leader_election.cc:290] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:55.037420 10752 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:55.037636 10752 raft_consensus.cc:697] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d [term 1 LEADER]: Becoming Leader. State: Replica: 5bea3a2b25e842d385eb3edae294147d, State: Running, Role: LEADER
I20260812 06:19:55.037753 10749 sys_catalog.cc:565] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:55.037774 10752 consensus_queue.cc:237] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d [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: "5bea3a2b25e842d385eb3edae294147d" member_type: VOTER }
I20260812 06:19:55.038192 10754 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "5bea3a2b25e842d385eb3edae294147d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5bea3a2b25e842d385eb3edae294147d" member_type: VOTER } }
I20260812 06:19:55.038213 10757 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d [sys.catalog]: SysCatalogTable state changed. Reason: New leader 5bea3a2b25e842d385eb3edae294147d. Latest consensus state: current_term: 1 leader_uuid: "5bea3a2b25e842d385eb3edae294147d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5bea3a2b25e842d385eb3edae294147d" member_type: VOTER } }
I20260812 06:19:55.038379 10757 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:55.038363 10754 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:55.038926 10766 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:55.039628 10766 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:55.039795 10282 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:55.041311 10766 catalog_manager.cc:1383] Generated new cluster ID: 95e62dffc57e41cfa2daa0ee4cf59a6e
I20260812 06:19:55.041356 10766 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:55.047964 10766 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:55.048457 10766 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:55.055975 10766 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d: Generated new TSK 0
I20260812 06:19:55.056128 10766 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:55.072038 10282 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:55.073808 10785 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:55.073908 10282 server_base.cc:1061] running on GCE node
W20260812 06:19:55.073971 10788 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:55.073836 10793 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:55.074222 10282 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:55.074267 10282 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:55.074286 10282 hybrid_clock.cc:648] HybridClock initialized: now 1786515595074286 us; error 0 us; skew 500 ppm
I20260812 06:19:55.075084 10282 webserver.cc:533] Webserver started at http://127.10.10.129:34815/ using document root <none> and password file <none>
I20260812 06:19:55.075232 10282 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:55.075282 10282 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:55.075351 10282 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:55.075697 10282 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/instance:
uuid: "2ab1121789ac439fa1743937449a9d51"
format_stamp: "Formatted at 2026-08-12 06:19:55 on dist-test-slave-bqcl"
I20260812 06:19:55.077087 10282 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:55.077924 10806 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:55.078164 10282 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:55.078239 10282 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root
uuid: "2ab1121789ac439fa1743937449a9d51"
format_stamp: "Formatted at 2026-08-12 06:19:55 on dist-test-slave-bqcl"
I20260812 06:19:55.078305 10282 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-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:55.085747 10282 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:55.086050 10282 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:55.086336 10282 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:55.086772 10282 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:55.086813 10282 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:55.086858 10282 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:55.086890 10282 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:55.091298 10282 rpc_server.cc:307] RPC server started. Bound to: 127.10.10.129:37239
I20260812 06:19:55.091320 10949 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.10.129:37239 every 8 connection(s)
I20260812 06:19:55.100033 10952 heartbeater.cc:344] Connected to a master server at 127.10.10.190:42213
I20260812 06:19:55.100117 10952 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:55.100281 10952 heartbeater.cc:507] Master 127.10.10.190:42213 requested a full tablet report, sending...
I20260812 06:19:55.100854 10672 ts_manager.cc:194] Registered new tserver with Master: 2ab1121789ac439fa1743937449a9d51 (127.10.10.129:37239)
I20260812 06:19:55.101512 10672 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:52954
I20260812 06:19:55.101639 10282 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009918351s
I20260812 06:19:55.107949 10672 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:52966:
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:55.115664 10871 tablet_service.cc:1511] Processing CreateTablet for tablet b31cfbdb124049c3b3ef0c208cbea249 (DEFAULT_TABLE table=heavy-update-compaction-test [id=130be75c177740679a0804d4df46e797]), partition=
I20260812 06:19:55.115883 10871 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet b31cfbdb124049c3b3ef0c208cbea249. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:55.117756 10971 tablet_bootstrap.cc:492] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Bootstrap starting.
I20260812 06:19:55.118650 10971 tablet_bootstrap.cc:654] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:55.119486 10971 tablet_bootstrap.cc:492] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: No bootstrap required, opened a new log
I20260812 06:19:55.119560 10971 ts_tablet_manager.cc:1403] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:55.119855 10971 raft_consensus.cc:359] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2ab1121789ac439fa1743937449a9d51" member_type: VOTER last_known_addr { host: "127.10.10.129" port: 37239 } }
I20260812 06:19:55.119930 10971 raft_consensus.cc:385] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:55.119956 10971 raft_consensus.cc:740] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2ab1121789ac439fa1743937449a9d51, State: Initialized, Role: FOLLOWER
I20260812 06:19:55.120056 10971 consensus_queue.cc:260] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51 [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: "2ab1121789ac439fa1743937449a9d51" member_type: VOTER last_known_addr { host: "127.10.10.129" port: 37239 } }
I20260812 06:19:55.120114 10971 raft_consensus.cc:399] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:55.120141 10971 raft_consensus.cc:493] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:55.120173 10971 raft_consensus.cc:3060] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:55.120786 10971 raft_consensus.cc:515] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2ab1121789ac439fa1743937449a9d51" member_type: VOTER last_known_addr { host: "127.10.10.129" port: 37239 } }
I20260812 06:19:55.120908 10971 leader_election.cc:304] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51 [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: 2ab1121789ac439fa1743937449a9d51; no voters: 
I20260812 06:19:55.121124 10971 leader_election.cc:290] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:55.121248 10973 raft_consensus.cc:2804] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:55.121456 10971 ts_tablet_manager.cc:1434] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:55.121471 10952 heartbeater.cc:499] Master 127.10.10.190:42213 was elected leader, sending a full tablet report...
I20260812 06:19:55.121515 10973 raft_consensus.cc:697] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51 [term 1 LEADER]: Becoming Leader. State: Replica: 2ab1121789ac439fa1743937449a9d51, State: Running, Role: LEADER
I20260812 06:19:55.121683 10973 consensus_queue.cc:237] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51 [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: "2ab1121789ac439fa1743937449a9d51" member_type: VOTER last_known_addr { host: "127.10.10.129" port: 37239 } }
I20260812 06:19:55.122996 10672 catalog_manager.cc:5719] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51 reported cstate change: term changed from 0 to 1, leader changed from <none> to 2ab1121789ac439fa1743937449a9d51 (127.10.10.129). New cstate: current_term: 1 leader_uuid: "2ab1121789ac439fa1743937449a9d51" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2ab1121789ac439fa1743937449a9d51" member_type: VOTER last_known_addr { host: "127.10.10.129" port: 37239 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:55.176703 10282 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.049s	user 0.017s	sys 0.004s
I20260812 06:19:55.342772 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushMRSOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=23.023690
I20260812 06:19:55.504601 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushMRSOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.162s	user 0.131s	sys 0.029s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":193,"dirs.run_wall_time_us":690,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44421,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:19:55.505183 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling LogGCOp(b31cfbdb124049c3b3ef0c208cbea249): free 20290830 bytes of WAL
I20260812 06:19:55.505398 10822 log_reader.cc:385] T b31cfbdb124049c3b3ef0c208cbea249: removed 2 log segments from log reader
I20260812 06:19:55.505445 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000001 (ops 1-6)
I20260812 06:19:55.505472 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000002 (ops 7-10)
I20260812 06:19:55.509523 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: LogGCOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:55.509985 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling UndoDeltaBlockGCOp(b31cfbdb124049c3b3ef0c208cbea249): 20513812 bytes on disk
I20260812 06:19:55.510574 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: UndoDeltaBlockGCOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":89,"lbm_reads_lt_1ms":4}
I20260812 06:19:55.511103 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=2.188937
I20260812 06:19:55.524387 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.013s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4476,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.524748 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=1.000000
I20260812 06:19:55.671469 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.147s	user 0.085s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":483,"lbm_read_time_us":8673,"lbm_reads_lt_1ms":460,"lbm_write_time_us":20306,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":288,"threads_started":5,"update_count":2000}
I20260812 06:19:55.672017 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=14.095187
I20260812 06:19:55.725296 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.053s	user 0.036s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21900,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.725746 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=2.188937
I20260812 06:19:55.734899 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.009s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3398,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.735571 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=1.000000
I20260812 06:19:55.879053 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.142s	user 0.099s	sys 0.042s 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":329,"lbm_read_time_us":8656,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27251,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2500}
I20260812 06:19:55.879812 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=11.118625
I20260812 06:19:55.912467 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.032s	user 0.013s	sys 0.017s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":13833,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:55.912964 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=2.188937
I20260812 06:19:55.928841 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6297,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:55.929342 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=1.000000
I20260812 06:19:56.049988 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.120s	user 0.084s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713265,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":196,"lbm_read_time_us":9494,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21873,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2000}
I20260812 06:19:56.050587 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=10.126437
I20260812 06:19:56.090996 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.040s	user 0.033s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12694,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.091522 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=2.188937
I20260812 06:19:56.102445 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4250,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.102893 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=1.000000
I20260812 06:19:56.261034 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.158s	user 0.106s	sys 0.052s 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":137,"lbm_read_time_us":11920,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25686,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19072,"update_count":2000}
I20260812 06:19:56.261629 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=10.126437
I20260812 06:19:56.297784 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.036s	user 0.026s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15438,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.298374 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=2.188937
I20260812 06:19:56.315773 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.017s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5989,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.316339 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=1.000000
I20260812 06:19:56.429888 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.113s	user 0.097s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":688,"lbm_read_time_us":8405,"lbm_reads_lt_1ms":464,"lbm_write_time_us":19071,"lbm_writes_lt_1ms":443,"mutex_wait_us":276,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":54272,"update_count":2000}
I20260812 06:19:56.430370 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=10.126437
I20260812 06:19:56.457147 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.027s	user 0.017s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":11178,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.457646 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=2.188937
I20260812 06:19:56.469341 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4478,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.469977 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=1.000000
I20260812 06:19:56.591156 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.121s	user 0.089s	sys 0.030s 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":183,"lbm_read_time_us":8429,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22710,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2000}
I20260812 06:19:56.591815 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=10.126437
I20260812 06:19:56.632934 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.041s	user 0.020s	sys 0.017s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17129,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.633469 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=2.188937
I20260812 06:19:56.644212 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3926,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.644791 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushMRSOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=1.000000
I20260812 06:19:56.672041 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushMRSOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.027s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":275,"dirs.run_wall_time_us":1263,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1489,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:56.672647 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling LogGCOp(b31cfbdb124049c3b3ef0c208cbea249): free 121459479 bytes of WAL
I20260812 06:19:56.672870 10822 log_reader.cc:385] T b31cfbdb124049c3b3ef0c208cbea249: removed 12 log segments from log reader
I20260812 06:19:56.672923 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000003 (ops 11-15)
I20260812 06:19:56.672955 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000004 (ops 16-20)
I20260812 06:19:56.672993 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000005 (ops 21-25)
I20260812 06:19:56.673024 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000006 (ops 26-30)
I20260812 06:19:56.673063 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000007 (ops 31-35)
I20260812 06:19:56.673102 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000008 (ops 36-40)
I20260812 06:19:56.673141 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000009 (ops 41-45)
I20260812 06:19:56.673177 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000010 (ops 46-50)
I20260812 06:19:56.673215 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000011 (ops 51-55)
I20260812 06:19:56.673252 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000012 (ops 56-60)
I20260812 06:19:56.673290 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000013 (ops 61-65)
I20260812 06:19:56.673326 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000014 (ops 66-70)
I20260812 06:19:56.695664 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: LogGCOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.023s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:19:56.696054 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling UndoDeltaBlockGCOp(b31cfbdb124049c3b3ef0c208cbea249): 462 bytes on disk
I20260812 06:19:56.696835 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: UndoDeltaBlockGCOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:19:56.697341 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=3.181125
I20260812 06:19:56.717514 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.020s	user 0.003s	sys 0.012s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6615,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:56.717935 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=2.188937
I20260812 06:19:56.727584 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3736,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:56.728068 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=1.000000
I20260812 06:19:56.902448 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.174s	user 0.122s	sys 0.052s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918322,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":100,"lbm_read_time_us":11760,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32642,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":59008,"thread_start_us":74,"threads_started":1,"update_count":3000}
I20260812 06:19:56.902952 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=14.095187
I20260812 06:19:56.949994 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.047s	user 0.020s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20488,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.950567 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=2.188937
I20260812 06:19:56.967386 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6102,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.967974 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=1.000000
I20260812 06:19:57.119171 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.151s	user 0.123s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":508,"lbm_read_time_us":10442,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28376,"lbm_writes_lt_1ms":543,"mutex_wait_us":271,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2500}
I20260812 06:19:57.119717 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=14.095187
I20260812 06:19:57.173367 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.054s	user 0.020s	sys 0.024s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":21757,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.173902 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=2.188937
I20260812 06:19:57.184717 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4020,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.185196 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=1.000000
I20260812 06:19:57.335603 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.150s	user 0.114s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815680,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":176,"lbm_read_time_us":10688,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24099,"lbm_writes_lt_1ms":543,"mutex_wait_us":19,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":131200,"update_count":2500}
I20260812 06:19:57.336071 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=14.095187
I20260812 06:19:57.387707 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.051s	user 0.033s	sys 0.014s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20665,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.388213 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=2.188937
I20260812 06:19:57.403443 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6050,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.404095 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=1.000000
I20260812 06:19:57.555943 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.152s	user 0.112s	sys 0.040s 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":194,"lbm_read_time_us":10580,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24178,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2500}
I20260812 06:19:57.556411 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=14.095187
I20260812 06:19:57.614675 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.058s	user 0.035s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21631,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.615211 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=2.188937
I20260812 06:19:57.629431 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5531,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.630528 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=1.000000
I20260812 06:19:57.821650 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.191s	user 0.109s	sys 0.080s 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":173,"lbm_read_time_us":14631,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29912,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2500}
I20260812 06:19:57.822203 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=14.095187
I20260812 06:19:57.877921 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.056s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":15945,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.878460 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=2.188937
I20260812 06:19:57.888298 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3809,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.888779 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=1.000000
I20260812 06:19:58.058670 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.170s	user 0.129s	sys 0.040s 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":531,"lbm_read_time_us":11408,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26366,"lbm_writes_lt_1ms":543,"mutex_wait_us":216,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:19:58.059224 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=11.118625
I20260812 06:19:58.092486 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.033s	user 0.027s	sys 0.004s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13387,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:58.093089 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=2.188937
I20260812 06:19:58.107192 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4519,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:58.107753 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushMRSOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=1.000000
I20260812 06:19:58.156418 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushMRSOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.048s	user 0.023s	sys 0.002s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":47,"dirs.run_cpu_time_us":186,"dirs.run_wall_time_us":1158,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1564,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:58.157361 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=6.157687
I20260812 06:19:58.188760 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.031s	user 0.016s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11185,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:58.189209 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling LogGCOp(b31cfbdb124049c3b3ef0c208cbea249): free 136728203 bytes of WAL
I20260812 06:19:58.189425 10822 log_reader.cc:385] T b31cfbdb124049c3b3ef0c208cbea249: removed 13 log segments from log reader
I20260812 06:19:58.189472 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000015 (ops 71-75)
I20260812 06:19:58.189502 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000016 (ops 76-80)
I20260812 06:19:58.189533 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000017 (ops 81-85)
I20260812 06:19:58.189567 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000018 (ops 86-90)
I20260812 06:19:58.189599 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000019 (ops 91-95)
I20260812 06:19:58.189632 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000020 (ops 96-100)
I20260812 06:19:58.189663 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000021 (ops 101-105)
I20260812 06:19:58.189695 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000022 (ops 106-110)
I20260812 06:19:58.189728 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000023 (ops 111-115)
I20260812 06:19:58.189757 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000024 (ops 116-120)
I20260812 06:19:58.189790 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000025 (ops 121-125)
I20260812 06:19:58.189821 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000026 (ops 126-130)
I20260812 06:19:58.189852 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000027 (ops 131-135)
I20260812 06:19:58.214937 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: LogGCOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:58.215320 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling UndoDeltaBlockGCOp(b31cfbdb124049c3b3ef0c208cbea249): 492 bytes on disk
I20260812 06:19:58.215690 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: UndoDeltaBlockGCOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:19:58.216171 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=2.188937
I20260812 06:19:58.233681 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.017s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4862,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.234161 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=1.000000
I20260812 06:19:58.447196 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.213s	user 0.136s	sys 0.076s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020738,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":494,"lbm_read_time_us":15226,"lbm_reads_lt_1ms":766,"lbm_write_time_us":34357,"lbm_writes_lt_1ms":743,"mutex_wait_us":298,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4992,"thread_start_us":71,"threads_started":1,"update_count":3500}
I20260812 06:19:58.447731 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=18.063937
I20260812 06:19:58.498025 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.050s	user 0.030s	sys 0.017s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":22358,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:58.498534 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=2.188937
I20260812 06:19:58.511664 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4943,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.512135 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=1.000000
I20260812 06:19:58.706940 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.195s	user 0.143s	sys 0.050s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":242,"lbm_read_time_us":12906,"lbm_reads_lt_1ms":664,"lbm_write_time_us":30675,"lbm_writes_lt_1ms":643,"mutex_wait_us":30,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":3000}
I20260812 06:19:58.707654 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=16.079562
I20260812 06:19:58.753815 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.046s	user 0.037s	sys 0.001s Metrics: {"bytes_written":17640626,"delete_count":0,"lbm_write_time_us":18681,"lbm_writes_lt_1ms":433,"reinsert_count":0,"update_count":2150}
I20260812 06:19:58.754321 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=2.188937
I20260812 06:19:58.764555 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.010s	user 0.006s	sys 0.001s Metrics: {"bytes_written":3282159,"delete_count":0,"lbm_write_time_us":3442,"lbm_writes_lt_1ms":83,"reinsert_count":0,"update_count":400}
I20260812 06:19:58.764957 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=2.188937
I20260812 06:19:58.773968 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3500,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:58.774344 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=1.000000
I20260812 06:19:58.970402 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.196s	user 0.101s	sys 0.095s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918185,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":713,"lbm_read_time_us":15553,"lbm_reads_lt_1ms":673,"lbm_write_time_us":30908,"lbm_writes_lt_1ms":643,"mutex_wait_us":266,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":3000}
I20260812 06:19:58.970919 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=14.095187
I20260812 06:19:59.023972 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.053s	user 0.025s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17175,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.024485 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=2.188937
I20260812 06:19:59.034497 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3937,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.034950 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=1.000000
I20260812 06:19:59.191398 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.156s	user 0.088s	sys 0.068s 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":197,"lbm_read_time_us":11850,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25391,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":35456,"update_count":2500}
I20260812 06:19:59.191996 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=14.095187
I20260812 06:19:59.244062 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.052s	user 0.031s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18384,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.244621 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=2.188937
I20260812 06:19:59.259640 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5796,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.260191 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=1.000000
I20260812 06:19:59.419878 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.160s	user 0.108s	sys 0.052s 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":137,"lbm_read_time_us":11355,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26272,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:19:59.420778 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=14.095187
I20260812 06:19:59.477516 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.056s	user 0.031s	sys 0.022s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18424,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.478065 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=2.188937
I20260812 06:19:59.488333 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3915,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.488773 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushMRSOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=1.000000
I20260812 06:19:59.521826 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushMRSOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.033s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":213,"dirs.run_wall_time_us":1107,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1425,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:59.522509 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling LogGCOp(b31cfbdb124049c3b3ef0c208cbea249): free 112239560 bytes of WAL
I20260812 06:19:59.522722 10822 log_reader.cc:385] T b31cfbdb124049c3b3ef0c208cbea249: removed 11 log segments from log reader
I20260812 06:19:59.522768 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000028 (ops 136-140)
I20260812 06:19:59.522795 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000029 (ops 141-144)
I20260812 06:19:59.522826 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000030 (ops 145-149)
I20260812 06:19:59.522856 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000031 (ops 150-154)
I20260812 06:19:59.522891 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000032 (ops 155-159)
I20260812 06:19:59.522924 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000033 (ops 160-164)
I20260812 06:19:59.522956 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000034 (ops 165-169)
I20260812 06:19:59.522990 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000035 (ops 170-174)
I20260812 06:19:59.523022 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000036 (ops 175-179)
I20260812 06:19:59.523067 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000037 (ops 180-184)
I20260812 06:19:59.523092 10822 log.cc:1079] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: Deleting log segment in path: /tmp/dist-test-taskiiNuju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515589985596-10282-0/minicluster-data/ts-0-root/wals/b31cfbdb124049c3b3ef0c208cbea249/wal-000000038 (ops 185-189)
I20260812 06:19:59.542768 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: LogGCOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.020s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:19:59.543135 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling UndoDeltaBlockGCOp(b31cfbdb124049c3b3ef0c208cbea249): 463 bytes on disk
I20260812 06:19:59.543519 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: UndoDeltaBlockGCOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:19:59.544024 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=3.181125
I20260812 06:19:59.566780 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.023s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6184,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:59.567169 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=2.188937
I20260812 06:19:59.575785 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.008s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3244,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:59.576156 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=1.000000
I20260812 06:19:59.701952 10282 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.525s	user 1.690s	sys 0.134s
I20260812 06:19:59.771641 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: MajorDeltaCompactionOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.195s	user 0.112s	sys 0.083s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020733,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":125,"lbm_read_time_us":14738,"lbm_reads_lt_1ms":770,"lbm_write_time_us":29995,"lbm_writes_lt_1ms":743,"mutex_wait_us":51,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3840,"thread_start_us":72,"threads_started":1,"update_count":3500}
I20260812 06:19:59.773353 10953 maintenance_manager.cc:419] P 2ab1121789ac439fa1743937449a9d51: Scheduling FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249): perf score=10.126437
I20260812 06:19:59.784492 10282 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.082s	user 0.001s	sys 0.000s
I20260812 06:19:59.784950 10282 tablet_server.cc:179] TabletServer@127.10.10.129:0 shutting down...
I20260812 06:19:59.805823 10822 maintenance_manager.cc:643] P 2ab1121789ac439fa1743937449a9d51: FlushDeltaMemStoresOp(b31cfbdb124049c3b3ef0c208cbea249) complete. Timing: real 0.032s	user 0.022s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12819,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:59.806357 10282 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:59.806579 10282 tablet_replica.cc:333] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51: stopping tablet replica
I20260812 06:19:59.806702 10282 raft_consensus.cc:2243] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:59.806895 10282 raft_consensus.cc:2272] T b31cfbdb124049c3b3ef0c208cbea249 P 2ab1121789ac439fa1743937449a9d51 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:59.819756 10282 tablet_server.cc:196] TabletServer@127.10.10.129:0 shutdown complete.
I20260812 06:19:59.828735 10282 master.cc:562] Master@127.10.10.190:42213 shutting down...
I20260812 06:19:59.831631 10282 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:59.831772 10282 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:59.831842 10282 tablet_replica.cc:333] T 00000000000000000000000000000000 P 5bea3a2b25e842d385eb3edae294147d: stopping tablet replica
I20260812 06:19:59.843676 10282 master.cc:584] Master@127.10.10.190:42213 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4924 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (9917 ms total)

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