[==========] 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:20:13.622614  8524 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.8.83.62:46267
I20260812 06:20:13.623648  8524 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:20:13.624257  8524 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:13.631052  8534 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:20:13.631223  8538 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:20:13.631346  8535 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:20:13.631232  8524 server_base.cc:1061] running on GCE node
I20260812 06:20:13.631986  8524 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:13.632114  8524 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:20:13.632167  8524 hybrid_clock.cc:648] HybridClock initialized: now 1786515613632165 us; error 0 us; skew 500 ppm
I20260812 06:20:13.634161  8524 webserver.cc:533] Webserver started at http://127.8.83.62:44811/ using document root <none> and password file <none>
I20260812 06:20:13.634814  8524 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:13.634902  8524 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:13.635178  8524 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:13.636926  8524 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/master-0-root/instance:
uuid: "d672c8543b2e441e983ddaae7f887093"
format_stamp: "Formatted at 2026-08-12 06:20:13 on dist-test-slave-7kzw"
I20260812 06:20:13.640617  8524 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:20:13.642824  8544 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:20:13.643819  8524 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:13.643970  8524 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/master-0-root
uuid: "d672c8543b2e441e983ddaae7f887093"
format_stamp: "Formatted at 2026-08-12 06:20:13 on dist-test-slave-7kzw"
I20260812 06:20:13.644068  8524 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-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:20:13.657609  8524 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:13.658268  8524 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:20:13.658501  8524 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:13.668124  8524 rpc_server.cc:307] RPC server started. Bound to: 127.8.83.62:46267
I20260812 06:20:13.668205  8621 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.83.62:46267 every 8 connection(s)
I20260812 06:20:13.671353  8626 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:20:13.677111  8626 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093: Bootstrap starting.
I20260812 06:20:13.679682  8626 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:13.680641  8626 log.cc:826] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:13.682586  8626 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093: No bootstrap required, opened a new log
I20260812 06:20:13.685716  8626 raft_consensus.cc:359] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d672c8543b2e441e983ddaae7f887093" member_type: VOTER }
I20260812 06:20:13.685894  8626 raft_consensus.cc:385] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:13.685990  8626 raft_consensus.cc:740] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d672c8543b2e441e983ddaae7f887093, State: Initialized, Role: FOLLOWER
I20260812 06:20:13.686755  8626 consensus_queue.cc:260] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093 [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: "d672c8543b2e441e983ddaae7f887093" member_type: VOTER }
I20260812 06:20:13.686939  8626 raft_consensus.cc:399] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:13.687016  8626 raft_consensus.cc:493] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:13.687194  8626 raft_consensus.cc:3060] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:13.688097  8626 raft_consensus.cc:515] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d672c8543b2e441e983ddaae7f887093" member_type: VOTER }
I20260812 06:20:13.688571  8626 leader_election.cc:304] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093 [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: d672c8543b2e441e983ddaae7f887093; no voters: 
I20260812 06:20:13.688953  8626 leader_election.cc:290] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:13.689172  8631 raft_consensus.cc:2804] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:13.689484  8631 raft_consensus.cc:697] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093 [term 1 LEADER]: Becoming Leader. State: Replica: d672c8543b2e441e983ddaae7f887093, State: Running, Role: LEADER
I20260812 06:20:13.689932  8631 consensus_queue.cc:237] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093 [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: "d672c8543b2e441e983ddaae7f887093" member_type: VOTER }
I20260812 06:20:13.690076  8626 sys_catalog.cc:565] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:13.692095  8635 sys_catalog.cc:455] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093 [sys.catalog]: SysCatalogTable state changed. Reason: New leader d672c8543b2e441e983ddaae7f887093. Latest consensus state: current_term: 1 leader_uuid: "d672c8543b2e441e983ddaae7f887093" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d672c8543b2e441e983ddaae7f887093" member_type: VOTER } }
I20260812 06:20:13.692147  8634 sys_catalog.cc:455] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "d672c8543b2e441e983ddaae7f887093" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d672c8543b2e441e983ddaae7f887093" member_type: VOTER } }
I20260812 06:20:13.692232  8635 sys_catalog.cc:458] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:13.692250  8634 sys_catalog.cc:458] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:13.692610  8648 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:13.692783  8524 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:13.695137  8648 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:13.700086  8648 catalog_manager.cc:1383] Generated new cluster ID: fdd025e275994db699fc15867e03a1c1
I20260812 06:20:13.700155  8648 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:13.712755  8648 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:13.713586  8648 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:13.722431  8648 catalog_manager.cc:6092] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093: Generated new TSK 0
I20260812 06:20:13.723024  8648 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:13.725329  8524 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:13.728224  8663 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:20:13.728380  8665 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:20:13.728380  8661 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:20:13.728914  8524 server_base.cc:1061] running on GCE node
I20260812 06:20:13.729118  8524 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:13.729164  8524 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:20:13.729183  8524 hybrid_clock.cc:648] HybridClock initialized: now 1786515613729183 us; error 0 us; skew 500 ppm
I20260812 06:20:13.730304  8524 webserver.cc:533] Webserver started at http://127.8.83.1:41591/ using document root <none> and password file <none>
I20260812 06:20:13.730533  8524 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:13.730605  8524 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:13.730715  8524 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:13.731158  8524 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/instance:
uuid: "823b1a1858c746adb4f9600054e32104"
format_stamp: "Formatted at 2026-08-12 06:20:13 on dist-test-slave-7kzw"
I20260812 06:20:13.732825  8524 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:13.733871  8675 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:20:13.734184  8524 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:13.734254  8524 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root
uuid: "823b1a1858c746adb4f9600054e32104"
format_stamp: "Formatted at 2026-08-12 06:20:13 on dist-test-slave-7kzw"
I20260812 06:20:13.734347  8524 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-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:20:13.739840  8524 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:13.740267  8524 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:13.740720  8524 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:13.741571  8524 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:13.741627  8524 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:13.741703  8524 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:13.741746  8524 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:13.749454  8524 rpc_server.cc:307] RPC server started. Bound to: 127.8.83.1:44743
I20260812 06:20:13.749497  8772 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.83.1:44743 every 8 connection(s)
I20260812 06:20:13.764266  8773 heartbeater.cc:344] Connected to a master server at 127.8.83.62:46267
I20260812 06:20:13.764580  8773 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:13.765100  8773 heartbeater.cc:507] Master 127.8.83.62:46267 requested a full tablet report, sending...
I20260812 06:20:13.766721  8572 ts_manager.cc:194] Registered new tserver with Master: 823b1a1858c746adb4f9600054e32104 (127.8.83.1:44743)
I20260812 06:20:13.767094  8524 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016987466s
I20260812 06:20:13.768103  8572 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:49102
I20260812 06:20:13.777745  8572 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:49104:
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:20:13.792902  8718 tablet_service.cc:1511] Processing CreateTablet for tablet fdd69399772042c787559aaf588fcfd1 (DEFAULT_TABLE table=heavy-update-compaction-test [id=9ac7961f250a4a1db2a905c58514915f]), partition=
I20260812 06:20:13.793366  8718 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet fdd69399772042c787559aaf588fcfd1. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:13.795805  8792 tablet_bootstrap.cc:492] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Bootstrap starting.
I20260812 06:20:13.796674  8792 tablet_bootstrap.cc:654] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:13.797788  8792 tablet_bootstrap.cc:492] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: No bootstrap required, opened a new log
I20260812 06:20:13.797904  8792 ts_tablet_manager.cc:1403] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:13.798375  8792 raft_consensus.cc:359] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "823b1a1858c746adb4f9600054e32104" member_type: VOTER last_known_addr { host: "127.8.83.1" port: 44743 } }
I20260812 06:20:13.798528  8792 raft_consensus.cc:385] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:13.798580  8792 raft_consensus.cc:740] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 823b1a1858c746adb4f9600054e32104, State: Initialized, Role: FOLLOWER
I20260812 06:20:13.798723  8792 consensus_queue.cc:260] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104 [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: "823b1a1858c746adb4f9600054e32104" member_type: VOTER last_known_addr { host: "127.8.83.1" port: 44743 } }
I20260812 06:20:13.798804  8792 raft_consensus.cc:399] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:13.798861  8792 raft_consensus.cc:493] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:13.798916  8792 raft_consensus.cc:3060] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:13.799887  8792 raft_consensus.cc:515] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "823b1a1858c746adb4f9600054e32104" member_type: VOTER last_known_addr { host: "127.8.83.1" port: 44743 } }
I20260812 06:20:13.800037  8792 leader_election.cc:304] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104 [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: 823b1a1858c746adb4f9600054e32104; no voters: 
I20260812 06:20:13.800263  8792 leader_election.cc:290] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:13.800385  8795 raft_consensus.cc:2804] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:13.800611  8792 ts_tablet_manager.cc:1434] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:20:13.800649  8795 raft_consensus.cc:697] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104 [term 1 LEADER]: Becoming Leader. State: Replica: 823b1a1858c746adb4f9600054e32104, State: Running, Role: LEADER
I20260812 06:20:13.800840  8773 heartbeater.cc:499] Master 127.8.83.62:46267 was elected leader, sending a full tablet report...
I20260812 06:20:13.800818  8795 consensus_queue.cc:237] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104 [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: "823b1a1858c746adb4f9600054e32104" member_type: VOTER last_known_addr { host: "127.8.83.1" port: 44743 } }
I20260812 06:20:13.803862  8572 catalog_manager.cc:5719] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104 reported cstate change: term changed from 0 to 1, leader changed from <none> to 823b1a1858c746adb4f9600054e32104 (127.8.83.1). New cstate: current_term: 1 leader_uuid: "823b1a1858c746adb4f9600054e32104" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "823b1a1858c746adb4f9600054e32104" member_type: VOTER last_known_addr { host: "127.8.83.1" port: 44743 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:13.869666  8524 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.025s	sys 0.000s
I20260812 06:20:14.000554  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushMRSOp(fdd69399772042c787559aaf588fcfd1): perf score=15.086190
I20260812 06:20:14.169912  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushMRSOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.169s	user 0.113s	sys 0.048s Metrics: {"bytes_written":11897251,"cfile_init":1,"compiler_manager_pool.queue_time_us":246,"delete_count":0,"dirs.queue_time_us":42,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":769,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42590,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":145,"threads_started":1,"update_count":1450}
I20260812 06:20:14.171145  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling LogGCOp(fdd69399772042c787559aaf588fcfd1): free 20743880 bytes of WAL
I20260812 06:20:14.171433  8682 log_reader.cc:385] T fdd69399772042c787559aaf588fcfd1: removed 2 log segments from log reader
I20260812 06:20:14.171489  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000001 (ops 1-6)
I20260812 06:20:14.171536  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000002 (ops 7-11)
I20260812 06:20:14.176890  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: LogGCOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:14.177253  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling UndoDeltaBlockGCOp(fdd69399772042c787559aaf588fcfd1): 12719217 bytes on disk
I20260812 06:20:14.177834  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: UndoDeltaBlockGCOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:20:14.178273  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=2.188937
I20260812 06:20:14.194588  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5172,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.195217  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:14.325865  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.130s	user 0.102s	sys 0.028s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262038,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":297,"lbm_read_time_us":9183,"lbm_reads_lt_1ms":450,"lbm_write_time_us":26332,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":2560,"thread_start_us":282,"threads_started":5,"update_count":1950}
I20260812 06:20:14.326421  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=10.126437
I20260812 06:20:14.372135  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.045s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18200,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.372648  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=2.188937
I20260812 06:20:14.383260  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3868,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.383801  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:14.513650  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.130s	user 0.097s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":347,"lbm_read_time_us":9895,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25355,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19456,"update_count":2000}
I20260812 06:20:14.514448  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=10.126437
I20260812 06:20:14.554366  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.040s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15237,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.554862  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=2.188937
I20260812 06:20:14.565174  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3928,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.565711  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:14.686643  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.121s	user 0.100s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2266,"lbm_read_time_us":7937,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24893,"lbm_writes_lt_1ms":443,"mutex_wait_us":1255,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2000}
I20260812 06:20:14.687341  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=10.126437
I20260812 06:20:14.741856  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.054s	user 0.021s	sys 0.020s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16236,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.742406  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=2.188937
I20260812 06:20:14.753221  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4166,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.753638  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:14.917742  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.164s	user 0.105s	sys 0.053s 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":1100,"lbm_read_time_us":11177,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27929,"lbm_writes_lt_1ms":443,"mutex_wait_us":359,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":121856,"update_count":2000}
I20260812 06:20:14.918346  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=10.126437
I20260812 06:20:14.957990  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.039s	user 0.033s	sys 0.000s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15597,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.958616  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:15.073017  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.114s	user 0.078s	sys 0.036s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":514,"lbm_read_time_us":6845,"lbm_reads_lt_1ms":363,"lbm_write_time_us":20245,"lbm_writes_lt_1ms":343,"mutex_wait_us":281,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":39040,"update_count":1500}
I20260812 06:20:15.073724  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=10.126437
I20260812 06:20:15.134315  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.060s	user 0.039s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21424,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.135162  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=2.188937
I20260812 06:20:15.148303  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4944,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.148797  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:15.276976  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.128s	user 0.092s	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":303,"lbm_read_time_us":9609,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23765,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2000}
I20260812 06:20:15.277546  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=10.126437
I20260812 06:20:15.330931  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.053s	user 0.037s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17765,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.331420  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=2.188937
I20260812 06:20:15.342162  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4160,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.342705  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:15.501541  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.159s	user 0.119s	sys 0.037s 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":1497,"lbm_read_time_us":10752,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26455,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:20:15.502218  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=10.126437
I20260812 06:20:15.544265  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.042s	user 0.011s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17176,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.544754  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=2.188937
I20260812 06:20:15.555550  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4179,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.556348  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushMRSOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:15.587934  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushMRSOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.031s	user 0.028s	sys 0.002s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":1443,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1577,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:15.588725  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling LogGCOp(fdd69399772042c787559aaf588fcfd1): free 116849519 bytes of WAL
I20260812 06:20:15.588956  8682 log_reader.cc:385] T fdd69399772042c787559aaf588fcfd1: removed 12 log segments from log reader
I20260812 06:20:15.589025  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000003 (ops 12-16)
I20260812 06:20:15.589080  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000004 (ops 17-20)
I20260812 06:20:15.589144  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000005 (ops 21-25)
I20260812 06:20:15.589185  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000006 (ops 26-30)
I20260812 06:20:15.589221  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000007 (ops 31-35)
I20260812 06:20:15.589258  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000008 (ops 36-40)
I20260812 06:20:15.589294  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000009 (ops 41-44)
I20260812 06:20:15.589331  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000010 (ops 45-49)
I20260812 06:20:15.589367  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000011 (ops 50-54)
I20260812 06:20:15.589404  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000012 (ops 55-58)
I20260812 06:20:15.589440  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000013 (ops 59-63)
I20260812 06:20:15.589475  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000014 (ops 64-68)
I20260812 06:20:15.617643  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: LogGCOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:15.618279  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=3.181125
I20260812 06:20:15.635941  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.017s	user 0.013s	sys 0.003s Metrics: {"bytes_written":4635978,"delete_count":0,"lbm_write_time_us":6927,"lbm_writes_lt_1ms":116,"reinsert_count":0,"update_count":565}
I20260812 06:20:15.636380  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling LogGCOp(fdd69399772042c787559aaf588fcfd1): free 11564875 bytes of WAL
I20260812 06:20:15.636593  8682 log_reader.cc:385] T fdd69399772042c787559aaf588fcfd1: removed 1 log segments from log reader
I20260812 06:20:15.636636  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000015 (ops 69-72)
I20260812 06:20:15.639024  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: LogGCOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.002s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:15.639319  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling UndoDeltaBlockGCOp(fdd69399772042c787559aaf588fcfd1): 472 bytes on disk
I20260812 06:20:15.639720  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: UndoDeltaBlockGCOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:20:15.640138  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=2.188937
I20260812 06:20:15.651925  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3569330,"delete_count":0,"lbm_write_time_us":4135,"lbm_writes_lt_1ms":90,"reinsert_count":0,"update_count":435}
I20260812 06:20:15.652447  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:15.847818  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.195s	user 0.132s	sys 0.059s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2266,"lbm_read_time_us":15090,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31350,"lbm_writes_lt_1ms":643,"mutex_wait_us":1466,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":84,"threads_started":1,"update_count":3000}
I20260812 06:20:15.848443  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=14.095187
I20260812 06:20:15.903854  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.055s	user 0.026s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23125,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:15.904364  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=2.188937
I20260812 06:20:15.915817  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4428,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.916486  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:16.103590  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.187s	user 0.151s	sys 0.027s 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":403,"lbm_read_time_us":12399,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31034,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:16.104317  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=11.118625
I20260812 06:20:16.149782  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.045s	user 0.030s	sys 0.012s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":18937,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:16.150367  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=2.188937
I20260812 06:20:16.166054  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.015s	user 0.005s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5735,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:16.166869  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:16.302117  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.135s	user 0.118s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672267,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":997,"lbm_read_time_us":8262,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28663,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.302937  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=10.126437
I20260812 06:20:16.344432  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.041s	user 0.010s	sys 0.029s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18400,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.344944  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=2.188937
I20260812 06:20:16.361222  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.016s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5034,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.361846  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:16.501307  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.139s	user 0.110s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2478,"lbm_read_time_us":10064,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27011,"lbm_writes_lt_1ms":443,"mutex_wait_us":667,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2000}
I20260812 06:20:16.501968  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=10.126437
I20260812 06:20:16.551666  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.047s	user 0.018s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15980,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.552244  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=2.188937
I20260812 06:20:16.567183  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5721,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.567726  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:16.705530  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.138s	user 0.096s	sys 0.037s 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":780,"lbm_read_time_us":10086,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25966,"lbm_writes_lt_1ms":443,"mutex_wait_us":309,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.706133  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=10.126437
I20260812 06:20:16.748986  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.043s	user 0.021s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14119,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.750291  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=1.196750
I20260812 06:20:16.758373  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.008s	user 0.005s	sys 0.000s Metrics: {"bytes_written":2338582,"delete_count":0,"lbm_write_time_us":2304,"lbm_writes_lt_1ms":60,"reinsert_count":0,"update_count":285}
I20260812 06:20:16.758939  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:16.764434  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.005s	user 0.003s	sys 0.001s Metrics: {"bytes_written":1764227,"delete_count":0,"lbm_write_time_us":1706,"lbm_writes_lt_1ms":46,"reinsert_count":0,"update_count":215}
I20260812 06:20:16.764882  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:16.923053  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.158s	user 0.110s	sys 0.048s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20672300,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":798,"lbm_read_time_us":10276,"lbm_reads_lt_1ms":473,"lbm_write_time_us":27297,"lbm_writes_lt_1ms":443,"mutex_wait_us":63,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:20:16.923674  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=10.126437
I20260812 06:20:16.975246  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.049s	user 0.031s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20693,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.975826  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=2.188937
I20260812 06:20:16.988031  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4553,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.988616  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:17.125342  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.137s	user 0.103s	sys 0.031s 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":253,"lbm_read_time_us":7823,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28513,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.126170  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=10.126437
I20260812 06:20:17.171018  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.045s	user 0.028s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19323,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.171548  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=2.188937
I20260812 06:20:17.187515  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.016s	user 0.009s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6055,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.188094  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushMRSOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:17.220767  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushMRSOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.032s	user 0.030s	sys 0.001s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":340,"dirs.run_wall_time_us":1673,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1554,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:17.221496  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling LogGCOp(fdd69399772042c787559aaf588fcfd1): free 120553404 bytes of WAL
I20260812 06:20:17.221745  8682 log_reader.cc:385] T fdd69399772042c787559aaf588fcfd1: removed 12 log segments from log reader
I20260812 06:20:17.221792  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000016 (ops 73-77)
I20260812 06:20:17.221822  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000017 (ops 78-82)
I20260812 06:20:17.221875  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000018 (ops 83-86)
I20260812 06:20:17.221918  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000019 (ops 87-91)
I20260812 06:20:17.221947  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000020 (ops 92-96)
I20260812 06:20:17.222005  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000021 (ops 97-100)
I20260812 06:20:17.222048  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000022 (ops 101-105)
I20260812 06:20:17.222084  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000023 (ops 106-110)
I20260812 06:20:17.222124  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000024 (ops 111-115)
I20260812 06:20:17.222159  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000025 (ops 116-120)
I20260812 06:20:17.222198  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000026 (ops 121-125)
I20260812 06:20:17.222239  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000027 (ops 126-130)
I20260812 06:20:17.249773  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: LogGCOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:17.250313  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=4.173312
I20260812 06:20:17.264132  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":5620563,"delete_count":0,"lbm_write_time_us":5533,"lbm_writes_lt_1ms":140,"reinsert_count":0,"update_count":685}
I20260812 06:20:17.264640  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=1.196750
I20260812 06:20:17.274407  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.010s	user 0.004s	sys 0.003s Metrics: {"bytes_written":2584729,"delete_count":0,"lbm_write_time_us":3200,"lbm_writes_lt_1ms":66,"reinsert_count":0,"update_count":315}
I20260812 06:20:17.274997  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling UndoDeltaBlockGCOp(fdd69399772042c787559aaf588fcfd1): 481 bytes on disk
I20260812 06:20:17.275449  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: UndoDeltaBlockGCOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:20:17.276075  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:17.440301  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.164s	user 0.125s	sys 0.036s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877307,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2225,"lbm_read_time_us":11254,"lbm_reads_lt_1ms":666,"lbm_write_time_us":31570,"lbm_writes_lt_1ms":643,"mutex_wait_us":86,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":47488,"thread_start_us":75,"threads_started":1,"update_count":3000}
I20260812 06:20:17.440810  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=14.095187
I20260812 06:20:17.496097  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.055s	user 0.036s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21104,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.496714  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=2.188937
I20260812 06:20:17.515363  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.018s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6122,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.515899  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:17.665405  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.149s	user 0.118s	sys 0.025s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1487,"lbm_read_time_us":9362,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29917,"lbm_writes_lt_1ms":543,"mutex_wait_us":307,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2500}
I20260812 06:20:17.666033  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=14.095187
I20260812 06:20:17.719372  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.053s	user 0.022s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20596,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.719903  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=2.188937
I20260812 06:20:17.731246  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4069,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.731715  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:17.894886  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.163s	user 0.114s	sys 0.048s 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":380,"lbm_read_time_us":11623,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32937,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:17.898967  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=13.103000
I20260812 06:20:17.945988  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.047s	user 0.038s	sys 0.005s Metrics: {"bytes_written":14933033,"delete_count":0,"lbm_write_time_us":20618,"lbm_writes_lt_1ms":367,"reinsert_count":0,"update_count":1820}
I20260812 06:20:17.946658  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:17.952714  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.006s	user 0.003s	sys 0.001s Metrics: {"bytes_written":1477052,"delete_count":0,"lbm_write_time_us":1631,"lbm_writes_lt_1ms":39,"reinsert_count":0,"update_count":180}
I20260812 06:20:17.953190  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:18.092904  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.140s	user 0.111s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672214,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":697,"lbm_read_time_us":11089,"lbm_reads_lt_1ms":468,"lbm_write_time_us":23549,"lbm_writes_lt_1ms":443,"mutex_wait_us":63,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13824,"update_count":2000}
I20260812 06:20:18.093596  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=10.126437
I20260812 06:20:18.132344  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.039s	user 0.025s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16177,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:18.132825  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=2.188937
I20260812 06:20:18.146459  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5220,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.146973  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:18.272823  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.126s	user 0.105s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":152,"lbm_read_time_us":8875,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22647,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2000}
I20260812 06:20:18.273588  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=10.126437
I20260812 06:20:18.311945  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.038s	user 0.024s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16705,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:18.312461  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=2.188937
I20260812 06:20:18.330088  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.017s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5268,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.330814  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:18.476341  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.145s	user 0.115s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":354,"lbm_read_time_us":10825,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27404,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2000}
I20260812 06:20:18.477195  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=11.118625
I20260812 06:20:18.526556  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.049s	user 0.026s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":23531,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":309,"reinsert_count":0,"update_count":1550}
I20260812 06:20:18.527168  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=2.188937
I20260812 06:20:18.550071  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.023s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5671,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.550733  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=2.188937
I20260812 06:20:18.560884  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3587,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:18.561610  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushMRSOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:18.590971  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushMRSOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.029s	user 0.023s	sys 0.004s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":89,"dirs.run_cpu_time_us":277,"dirs.run_wall_time_us":1393,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1544,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:18.591820  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling LogGCOp(fdd69399772042c787559aaf588fcfd1): free 121006706 bytes of WAL
I20260812 06:20:18.592082  8682 log_reader.cc:385] T fdd69399772042c787559aaf588fcfd1: removed 12 log segments from log reader
I20260812 06:20:18.592149  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000028 (ops 131-135)
I20260812 06:20:18.592190  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000029 (ops 136-140)
I20260812 06:20:18.592212  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000030 (ops 141-145)
I20260812 06:20:18.592235  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000031 (ops 146-150)
I20260812 06:20:18.592257  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000032 (ops 151-155)
I20260812 06:20:18.592280  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000033 (ops 156-160)
I20260812 06:20:18.592307  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000034 (ops 161-165)
I20260812 06:20:18.592340  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000035 (ops 166-170)
I20260812 06:20:18.592376  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000036 (ops 171-175)
I20260812 06:20:18.592407  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000037 (ops 176-180)
I20260812 06:20:18.592437  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000038 (ops 181-184)
I20260812 06:20:18.592474  8682 log.cc:1079] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/fdd69399772042c787559aaf588fcfd1/wal-000000039 (ops 185-189)
I20260812 06:20:18.621889  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: LogGCOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:18.622377  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=3.181125
I20260812 06:20:18.641680  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.019s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4635,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:18.642191  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling UndoDeltaBlockGCOp(fdd69399772042c787559aaf588fcfd1): 463 bytes on disk
I20260812 06:20:18.642693  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: UndoDeltaBlockGCOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":104,"lbm_reads_lt_1ms":4}
I20260812 06:20:18.643232  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=2.188937
I20260812 06:20:18.653113  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3648,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:18.653579  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:18.822252  8524 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.952s	user 1.838s	sys 0.097s
I20260812 06:20:18.840158  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.186s	user 0.137s	sys 0.047s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979848,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"lbm_read_time_us":13145,"lbm_reads_lt_1ms":771,"lbm_write_time_us":38846,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"update_count":3500}
I20260812 06:20:18.840684  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1): perf score=14.095187
I20260812 06:20:18.873416  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: FlushDeltaMemStoresOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.032s	user 0.012s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":15847,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:18.873961  8774 maintenance_manager.cc:419] P 823b1a1858c746adb4f9600054e32104: Scheduling MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1): perf score=1.000000
I20260812 06:20:18.899050  8524 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.076s	user 0.003s	sys 0.000s
I20260812 06:20:18.899791  8524 tablet_server.cc:179] TabletServer@127.8.83.1:0 shutting down...
I20260812 06:20:18.999665  8682 maintenance_manager.cc:643] P 823b1a1858c746adb4f9600054e32104: MajorDeltaCompactionOp(fdd69399772042c787559aaf588fcfd1) complete. Timing: real 0.125s	user 0.094s	sys 0.032s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":297,"lbm_read_time_us":8563,"lbm_reads_lt_1ms":467,"lbm_write_time_us":27999,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":441,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18944,"update_count":2000}
I20260812 06:20:19.000777  8524 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:19.001232  8524 tablet_replica.cc:333] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104: stopping tablet replica
I20260812 06:20:19.001497  8524 raft_consensus.cc:2243] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:19.001755  8524 raft_consensus.cc:2272] T fdd69399772042c787559aaf588fcfd1 P 823b1a1858c746adb4f9600054e32104 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:19.018455  8524 tablet_server.cc:196] TabletServer@127.8.83.1:0 shutdown complete.
I20260812 06:20:19.040375  8524 master.cc:562] Master@127.8.83.62:46267 shutting down...
I20260812 06:20:19.044102  8524 raft_consensus.cc:2243] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:19.044282  8524 raft_consensus.cc:2272] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:19.044338  8524 tablet_replica.cc:333] T 00000000000000000000000000000000 P d672c8543b2e441e983ddaae7f887093: stopping tablet replica
I20260812 06:20:19.057062  8524 master.cc:584] Master@127.8.83.62:46267 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5537 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:19.175357  8524 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.8.83.62:35363
I20260812 06:20:19.175843  8524 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:19.179206  8820 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:20:19.179328  8524 server_base.cc:1061] running on GCE node
W20260812 06:20:19.179217  8821 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:20:19.179755  8825 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:20:19.180015  8524 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:19.180059  8524 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:20:19.180076  8524 hybrid_clock.cc:648] HybridClock initialized: now 1786515619180076 us; error 0 us; skew 500 ppm
I20260812 06:20:19.181051  8524 webserver.cc:533] Webserver started at http://127.8.83.62:39969/ using document root <none> and password file <none>
I20260812 06:20:19.181222  8524 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:19.181264  8524 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:19.181327  8524 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:19.181707  8524 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/master-0-root/instance:
uuid: "2d501e9bc2374ca4a968cc9018eff2f1"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-7kzw"
I20260812 06:20:19.183326  8524 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:19.184406  8837 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:20:19.184906  8524 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:19.185009  8524 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/master-0-root
uuid: "2d501e9bc2374ca4a968cc9018eff2f1"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-7kzw"
I20260812 06:20:19.185148  8524 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-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:20:19.197002  8524 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:19.197571  8524 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:19.203450  8524 rpc_server.cc:307] RPC server started. Bound to: 127.8.83.62:35363
I20260812 06:20:19.206840  8925 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:20:19.211256  8924 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.83.62:35363 every 8 connection(s)
I20260812 06:20:19.212822  8925 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1: Bootstrap starting.
I20260812 06:20:19.213771  8925 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:19.215176  8925 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1: No bootstrap required, opened a new log
I20260812 06:20:19.215720  8925 raft_consensus.cc:359] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2d501e9bc2374ca4a968cc9018eff2f1" member_type: VOTER }
I20260812 06:20:19.215826  8925 raft_consensus.cc:385] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:19.215891  8925 raft_consensus.cc:740] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2d501e9bc2374ca4a968cc9018eff2f1, State: Initialized, Role: FOLLOWER
I20260812 06:20:19.216115  8925 consensus_queue.cc:260] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1 [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: "2d501e9bc2374ca4a968cc9018eff2f1" member_type: VOTER }
I20260812 06:20:19.216208  8925 raft_consensus.cc:399] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:19.216291  8925 raft_consensus.cc:493] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:19.216387  8925 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:19.217273  8925 raft_consensus.cc:515] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2d501e9bc2374ca4a968cc9018eff2f1" member_type: VOTER }
I20260812 06:20:19.217446  8925 leader_election.cc:304] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1 [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: 2d501e9bc2374ca4a968cc9018eff2f1; no voters: 
I20260812 06:20:19.217724  8925 leader_election.cc:290] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:19.217970  8929 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:19.218214  8929 raft_consensus.cc:697] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1 [term 1 LEADER]: Becoming Leader. State: Replica: 2d501e9bc2374ca4a968cc9018eff2f1, State: Running, Role: LEADER
I20260812 06:20:19.218364  8925 sys_catalog.cc:565] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:19.218413  8929 consensus_queue.cc:237] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1 [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: "2d501e9bc2374ca4a968cc9018eff2f1" member_type: VOTER }
I20260812 06:20:19.219010  8931 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 2d501e9bc2374ca4a968cc9018eff2f1. Latest consensus state: current_term: 1 leader_uuid: "2d501e9bc2374ca4a968cc9018eff2f1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2d501e9bc2374ca4a968cc9018eff2f1" member_type: VOTER } }
I20260812 06:20:19.219131  8931 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:19.219300  8930 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "2d501e9bc2374ca4a968cc9018eff2f1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2d501e9bc2374ca4a968cc9018eff2f1" member_type: VOTER } }
I20260812 06:20:19.219383  8930 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:19.219813  8936 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:19.220538  8936 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:19.220742  8524 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:19.222922  8936 catalog_manager.cc:1383] Generated new cluster ID: 3846037295254f0eaddc5df6761f8596
I20260812 06:20:19.222991  8936 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:19.238799  8936 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:19.239498  8936 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:19.250948  8936 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1: Generated new TSK 0
I20260812 06:20:19.251200  8936 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:19.253176  8524 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:19.255672  8959 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:20:19.255626  8965 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:20:19.255654  8524 server_base.cc:1061] running on GCE node
W20260812 06:20:19.255759  8956 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:20:19.256135  8524 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:19.256207  8524 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:20:19.256233  8524 hybrid_clock.cc:648] HybridClock initialized: now 1786515619256233 us; error 0 us; skew 500 ppm
I20260812 06:20:19.257135  8524 webserver.cc:533] Webserver started at http://127.8.83.1:33423/ using document root <none> and password file <none>
I20260812 06:20:19.257336  8524 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:19.257412  8524 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:19.257491  8524 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:19.257885  8524 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/instance:
uuid: "f74618ac7fc34a849c6a18fee396cde8"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-7kzw"
I20260812 06:20:19.259570  8524 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:19.260671  8973 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:20:19.260978  8524 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:19.261076  8524 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root
uuid: "f74618ac7fc34a849c6a18fee396cde8"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-7kzw"
I20260812 06:20:19.261166  8524 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-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:20:19.266175  8524 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:19.266610  8524 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:19.266919  8524 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:19.267416  8524 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:19.267483  8524 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.267542  8524 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:19.267575  8524 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.272145  8524 rpc_server.cc:307] RPC server started. Bound to: 127.8.83.1:36195
I20260812 06:20:19.272192  9077 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.83.1:36195 every 8 connection(s)
I20260812 06:20:19.283176  9078 heartbeater.cc:344] Connected to a master server at 127.8.83.62:35363
I20260812 06:20:19.283336  9078 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:19.283702  9078 heartbeater.cc:507] Master 127.8.83.62:35363 requested a full tablet report, sending...
I20260812 06:20:19.284987  8866 ts_manager.cc:194] Registered new tserver with Master: f74618ac7fc34a849c6a18fee396cde8 (127.8.83.1:36195)
I20260812 06:20:19.285625  8524 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013004934s
I20260812 06:20:19.286001  8866 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:36934
I20260812 06:20:19.295260  8866 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:36946:
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:20:19.305035  9019 tablet_service.cc:1511] Processing CreateTablet for tablet 3efbf9742aaf4f88add9561e43f1bda2 (DEFAULT_TABLE table=heavy-update-compaction-test [id=732db1ae75794425865ee07fa91830c2]), partition=
I20260812 06:20:19.305344  9019 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 3efbf9742aaf4f88add9561e43f1bda2. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:19.307830  9097 tablet_bootstrap.cc:492] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Bootstrap starting.
I20260812 06:20:19.308684  9097 tablet_bootstrap.cc:654] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:19.309834  9097 tablet_bootstrap.cc:492] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: No bootstrap required, opened a new log
I20260812 06:20:19.309932  9097 ts_tablet_manager.cc:1403] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:19.310436  9097 raft_consensus.cc:359] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f74618ac7fc34a849c6a18fee396cde8" member_type: VOTER last_known_addr { host: "127.8.83.1" port: 36195 } }
I20260812 06:20:19.310555  9097 raft_consensus.cc:385] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:19.310580  9097 raft_consensus.cc:740] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f74618ac7fc34a849c6a18fee396cde8, State: Initialized, Role: FOLLOWER
I20260812 06:20:19.310694  9097 consensus_queue.cc:260] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8 [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: "f74618ac7fc34a849c6a18fee396cde8" member_type: VOTER last_known_addr { host: "127.8.83.1" port: 36195 } }
I20260812 06:20:19.310756  9097 raft_consensus.cc:399] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:19.310779  9097 raft_consensus.cc:493] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:19.310809  9097 raft_consensus.cc:3060] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:19.311477  9097 raft_consensus.cc:515] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f74618ac7fc34a849c6a18fee396cde8" member_type: VOTER last_known_addr { host: "127.8.83.1" port: 36195 } }
I20260812 06:20:19.311597  9097 leader_election.cc:304] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8 [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: f74618ac7fc34a849c6a18fee396cde8; no voters: 
I20260812 06:20:19.311806  9097 leader_election.cc:290] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:19.311901  9101 raft_consensus.cc:2804] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:19.312089  9101 raft_consensus.cc:697] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8 [term 1 LEADER]: Becoming Leader. State: Replica: f74618ac7fc34a849c6a18fee396cde8, State: Running, Role: LEADER
I20260812 06:20:19.312237  9078 heartbeater.cc:499] Master 127.8.83.62:35363 was elected leader, sending a full tablet report...
I20260812 06:20:19.312288  9101 consensus_queue.cc:237] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8 [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: "f74618ac7fc34a849c6a18fee396cde8" member_type: VOTER last_known_addr { host: "127.8.83.1" port: 36195 } }
I20260812 06:20:19.312465  9097 ts_tablet_manager.cc:1434] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:19.313742  8866 catalog_manager.cc:5719] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8 reported cstate change: term changed from 0 to 1, leader changed from <none> to f74618ac7fc34a849c6a18fee396cde8 (127.8.83.1). New cstate: current_term: 1 leader_uuid: "f74618ac7fc34a849c6a18fee396cde8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f74618ac7fc34a849c6a18fee396cde8" member_type: VOTER last_known_addr { host: "127.8.83.1" port: 36195 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:19.375003  8524 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.020s	sys 0.003s
I20260812 06:20:19.523110  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushMRSOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=19.054940
I20260812 06:20:19.690779  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushMRSOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.167s	user 0.123s	sys 0.044s Metrics: {"bytes_written":12307489,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":106,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":866,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42498,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:20:19.691519  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling LogGCOp(3efbf9742aaf4f88add9561e43f1bda2): free 20743880 bytes of WAL
I20260812 06:20:19.691866  8980 log_reader.cc:385] T 3efbf9742aaf4f88add9561e43f1bda2: removed 2 log segments from log reader
I20260812 06:20:19.691956  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000001 (ops 1-6)
I20260812 06:20:19.692008  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000002 (ops 7-11)
I20260812 06:20:19.698089  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: LogGCOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:19.698622  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling UndoDeltaBlockGCOp(3efbf9742aaf4f88add9561e43f1bda2): 16411393 bytes on disk
I20260812 06:20:19.699137  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: UndoDeltaBlockGCOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4}
I20260812 06:20:19.699592  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=2.188937
I20260812 06:20:19.716697  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.017s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5869,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.717217  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=1.000000
I20260812 06:20:19.880240  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.163s	user 0.098s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":695,"lbm_read_time_us":9640,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27480,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":339,"threads_started":5,"update_count":2000}
I20260812 06:20:19.881009  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=11.118625
I20260812 06:20:19.917312  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.036s	user 0.015s	sys 0.018s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15718,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:19.917922  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=2.188937
I20260812 06:20:19.943676  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.026s	user 0.010s	sys 0.013s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5942,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:19.944303  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=1.000000
I20260812 06:20:20.110142  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.166s	user 0.105s	sys 0.057s 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":441,"lbm_read_time_us":11928,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25298,"lbm_writes_lt_1ms":443,"mutex_wait_us":59,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2000}
I20260812 06:20:20.110920  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=11.118625
I20260812 06:20:20.148130  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.037s	user 0.031s	sys 0.004s Metrics: {"bytes_written":12676711,"delete_count":0,"lbm_write_time_us":16108,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1545}
I20260812 06:20:20.148769  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=2.188937
I20260812 06:20:20.169353  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.020s	user 0.006s	sys 0.009s Metrics: {"bytes_written":3733434,"delete_count":0,"lbm_write_time_us":6039,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:20:20.169931  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=1.000000
I20260812 06:20:20.289765  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.120s	user 0.100s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672273,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":904,"lbm_read_time_us":8108,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23603,"lbm_writes_lt_1ms":443,"mutex_wait_us":274,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2000}
I20260812 06:20:20.290323  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=10.126437
I20260812 06:20:20.335680  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.045s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16752,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.336225  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=2.188937
I20260812 06:20:20.347040  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4048,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.347785  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=1.000000
I20260812 06:20:20.486989  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.139s	user 0.119s	sys 0.019s 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":1356,"lbm_read_time_us":10308,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26446,"lbm_writes_lt_1ms":443,"mutex_wait_us":319,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2000}
I20260812 06:20:20.487741  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=10.126437
I20260812 06:20:20.561841  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.074s	user 0.019s	sys 0.023s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":44852,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.562608  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=2.188937
I20260812 06:20:20.579928  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.017s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6721,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.580569  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=1.000000
I20260812 06:20:20.740716  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.160s	user 0.103s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":541,"lbm_read_time_us":11889,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26072,"lbm_writes_lt_1ms":443,"mutex_wait_us":92,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2000}
I20260812 06:20:20.741444  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=10.126437
I20260812 06:20:20.792826  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.051s	user 0.020s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21877,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.793397  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=2.188937
I20260812 06:20:20.805498  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4381,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.806033  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=1.000000
I20260812 06:20:20.942535  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.136s	user 0.093s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":184,"lbm_read_time_us":10612,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26054,"lbm_writes_lt_1ms":443,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19840,"update_count":2000}
I20260812 06:20:20.943269  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=10.126437
I20260812 06:20:20.983584  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.040s	user 0.019s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19464,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.984083  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=2.188937
I20260812 06:20:21.000686  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.016s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5324,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":500}
I20260812 06:20:21.001411  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushMRSOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=1.000000
I20260812 06:20:21.034885  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushMRSOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.033s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":110,"dirs.run_cpu_time_us":328,"dirs.run_wall_time_us":1441,"drs_written":1,"lbm_read_time_us":115,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2370,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29,"spinlock_wait_cycles":12160}
I20260812 06:20:21.035926  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling LogGCOp(3efbf9742aaf4f88add9561e43f1bda2): free 112239312 bytes of WAL
I20260812 06:20:21.036307  8980 log_reader.cc:385] T 3efbf9742aaf4f88add9561e43f1bda2: removed 11 log segments from log reader
I20260812 06:20:21.036394  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000003 (ops 12-16)
I20260812 06:20:21.036495  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000004 (ops 17-21)
I20260812 06:20:21.036571  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000005 (ops 22-26)
I20260812 06:20:21.036640  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000006 (ops 27-30)
I20260812 06:20:21.036713  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000007 (ops 31-35)
I20260812 06:20:21.036777  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000008 (ops 36-40)
I20260812 06:20:21.036846  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000009 (ops 41-45)
I20260812 06:20:21.036919  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000010 (ops 46-50)
I20260812 06:20:21.036990  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000011 (ops 51-55)
I20260812 06:20:21.037065  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000012 (ops 56-60)
I20260812 06:20:21.037147  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000013 (ops 61-65)
I20260812 06:20:21.066308  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: LogGCOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.030s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:21.066864  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=4.173312
I20260812 06:20:21.086472  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.019s	user 0.013s	sys 0.004s Metrics: {"bytes_written":5784657,"delete_count":0,"lbm_write_time_us":7893,"lbm_writes_lt_1ms":144,"reinsert_count":0,"update_count":705}
I20260812 06:20:21.087204  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling UndoDeltaBlockGCOp(3efbf9742aaf4f88add9561e43f1bda2): 462 bytes on disk
I20260812 06:20:21.087688  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: UndoDeltaBlockGCOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:20:21.088286  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=1.196750
I20260812 06:20:21.099298  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":2420629,"delete_count":0,"lbm_write_time_us":3775,"lbm_writes_lt_1ms":62,"reinsert_count":0,"update_count":295}
I20260812 06:20:21.100033  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling LogGCOp(3efbf9742aaf4f88add9561e43f1bda2): free 12017932 bytes of WAL
I20260812 06:20:21.100270  8980 log_reader.cc:385] T 3efbf9742aaf4f88add9561e43f1bda2: removed 1 log segments from log reader
I20260812 06:20:21.100350  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000014 (ops 66-70)
I20260812 06:20:21.103129  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: LogGCOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:21.103446  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=1.000000
I20260812 06:20:21.279624  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.176s	user 0.147s	sys 0.028s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877301,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":685,"lbm_read_time_us":12072,"lbm_reads_lt_1ms":666,"lbm_write_time_us":34912,"lbm_writes_lt_1ms":643,"mutex_wait_us":43,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":67840,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:20:21.280359  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=14.095187
I20260812 06:20:21.333921  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.053s	user 0.042s	sys 0.004s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21589,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.334535  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=2.188937
I20260812 06:20:21.351943  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.017s	user 0.006s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6490,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.353009  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=1.000000
I20260812 06:20:21.529950  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.177s	user 0.124s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":985,"lbm_read_time_us":11673,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35526,"lbm_writes_lt_1ms":543,"mutex_wait_us":368,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19072,"update_count":2500}
I20260812 06:20:21.530774  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=14.095187
I20260812 06:20:21.604722  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.074s	user 0.030s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23964,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.605269  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=2.188937
I20260812 06:20:21.617380  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4326,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.617880  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=1.000000
I20260812 06:20:21.790910  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.173s	user 0.132s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1122,"lbm_read_time_us":11058,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28243,"lbm_writes_lt_1ms":543,"mutex_wait_us":379,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":2500}
I20260812 06:20:21.791460  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=14.095187
I20260812 06:20:21.851725  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.060s	user 0.035s	sys 0.009s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18481,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.852394  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=2.188937
I20260812 06:20:21.864355  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4387,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.864869  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=1.000000
I20260812 06:20:22.039063  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.174s	user 0.122s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":443,"lbm_read_time_us":11255,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30157,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2500}
I20260812 06:20:22.039705  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=14.095187
I20260812 06:20:22.095870  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.056s	user 0.022s	sys 0.031s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19498,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.096446  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=2.188937
I20260812 06:20:22.106988  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4133,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.107457  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=1.000000
I20260812 06:20:22.299664  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.192s	user 0.113s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":975,"lbm_read_time_us":13199,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29712,"lbm_writes_lt_1ms":543,"mutex_wait_us":284,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:20:22.300310  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=14.095187
I20260812 06:20:22.369844  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.069s	user 0.034s	sys 0.022s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":22689,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.370362  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=2.188937
I20260812 06:20:22.380915  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4103,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.381422  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=1.000000
I20260812 06:20:22.575707  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.194s	user 0.114s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1404,"lbm_read_time_us":12315,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32145,"lbm_writes_lt_1ms":543,"mutex_wait_us":66,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:22.576501  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=14.095187
I20260812 06:20:22.623174  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.046s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19174,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.623746  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=2.188937
I20260812 06:20:22.636051  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4253,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.637477  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushMRSOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=1.000000
I20260812 06:20:22.681516  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushMRSOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.044s	user 0.033s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":85,"dirs.run_cpu_time_us":250,"dirs.run_wall_time_us":1639,"drs_written":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1638,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:22.682260  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling LogGCOp(3efbf9742aaf4f88add9561e43f1bda2): free 121006391 bytes of WAL
I20260812 06:20:22.682569  8980 log_reader.cc:385] T 3efbf9742aaf4f88add9561e43f1bda2: removed 12 log segments from log reader
I20260812 06:20:22.682619  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000015 (ops 71-75)
I20260812 06:20:22.682650  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000016 (ops 76-80)
I20260812 06:20:22.682718  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000017 (ops 81-85)
I20260812 06:20:22.682757  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000018 (ops 86-90)
I20260812 06:20:22.682781  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000019 (ops 91-95)
I20260812 06:20:22.682839  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000020 (ops 96-100)
I20260812 06:20:22.682879  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000021 (ops 101-105)
I20260812 06:20:22.682924  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000022 (ops 106-110)
I20260812 06:20:22.682965  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000023 (ops 111-114)
I20260812 06:20:22.683002  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000024 (ops 115-119)
I20260812 06:20:22.683043  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000025 (ops 120-124)
I20260812 06:20:22.683081  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000026 (ops 125-129)
I20260812 06:20:22.712832  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: LogGCOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.030s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:20:22.713277  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling UndoDeltaBlockGCOp(3efbf9742aaf4f88add9561e43f1bda2): 483 bytes on disk
I20260812 06:20:22.713831  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: UndoDeltaBlockGCOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:20:22.714502  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=3.181125
I20260812 06:20:22.726362  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4426,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:22.726977  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=2.188937
I20260812 06:20:22.740176  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4941,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:22.740784  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=1.000000
I20260812 06:20:22.995579  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.255s	user 0.129s	sys 0.121s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979739,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":217,"lbm_read_time_us":16584,"lbm_reads_lt_1ms":774,"lbm_write_time_us":44583,"lbm_writes_lt_1ms":743,"mutex_wait_us":38,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":98,"threads_started":1,"update_count":3500}
I20260812 06:20:22.996372  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=18.063937
I20260812 06:20:23.068796  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.072s	user 0.044s	sys 0.010s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":25373,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:23.069283  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=2.188937
I20260812 06:20:23.079636  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3842,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.080127  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=1.000000
I20260812 06:20:23.294862  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.215s	user 0.155s	sys 0.056s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":829,"lbm_read_time_us":14419,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35992,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":3000}
I20260812 06:20:23.295677  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=15.087375
I20260812 06:20:23.340955  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.045s	user 0.022s	sys 0.020s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":19800,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:23.341552  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=2.188937
I20260812 06:20:23.363363  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.022s	user 0.004s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5592,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.363875  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=2.188937
I20260812 06:20:23.375849  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.012s	user 0.001s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4553,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.376394  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=1.000000
I20260812 06:20:23.593691  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.217s	user 0.159s	sys 0.055s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877207,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":3359,"lbm_read_time_us":15795,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35548,"lbm_writes_lt_1ms":643,"mutex_wait_us":2755,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":18944,"update_count":3000}
I20260812 06:20:23.594653  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=14.095187
I20260812 06:20:23.637894  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.043s	user 0.030s	sys 0.009s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19534,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.638751  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=2.188937
I20260812 06:20:23.655580  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.016s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5760,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.656421  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=1.000000
I20260812 06:20:23.853843  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.197s	user 0.135s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":857,"lbm_read_time_us":14492,"lbm_reads_lt_1ms":564,"lbm_write_time_us":34006,"lbm_writes_lt_1ms":543,"mutex_wait_us":283,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19584,"update_count":2500}
I20260812 06:20:23.854625  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=14.095187
I20260812 06:20:23.908329  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.054s	user 0.035s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19355,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.909027  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=2.188937
I20260812 06:20:23.931741  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.022s	user 0.008s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6475,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.932324  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=1.000000
I20260812 06:20:24.124387  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.192s	user 0.123s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":653,"lbm_read_time_us":13205,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30948,"lbm_writes_lt_1ms":543,"mutex_wait_us":310,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:20:24.125087  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=18.063937
I20260812 06:20:24.191908  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.067s	user 0.050s	sys 0.015s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":26584,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:24.192525  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=2.188937
I20260812 06:20:24.202811  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4016,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.203251  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushMRSOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=1.000000
I20260812 06:20:24.247443  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushMRSOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.044s	user 0.032s	sys 0.001s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":222,"dirs.run_wall_time_us":1463,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1625,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:24.248240  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling LogGCOp(3efbf9742aaf4f88add9561e43f1bda2): free 124257560 bytes of WAL
I20260812 06:20:24.248548  8980 log_reader.cc:385] T 3efbf9742aaf4f88add9561e43f1bda2: removed 12 log segments from log reader
I20260812 06:20:24.248613  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000027 (ops 130-134)
I20260812 06:20:24.248669  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000028 (ops 135-139)
I20260812 06:20:24.248709  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000029 (ops 140-144)
I20260812 06:20:24.248740  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000030 (ops 145-148)
I20260812 06:20:24.248777  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000031 (ops 149-153)
I20260812 06:20:24.248816  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000032 (ops 154-158)
I20260812 06:20:24.248853  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000033 (ops 159-163)
I20260812 06:20:24.248893  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000034 (ops 164-168)
I20260812 06:20:24.248929  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000035 (ops 169-173)
I20260812 06:20:24.248966  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000036 (ops 174-178)
I20260812 06:20:24.249003  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000037 (ops 179-183)
I20260812 06:20:24.249039  8980 log.cc:1079] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: Deleting log segment in path: /tmp/dist-test-taskRMe8LY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613611790-8524-0/minicluster-data/ts-0-root/wals/3efbf9742aaf4f88add9561e43f1bda2/wal-000000038 (ops 184-188)
I20260812 06:20:24.276361  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: LogGCOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:24.276886  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=3.181125
I20260812 06:20:24.289009  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4338,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:24.289494  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling UndoDeltaBlockGCOp(3efbf9742aaf4f88add9561e43f1bda2): 472 bytes on disk
I20260812 06:20:24.289912  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: UndoDeltaBlockGCOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:20:24.290446  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=2.188937
I20260812 06:20:24.300163  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3592,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:24.300707  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=1.000000
I20260812 06:20:24.478801  8524 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.104s	user 1.883s	sys 0.174s
I20260812 06:20:24.557523  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: MajorDeltaCompactionOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.257s	user 0.179s	sys 0.076s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37082151,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":17217,"lbm_reads_lt_1ms":870,"lbm_write_time_us":47652,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":4000}
I20260812 06:20:24.558145  9079 maintenance_manager.cc:419] P f74618ac7fc34a849c6a18fee396cde8: Scheduling FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2): perf score=14.095187
I20260812 06:20:24.585081  8524 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.106s	user 0.001s	sys 0.000s
I20260812 06:20:24.585680  8524 tablet_server.cc:179] TabletServer@127.8.83.1:0 shutting down...
I20260812 06:20:24.601990  8980 maintenance_manager.cc:643] P f74618ac7fc34a849c6a18fee396cde8: FlushDeltaMemStoresOp(3efbf9742aaf4f88add9561e43f1bda2) complete. Timing: real 0.044s	user 0.033s	sys 0.007s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19149,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.602808  8524 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:24.603041  8524 tablet_replica.cc:333] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8: stopping tablet replica
I20260812 06:20:24.603201  8524 raft_consensus.cc:2243] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:24.603399  8524 raft_consensus.cc:2272] T 3efbf9742aaf4f88add9561e43f1bda2 P f74618ac7fc34a849c6a18fee396cde8 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:24.608376  8524 tablet_server.cc:196] TabletServer@127.8.83.1:0 shutdown complete.
I20260812 06:20:24.638904  8524 master.cc:562] Master@127.8.83.62:35363 shutting down...
I20260812 06:20:24.643649  8524 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:24.643850  8524 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:24.643898  8524 tablet_replica.cc:333] T 00000000000000000000000000000000 P 2d501e9bc2374ca4a968cc9018eff2f1: stopping tablet replica
I20260812 06:20:24.657114  8524 master.cc:584] Master@127.8.83.62:35363 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5590 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11129 ms total)

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