[==========] 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:17:26.226941 21461 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.20.245.126:37623
I20260812 06:17:26.228277 21461 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:17:26.229055 21461 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:26.237493 21471 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:17:26.237543 21467 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:17:26.237555 21461 server_base.cc:1061] running on GCE node
W20260812 06:17:26.238021 21473 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:17:26.238674 21461 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:26.238814 21461 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:17:26.238863 21461 hybrid_clock.cc:648] HybridClock initialized: now 1786515446238860 us; error 0 us; skew 500 ppm
I20260812 06:17:26.241218 21461 webserver.cc:533] Webserver started at http://127.20.245.126:35021/ using document root <none> and password file <none>
I20260812 06:17:26.241842 21461 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:26.241902 21461 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:26.242165 21461 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:26.244309 21461 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/master-0-root/instance:
uuid: "53838e2c5c5d42f59f3f6fb70a8d20a0"
format_stamp: "Formatted at 2026-08-12 06:17:26 on dist-test-slave-jpj1"
I20260812 06:17:26.249287 21461 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.004s	sys 0.000s
I20260812 06:17:26.253943 21479 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:17:26.255427 21461 fs_manager.cc:730] Time spent opening block manager: real 0.005s	user 0.005s	sys 0.000s
I20260812 06:17:26.255595 21461 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/master-0-root
uuid: "53838e2c5c5d42f59f3f6fb70a8d20a0"
format_stamp: "Formatted at 2026-08-12 06:17:26 on dist-test-slave-jpj1"
I20260812 06:17:26.255723 21461 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-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:17:26.275416 21461 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:26.276124 21461 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:17:26.276271 21461 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:26.283716 21461 rpc_server.cc:307] RPC server started. Bound to: 127.20.245.126:37623
I20260812 06:17:26.283737 21564 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.245.126:37623 every 8 connection(s)
I20260812 06:17:26.286041 21565 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:17:26.291486 21565 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0: Bootstrap starting.
I20260812 06:17:26.293987 21565 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:26.294896 21565 log.cc:826] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:26.296726 21565 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0: No bootstrap required, opened a new log
I20260812 06:17:26.299592 21565 raft_consensus.cc:359] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "53838e2c5c5d42f59f3f6fb70a8d20a0" member_type: VOTER }
I20260812 06:17:26.299773 21565 raft_consensus.cc:385] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:26.299814 21565 raft_consensus.cc:740] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 53838e2c5c5d42f59f3f6fb70a8d20a0, State: Initialized, Role: FOLLOWER
I20260812 06:17:26.300365 21565 consensus_queue.cc:260] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0 [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: "53838e2c5c5d42f59f3f6fb70a8d20a0" member_type: VOTER }
I20260812 06:17:26.300511 21565 raft_consensus.cc:399] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:26.300558 21565 raft_consensus.cc:493] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:26.300658 21565 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:26.301421 21565 raft_consensus.cc:515] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "53838e2c5c5d42f59f3f6fb70a8d20a0" member_type: VOTER }
I20260812 06:17:26.301837 21565 leader_election.cc:304] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0 [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: 53838e2c5c5d42f59f3f6fb70a8d20a0; no voters: 
I20260812 06:17:26.302152 21565 leader_election.cc:290] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:26.302294 21568 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:26.302518 21568 raft_consensus.cc:697] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0 [term 1 LEADER]: Becoming Leader. State: Replica: 53838e2c5c5d42f59f3f6fb70a8d20a0, State: Running, Role: LEADER
I20260812 06:17:26.302884 21568 consensus_queue.cc:237] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0 [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: "53838e2c5c5d42f59f3f6fb70a8d20a0" member_type: VOTER }
I20260812 06:17:26.303117 21565 sys_catalog.cc:565] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:26.304637 21570 sys_catalog.cc:455] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "53838e2c5c5d42f59f3f6fb70a8d20a0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "53838e2c5c5d42f59f3f6fb70a8d20a0" member_type: VOTER } }
I20260812 06:17:26.304684 21571 sys_catalog.cc:455] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 53838e2c5c5d42f59f3f6fb70a8d20a0. Latest consensus state: current_term: 1 leader_uuid: "53838e2c5c5d42f59f3f6fb70a8d20a0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "53838e2c5c5d42f59f3f6fb70a8d20a0" member_type: VOTER } }
I20260812 06:17:26.304746 21570 sys_catalog.cc:458] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:26.304776 21571 sys_catalog.cc:458] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:26.305127 21586 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:26.305406 21461 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:26.308020 21586 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:26.313105 21586 catalog_manager.cc:1383] Generated new cluster ID: 2fedf87480c74e93990858a1a74c573d
I20260812 06:17:26.313169 21586 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:26.338479 21586 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:26.339381 21586 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:26.344270 21586 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0: Generated new TSK 0
I20260812 06:17:26.344909 21586 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:26.370497 21461 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:26.373596 21604 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:17:26.373697 21603 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:17:26.373781 21606 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:17:26.374300 21461 server_base.cc:1061] running on GCE node
I20260812 06:17:26.374482 21461 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:26.374524 21461 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:17:26.374538 21461 hybrid_clock.cc:648] HybridClock initialized: now 1786515446374539 us; error 0 us; skew 500 ppm
I20260812 06:17:26.375442 21461 webserver.cc:533] Webserver started at http://127.20.245.65:45793/ using document root <none> and password file <none>
I20260812 06:17:26.375627 21461 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:26.375690 21461 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:26.375773 21461 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:26.376168 21461 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/instance:
uuid: "5e2be88642b6457aa626ed8f282d3329"
format_stamp: "Formatted at 2026-08-12 06:17:26 on dist-test-slave-jpj1"
I20260812 06:17:26.377622 21461 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:26.378609 21613 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:17:26.378856 21461 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:26.378928 21461 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root
uuid: "5e2be88642b6457aa626ed8f282d3329"
format_stamp: "Formatted at 2026-08-12 06:17:26 on dist-test-slave-jpj1"
I20260812 06:17:26.379000 21461 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-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:17:26.390331 21461 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:26.390777 21461 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:26.391237 21461 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:26.392149 21461 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:26.392203 21461 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:26.392263 21461 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:26.392289 21461 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:26.398749 21461 rpc_server.cc:307] RPC server started. Bound to: 127.20.245.65:35399
I20260812 06:17:26.398794 21731 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.245.65:35399 every 8 connection(s)
I20260812 06:17:26.408727 21732 heartbeater.cc:344] Connected to a master server at 127.20.245.126:37623
I20260812 06:17:26.408987 21732 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:26.409451 21732 heartbeater.cc:507] Master 127.20.245.126:37623 requested a full tablet report, sending...
I20260812 06:17:26.410969 21501 ts_manager.cc:194] Registered new tserver with Master: 5e2be88642b6457aa626ed8f282d3329 (127.20.245.65:35399)
I20260812 06:17:26.411733 21461 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012370172s
I20260812 06:17:26.412192 21501 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:32862
I20260812 06:17:26.421504 21501 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:32876:
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:17:26.435478 21668 tablet_service.cc:1511] Processing CreateTablet for tablet 19a1f7b691d944119bcd9de90505bed1 (DEFAULT_TABLE table=heavy-update-compaction-test [id=8c8ea70c7cc844eb8ab5cdb756a1e410]), partition=
I20260812 06:17:26.436014 21668 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 19a1f7b691d944119bcd9de90505bed1. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:26.438197 21753 tablet_bootstrap.cc:492] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Bootstrap starting.
I20260812 06:17:26.439265 21753 tablet_bootstrap.cc:654] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:26.440537 21753 tablet_bootstrap.cc:492] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: No bootstrap required, opened a new log
I20260812 06:17:26.440636 21753 ts_tablet_manager.cc:1403] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Time spent bootstrapping tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:17:26.441273 21753 raft_consensus.cc:359] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5e2be88642b6457aa626ed8f282d3329" member_type: VOTER last_known_addr { host: "127.20.245.65" port: 35399 } }
I20260812 06:17:26.441376 21753 raft_consensus.cc:385] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:26.441465 21753 raft_consensus.cc:740] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5e2be88642b6457aa626ed8f282d3329, State: Initialized, Role: FOLLOWER
I20260812 06:17:26.441612 21753 consensus_queue.cc:260] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329 [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: "5e2be88642b6457aa626ed8f282d3329" member_type: VOTER last_known_addr { host: "127.20.245.65" port: 35399 } }
I20260812 06:17:26.441699 21753 raft_consensus.cc:399] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:26.441742 21753 raft_consensus.cc:493] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:26.441790 21753 raft_consensus.cc:3060] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:26.442505 21753 raft_consensus.cc:515] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5e2be88642b6457aa626ed8f282d3329" member_type: VOTER last_known_addr { host: "127.20.245.65" port: 35399 } }
I20260812 06:17:26.442646 21753 leader_election.cc:304] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329 [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: 5e2be88642b6457aa626ed8f282d3329; no voters: 
I20260812 06:17:26.442847 21753 leader_election.cc:290] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:26.442960 21755 raft_consensus.cc:2804] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:26.443135 21755 raft_consensus.cc:697] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329 [term 1 LEADER]: Becoming Leader. State: Replica: 5e2be88642b6457aa626ed8f282d3329, State: Running, Role: LEADER
I20260812 06:17:26.443197 21753 ts_tablet_manager.cc:1434] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:17:26.443323 21755 consensus_queue.cc:237] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329 [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: "5e2be88642b6457aa626ed8f282d3329" member_type: VOTER last_known_addr { host: "127.20.245.65" port: 35399 } }
I20260812 06:17:26.443661 21732 heartbeater.cc:499] Master 127.20.245.126:37623 was elected leader, sending a full tablet report...
I20260812 06:17:26.446062 21501 catalog_manager.cc:5719] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329 reported cstate change: term changed from 0 to 1, leader changed from <none> to 5e2be88642b6457aa626ed8f282d3329 (127.20.245.65). New cstate: current_term: 1 leader_uuid: "5e2be88642b6457aa626ed8f282d3329" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5e2be88642b6457aa626ed8f282d3329" member_type: VOTER last_known_addr { host: "127.20.245.65" port: 35399 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:26.509100 21461 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.008s	sys 0.016s
I20260812 06:17:26.649883 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushMRSOp(19a1f7b691d944119bcd9de90505bed1): perf score=19.054940
I20260812 06:17:26.795269 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushMRSOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.145s	user 0.117s	sys 0.024s Metrics: {"bytes_written":9148636,"cfile_init":1,"compiler_manager_pool.queue_time_us":233,"delete_count":0,"dirs.queue_time_us":85,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":893,"drs_written":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36306,"lbm_writes_lt_1ms":680,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":287488,"thread_start_us":141,"threads_started":1,"update_count":1115}
I20260812 06:17:26.796531 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling LogGCOp(19a1f7b691d944119bcd9de90505bed1): free 20743880 bytes of WAL
I20260812 06:17:26.796856 21625 log_reader.cc:385] T 19a1f7b691d944119bcd9de90505bed1: removed 2 log segments from log reader
I20260812 06:17:26.796957 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000001 (ops 1-6)
I20260812 06:17:26.797034 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000002 (ops 7-11)
I20260812 06:17:26.802943 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: LogGCOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:26.803623 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling UndoDeltaBlockGCOp(19a1f7b691d944119bcd9de90505bed1): 16411393 bytes on disk
I20260812 06:17:26.804585 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: UndoDeltaBlockGCOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:17:26.805336 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:26.828042 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.022s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3405234,"delete_count":0,"lbm_write_time_us":3801,"lbm_writes_lt_1ms":86,"reinsert_count":0,"update_count":415}
I20260812 06:17:26.828531 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:26.841320 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":4786,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:17:26.841768 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1): perf score=1.000000
I20260812 06:17:26.970929 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.129s	user 0.084s	sys 0.041s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20672379,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":676,"lbm_read_time_us":8351,"lbm_reads_lt_1ms":469,"lbm_write_time_us":23619,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":289,"threads_started":5,"update_count":2000}
I20260812 06:17:26.971418 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=10.126437
I20260812 06:17:27.014634 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.043s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14044,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:27.015151 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:27.026538 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3837,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.027096 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1): perf score=1.000000
I20260812 06:17:27.147794 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.120s	user 0.097s	sys 0.023s 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":98,"lbm_read_time_us":8530,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22702,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2000}
I20260812 06:17:27.148357 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=10.126437
I20260812 06:17:27.182292 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.034s	user 0.023s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14745,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:27.182804 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:27.195909 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4058,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.196379 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1): perf score=1.000000
I20260812 06:17:27.320237 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.124s	user 0.092s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":151,"lbm_read_time_us":8552,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25616,"lbm_writes_lt_1ms":443,"mutex_wait_us":18,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":44672,"update_count":2000}
I20260812 06:17:27.320808 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=10.126437
I20260812 06:17:27.366056 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.045s	user 0.017s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13961,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:27.366583 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:27.377650 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4138,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.378154 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1): perf score=1.000000
I20260812 06:17:27.523211 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.145s	user 0.092s	sys 0.052s 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":371,"lbm_read_time_us":11404,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23549,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:17:27.523787 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=10.126437
I20260812 06:17:27.563483 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.040s	user 0.013s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12365,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":26496,"update_count":1500}
I20260812 06:17:27.564015 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:27.580407 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.016s	user 0.003s	sys 0.013s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6271,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.580937 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1): perf score=1.000000
I20260812 06:17:27.702864 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.122s	user 0.101s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":846,"lbm_read_time_us":8400,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22961,"lbm_writes_lt_1ms":443,"mutex_wait_us":330,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":80512,"update_count":2000}
I20260812 06:17:27.703474 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=10.126437
I20260812 06:17:27.742877 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.039s	user 0.023s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16833,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:27.743767 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:27.763396 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.019s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6046,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.764098 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1): perf score=1.000000
I20260812 06:17:27.890329 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.126s	user 0.110s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":305,"lbm_read_time_us":9378,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23551,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:17:27.890861 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=11.118625
I20260812 06:17:27.927911 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.037s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":12525,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:27.928668 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:27.940640 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4336,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:27.941231 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushMRSOp(19a1f7b691d944119bcd9de90505bed1): perf score=1.000000
I20260812 06:17:27.969843 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushMRSOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.028s	user 0.025s	sys 0.001s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":220,"dirs.run_wall_time_us":1682,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1716,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:27.970615 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling LogGCOp(19a1f7b691d944119bcd9de90505bed1): free 112692375 bytes of WAL
I20260812 06:17:27.970849 21625 log_reader.cc:385] T 19a1f7b691d944119bcd9de90505bed1: removed 11 log segments from log reader
I20260812 06:17:27.970897 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000003 (ops 12-16)
I20260812 06:17:27.970927 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000004 (ops 17-21)
I20260812 06:17:27.970956 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000005 (ops 22-26)
I20260812 06:17:27.970988 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000006 (ops 27-31)
I20260812 06:17:27.971011 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000007 (ops 32-36)
I20260812 06:17:27.971045 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000008 (ops 37-41)
I20260812 06:17:27.971076 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000009 (ops 42-46)
I20260812 06:17:27.971107 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000010 (ops 47-51)
I20260812 06:17:27.971139 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000011 (ops 52-56)
I20260812 06:17:27.971169 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000012 (ops 57-61)
I20260812 06:17:27.971201 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000013 (ops 62-66)
I20260812 06:17:27.993539 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: LogGCOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.023s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:17:27.994006 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling UndoDeltaBlockGCOp(19a1f7b691d944119bcd9de90505bed1): 462 bytes on disk
I20260812 06:17:27.994513 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: UndoDeltaBlockGCOp(19a1f7b691d944119bcd9de90505bed1) 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:17:27.995082 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=3.181125
I20260812 06:17:28.014215 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.019s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4126,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:28.014707 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:28.024427 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3400,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:28.025108 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1): perf score=1.000000
I20260812 06:17:28.216747 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.191s	user 0.130s	sys 0.061s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877321,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":735,"lbm_read_time_us":12383,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31965,"lbm_writes_lt_1ms":643,"mutex_wait_us":72,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8960,"thread_start_us":84,"threads_started":1,"update_count":3000}
I20260812 06:17:28.217366 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=14.095187
I20260812 06:17:28.277806 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.060s	user 0.033s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25333,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:28.278375 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:28.294009 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5690,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.294646 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1): perf score=1.000000
I20260812 06:17:28.460933 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.166s	user 0.120s	sys 0.046s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":272,"lbm_read_time_us":13889,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28061,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2500}
I20260812 06:17:28.461404 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=11.118625
I20260812 06:17:28.512135 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.051s	user 0.021s	sys 0.028s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":17044,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:28.512696 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:28.526716 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.014s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3919,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.527165 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:28.536717 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3383,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:28.537173 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1): perf score=1.000000
I20260812 06:17:28.702890 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.166s	user 0.113s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774802,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":154,"lbm_read_time_us":11677,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27026,"lbm_writes_lt_1ms":543,"mutex_wait_us":63,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:28.703408 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=11.118625
I20260812 06:17:28.733278 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.030s	user 0.016s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12468,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:28.733846 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:28.749538 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5493,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:28.750049 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1): perf score=1.000000
I20260812 06:17:28.896236 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.146s	user 0.086s	sys 0.059s 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":98,"lbm_read_time_us":9191,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23174,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2000}
I20260812 06:17:28.897310 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=10.126437
I20260812 06:17:28.949430 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.052s	user 0.016s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15747,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:28.950117 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=3.181125
I20260812 06:17:28.967949 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.018s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4186,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:28.968412 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:28.982282 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4812,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:28.982841 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1): perf score=1.000000
I20260812 06:17:29.116958 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.134s	user 0.108s	sys 0.025s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":618,"lbm_read_time_us":8999,"lbm_reads_lt_1ms":573,"lbm_write_time_us":25629,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2500}
I20260812 06:17:29.117714 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=11.118625
I20260812 06:17:29.151784 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.034s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":13659,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:29.152526 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:29.177821 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.025s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4819,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:29.178400 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:29.188735 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3643,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.189389 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1): perf score=1.000000
I20260812 06:17:29.333503 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.144s	user 0.103s	sys 0.035s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1303,"lbm_read_time_us":9510,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28626,"lbm_writes_lt_1ms":543,"mutex_wait_us":252,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2500}
I20260812 06:17:29.334098 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=11.118625
I20260812 06:17:29.364522 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.030s	user 0.018s	sys 0.011s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":12260,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:29.365175 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:29.379184 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.014s	user 0.009s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4223,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:29.379781 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushMRSOp(19a1f7b691d944119bcd9de90505bed1): perf score=1.000000
I20260812 06:17:29.418525 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushMRSOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.039s	user 0.024s	sys 0.004s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":356,"dirs.run_wall_time_us":1765,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1755,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:29.419237 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=3.181125
I20260812 06:17:29.438014 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.019s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6585,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:29.438486 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling LogGCOp(19a1f7b691d944119bcd9de90505bed1): free 127961107 bytes of WAL
I20260812 06:17:29.438726 21625 log_reader.cc:385] T 19a1f7b691d944119bcd9de90505bed1: removed 12 log segments from log reader
I20260812 06:17:29.438784 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000014 (ops 67-71)
I20260812 06:17:29.438828 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000015 (ops 72-76)
I20260812 06:17:29.438863 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000016 (ops 77-81)
I20260812 06:17:29.438885 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000017 (ops 82-86)
I20260812 06:17:29.438913 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000018 (ops 87-91)
I20260812 06:17:29.438941 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000019 (ops 92-96)
I20260812 06:17:29.438969 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000020 (ops 97-101)
I20260812 06:17:29.439003 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000021 (ops 102-106)
I20260812 06:17:29.439033 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000022 (ops 107-111)
I20260812 06:17:29.439059 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000023 (ops 112-116)
I20260812 06:17:29.439086 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000024 (ops 117-121)
I20260812 06:17:29.439116 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000025 (ops 122-126)
I20260812 06:17:29.468178 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: LogGCOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:17:29.468645 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling UndoDeltaBlockGCOp(19a1f7b691d944119bcd9de90505bed1): 472 bytes on disk
I20260812 06:17:29.469144 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: UndoDeltaBlockGCOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:17:29.469698 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:29.480532 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.011s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":3750,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.480973 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:29.494695 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.014s	user 0.009s	sys 0.002s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4844,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:29.495217 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1): perf score=1.000000
I20260812 06:17:29.679103 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.184s	user 0.131s	sys 0.052s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979853,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1109,"lbm_read_time_us":12787,"lbm_reads_lt_1ms":775,"lbm_write_time_us":38300,"lbm_writes_lt_1ms":743,"mutex_wait_us":362,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13440,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:17:29.679661 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=14.095187
I20260812 06:17:29.734648 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.055s	user 0.019s	sys 0.033s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23085,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:29.735173 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:29.759382 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.024s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6094,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.759939 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:29.769924 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.010s	user 0.003s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3611,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.770392 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1): perf score=1.000000
I20260812 06:17:29.932120 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.162s	user 0.133s	sys 0.028s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1098,"lbm_read_time_us":12535,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32260,"lbm_writes_lt_1ms":643,"mutex_wait_us":270,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:17:29.932653 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=14.095187
I20260812 06:17:29.978448 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.046s	user 0.026s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20279,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:29.978998 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:29.989272 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3783,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.990051 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1): perf score=1.000000
I20260812 06:17:30.139138 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.149s	user 0.102s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":602,"lbm_read_time_us":9136,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29810,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":87936,"update_count":2500}
I20260812 06:17:30.139868 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=11.118625
I20260812 06:17:30.174305 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.034s	user 0.015s	sys 0.017s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":15547,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:30.174889 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:30.202206 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.027s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4680,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:30.202729 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:30.213301 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3887,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.213792 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1): perf score=1.000000
I20260812 06:17:30.377483 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.162s	user 0.112s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":215,"lbm_read_time_us":10764,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26965,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:30.378095 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=14.095187
I20260812 06:17:30.432075 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.054s	user 0.030s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23111,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:30.432610 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:30.442602 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3663,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.443092 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1): perf score=1.000000
I20260812 06:17:30.603653 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.160s	user 0.109s	sys 0.043s 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":320,"lbm_read_time_us":10740,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27005,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2500}
I20260812 06:17:30.604265 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=14.095187
I20260812 06:17:30.657488 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.053s	user 0.026s	sys 0.025s Metrics: {"bytes_written":16409907,"delete_count":0,"lbm_write_time_us":19564,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:30.658069 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:30.668718 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.010s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3971,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.669196 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushMRSOp(19a1f7b691d944119bcd9de90505bed1): perf score=1.000000
I20260812 06:17:30.707505 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushMRSOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.038s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":1300,"drs_written":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1306,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:30.708293 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling LogGCOp(19a1f7b691d944119bcd9de90505bed1): free 112692600 bytes of WAL
I20260812 06:17:30.708516 21625 log_reader.cc:385] T 19a1f7b691d944119bcd9de90505bed1: removed 11 log segments from log reader
I20260812 06:17:30.708561 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000026 (ops 127-131)
I20260812 06:17:30.708590 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000027 (ops 132-136)
I20260812 06:17:30.708621 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000028 (ops 137-141)
I20260812 06:17:30.708652 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000029 (ops 142-146)
I20260812 06:17:30.708686 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000030 (ops 147-151)
I20260812 06:17:30.708719 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000031 (ops 152-156)
I20260812 06:17:30.708751 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000032 (ops 157-161)
I20260812 06:17:30.708781 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000033 (ops 162-166)
I20260812 06:17:30.708812 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000034 (ops 167-171)
I20260812 06:17:30.708844 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000035 (ops 172-176)
I20260812 06:17:30.708868 21625 log.cc:1079] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/19a1f7b691d944119bcd9de90505bed1/wal-000000036 (ops 177-181)
I20260812 06:17:30.729943 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: LogGCOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.021s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:17:30.730412 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling UndoDeltaBlockGCOp(19a1f7b691d944119bcd9de90505bed1): 448 bytes on disk
I20260812 06:17:30.730894 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: UndoDeltaBlockGCOp(19a1f7b691d944119bcd9de90505bed1) 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:17:30.731477 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:30.754048 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.022s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5211,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.754575 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=2.188937
I20260812 06:17:30.765295 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3897,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.765899 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1): perf score=1.000000
I20260812 06:17:30.974192 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.208s	user 0.148s	sys 0.060s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979755,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1403,"lbm_read_time_us":15661,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36148,"lbm_writes_lt_1ms":743,"mutex_wait_us":337,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3712,"thread_start_us":105,"threads_started":1,"update_count":3500}
I20260812 06:17:30.974926 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=15.087375
I20260812 06:17:31.041970 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.067s	user 0.011s	sys 0.043s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":23530,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2050}
I20260812 06:17:31.042498 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1): perf score=6.157687
I20260812 06:17:31.062456 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: FlushDeltaMemStoresOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.020s	user 0.012s	sys 0.004s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":7397,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:17:31.063069 21733 maintenance_manager.cc:419] P 5e2be88642b6457aa626ed8f282d3329: Scheduling MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1): perf score=1.000000
I20260812 06:17:31.085973 21461 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.577s	user 1.668s	sys 0.103s
I20260812 06:17:31.143713 21461 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.057s	user 0.000s	sys 0.003s
I20260812 06:17:31.144378 21461 tablet_server.cc:179] TabletServer@127.20.245.65:0 shutting down...
I20260812 06:17:31.216936 21625 maintenance_manager.cc:643] P 5e2be88642b6457aa626ed8f282d3329: MajorDeltaCompactionOp(19a1f7b691d944119bcd9de90505bed1) complete. Timing: real 0.154s	user 0.096s	sys 0.057s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":703,"lbm_read_time_us":12557,"lbm_reads_lt_1ms":668,"lbm_write_time_us":28120,"lbm_writes_lt_1ms":643,"mutex_wait_us":93,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":25984,"update_count":3000}
I20260812 06:17:31.217645 21461 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:31.218230 21461 tablet_replica.cc:333] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329: stopping tablet replica
I20260812 06:17:31.218497 21461 raft_consensus.cc:2243] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:31.218768 21461 raft_consensus.cc:2272] T 19a1f7b691d944119bcd9de90505bed1 P 5e2be88642b6457aa626ed8f282d3329 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:31.225615 21461 tablet_server.cc:196] TabletServer@127.20.245.65:0 shutdown complete.
I20260812 06:17:31.269447 21461 master.cc:562] Master@127.20.245.126:37623 shutting down...
I20260812 06:17:31.272712 21461 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:31.272899 21461 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:31.272980 21461 tablet_replica.cc:333] T 00000000000000000000000000000000 P 53838e2c5c5d42f59f3f6fb70a8d20a0: stopping tablet replica
I20260812 06:17:31.285377 21461 master.cc:584] Master@127.20.245.126:37623 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5143 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:31.369092 21461 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.20.245.126:45457
I20260812 06:17:31.369488 21461 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:31.371596 21786 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:17:31.371667 21783 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:17:31.371868 21461 server_base.cc:1061] running on GCE node
W20260812 06:17:31.371905 21790 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:17:31.372080 21461 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:31.372119 21461 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:17:31.372139 21461 hybrid_clock.cc:648] HybridClock initialized: now 1786515451372138 us; error 0 us; skew 500 ppm
I20260812 06:17:31.373057 21461 webserver.cc:533] Webserver started at http://127.20.245.126:43577/ using document root <none> and password file <none>
I20260812 06:17:31.373211 21461 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:31.373258 21461 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:31.373333 21461 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:31.373714 21461 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/master-0-root/instance:
uuid: "583c7bb06d874c60aaa7d1285a110d32"
format_stamp: "Formatted at 2026-08-12 06:17:31 on dist-test-slave-jpj1"
I20260812 06:17:31.375175 21461 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:31.376273 21798 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:17:31.376560 21461 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:31.376639 21461 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/master-0-root
uuid: "583c7bb06d874c60aaa7d1285a110d32"
format_stamp: "Formatted at 2026-08-12 06:17:31 on dist-test-slave-jpj1"
I20260812 06:17:31.376749 21461 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-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:17:31.388439 21461 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:31.388854 21461 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:31.393067 21461 rpc_server.cc:307] RPC server started. Bound to: 127.20.245.126:45457
I20260812 06:17:31.404224 21883 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.245.126:45457 every 8 connection(s)
I20260812 06:17:31.404814 21884 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:17:31.407356 21884 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32: Bootstrap starting.
I20260812 06:17:31.408284 21884 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:31.409307 21884 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32: No bootstrap required, opened a new log
I20260812 06:17:31.409718 21884 raft_consensus.cc:359] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "583c7bb06d874c60aaa7d1285a110d32" member_type: VOTER }
I20260812 06:17:31.409807 21884 raft_consensus.cc:385] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:31.409828 21884 raft_consensus.cc:740] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 583c7bb06d874c60aaa7d1285a110d32, State: Initialized, Role: FOLLOWER
I20260812 06:17:31.409981 21884 consensus_queue.cc:260] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32 [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: "583c7bb06d874c60aaa7d1285a110d32" member_type: VOTER }
I20260812 06:17:31.410072 21884 raft_consensus.cc:399] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:31.410099 21884 raft_consensus.cc:493] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:31.410128 21884 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:31.410802 21884 raft_consensus.cc:515] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "583c7bb06d874c60aaa7d1285a110d32" member_type: VOTER }
I20260812 06:17:31.410956 21884 leader_election.cc:304] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32 [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: 583c7bb06d874c60aaa7d1285a110d32; no voters: 
I20260812 06:17:31.411131 21884 leader_election.cc:290] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:31.411309 21887 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:31.411495 21887 raft_consensus.cc:697] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32 [term 1 LEADER]: Becoming Leader. State: Replica: 583c7bb06d874c60aaa7d1285a110d32, State: Running, Role: LEADER
I20260812 06:17:31.411567 21884 sys_catalog.cc:565] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:31.411661 21887 consensus_queue.cc:237] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32 [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: "583c7bb06d874c60aaa7d1285a110d32" member_type: VOTER }
I20260812 06:17:31.412130 21889 sys_catalog.cc:455] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "583c7bb06d874c60aaa7d1285a110d32" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "583c7bb06d874c60aaa7d1285a110d32" member_type: VOTER } }
I20260812 06:17:31.412158 21891 sys_catalog.cc:455] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 583c7bb06d874c60aaa7d1285a110d32. Latest consensus state: current_term: 1 leader_uuid: "583c7bb06d874c60aaa7d1285a110d32" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "583c7bb06d874c60aaa7d1285a110d32" member_type: VOTER } }
I20260812 06:17:31.412233 21889 sys_catalog.cc:458] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:31.412254 21891 sys_catalog.cc:458] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:31.412509 21897 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:31.413365 21897 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:31.413576 21461 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:31.415171 21897 catalog_manager.cc:1383] Generated new cluster ID: eeed6b34d6f446d5b0fbba1682b7ed7c
I20260812 06:17:31.415227 21897 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:31.433965 21897 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:31.434520 21897 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:31.440331 21897 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32: Generated new TSK 0
I20260812 06:17:31.440492 21897 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:31.445827 21461 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:31.448287 21929 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:17:31.448305 21932 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:17:31.448421 21461 server_base.cc:1061] running on GCE node
W20260812 06:17:31.448472 21924 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:17:31.448820 21461 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:31.448866 21461 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:17:31.448880 21461 hybrid_clock.cc:648] HybridClock initialized: now 1786515451448880 us; error 0 us; skew 500 ppm
I20260812 06:17:31.449681 21461 webserver.cc:533] Webserver started at http://127.20.245.65:41693/ using document root <none> and password file <none>
I20260812 06:17:31.449846 21461 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:31.449892 21461 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:31.449949 21461 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:31.450290 21461 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/instance:
uuid: "2ac79677bc24498fb363fb82186b5d90"
format_stamp: "Formatted at 2026-08-12 06:17:31 on dist-test-slave-jpj1"
I20260812 06:17:31.451679 21461 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:31.452625 21943 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:17:31.452847 21461 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:31.452916 21461 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root
uuid: "2ac79677bc24498fb363fb82186b5d90"
format_stamp: "Formatted at 2026-08-12 06:17:31 on dist-test-slave-jpj1"
I20260812 06:17:31.452982 21461 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-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:17:31.469792 21461 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:31.470157 21461 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:31.470449 21461 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:31.470932 21461 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:31.470973 21461 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:31.471019 21461 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:31.471048 21461 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:31.475288 21461 rpc_server.cc:307] RPC server started. Bound to: 127.20.245.65:33745
I20260812 06:17:31.475433 22051 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.245.65:33745 every 8 connection(s)
I20260812 06:17:31.484699 22053 heartbeater.cc:344] Connected to a master server at 127.20.245.126:45457
I20260812 06:17:31.484825 22053 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:31.485028 22053 heartbeater.cc:507] Master 127.20.245.126:45457 requested a full tablet report, sending...
I20260812 06:17:31.485774 21827 ts_manager.cc:194] Registered new tserver with Master: 2ac79677bc24498fb363fb82186b5d90 (127.20.245.65:33745)
I20260812 06:17:31.486495 21827 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:56736
I20260812 06:17:31.486850 21461 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011112409s
I20260812 06:17:31.493395 21827 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:56742:
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:17:31.502205 21996 tablet_service.cc:1511] Processing CreateTablet for tablet efd534f0368d4990879dbfecb9faaf36 (DEFAULT_TABLE table=heavy-update-compaction-test [id=a9bc5543296c4153a66cbfd75136f991]), partition=
I20260812 06:17:31.502490 21996 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet efd534f0368d4990879dbfecb9faaf36. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:31.504739 22072 tablet_bootstrap.cc:492] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Bootstrap starting.
I20260812 06:17:31.505602 22072 tablet_bootstrap.cc:654] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:31.506583 22072 tablet_bootstrap.cc:492] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: No bootstrap required, opened a new log
I20260812 06:17:31.506664 22072 ts_tablet_manager.cc:1403] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:31.507022 22072 raft_consensus.cc:359] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2ac79677bc24498fb363fb82186b5d90" member_type: VOTER last_known_addr { host: "127.20.245.65" port: 33745 } }
I20260812 06:17:31.507138 22072 raft_consensus.cc:385] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:31.507182 22072 raft_consensus.cc:740] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2ac79677bc24498fb363fb82186b5d90, State: Initialized, Role: FOLLOWER
I20260812 06:17:31.507311 22072 consensus_queue.cc:260] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90 [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: "2ac79677bc24498fb363fb82186b5d90" member_type: VOTER last_known_addr { host: "127.20.245.65" port: 33745 } }
I20260812 06:17:31.507403 22072 raft_consensus.cc:399] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:31.507447 22072 raft_consensus.cc:493] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:31.507496 22072 raft_consensus.cc:3060] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:31.508333 22072 raft_consensus.cc:515] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2ac79677bc24498fb363fb82186b5d90" member_type: VOTER last_known_addr { host: "127.20.245.65" port: 33745 } }
I20260812 06:17:31.508460 22072 leader_election.cc:304] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90 [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: 2ac79677bc24498fb363fb82186b5d90; no voters: 
I20260812 06:17:31.508620 22072 leader_election.cc:290] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:31.508754 22078 raft_consensus.cc:2804] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:31.508888 22072 ts_tablet_manager.cc:1434] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:31.508935 22053 heartbeater.cc:499] Master 127.20.245.126:45457 was elected leader, sending a full tablet report...
I20260812 06:17:31.508949 22078 raft_consensus.cc:697] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90 [term 1 LEADER]: Becoming Leader. State: Replica: 2ac79677bc24498fb363fb82186b5d90, State: Running, Role: LEADER
I20260812 06:17:31.509119 22078 consensus_queue.cc:237] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90 [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: "2ac79677bc24498fb363fb82186b5d90" member_type: VOTER last_known_addr { host: "127.20.245.65" port: 33745 } }
I20260812 06:17:31.510496 21827 catalog_manager.cc:5719] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90 reported cstate change: term changed from 0 to 1, leader changed from <none> to 2ac79677bc24498fb363fb82186b5d90 (127.20.245.65). New cstate: current_term: 1 leader_uuid: "2ac79677bc24498fb363fb82186b5d90" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2ac79677bc24498fb363fb82186b5d90" member_type: VOTER last_known_addr { host: "127.20.245.65" port: 33745 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:31.569517 21461 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.018s	sys 0.004s
I20260812 06:17:31.726292 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushMRSOp(efd534f0368d4990879dbfecb9faaf36): perf score=19.054940
I20260812 06:17:31.873284 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushMRSOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.147s	user 0.111s	sys 0.032s Metrics: {"bytes_written":11897250,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":199,"dirs.run_wall_time_us":714,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37483,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1450}
I20260812 06:17:31.873917 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling LogGCOp(efd534f0368d4990879dbfecb9faaf36): free 20743880 bytes of WAL
I20260812 06:17:31.874157 21950 log_reader.cc:385] T efd534f0368d4990879dbfecb9faaf36: removed 2 log segments from log reader
I20260812 06:17:31.874208 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000001 (ops 1-6)
I20260812 06:17:31.874238 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000002 (ops 7-11)
I20260812 06:17:31.879293 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: LogGCOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:17:31.879805 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling UndoDeltaBlockGCOp(efd534f0368d4990879dbfecb9faaf36): 16821647 bytes on disk
I20260812 06:17:31.880329 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: UndoDeltaBlockGCOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4}
I20260812 06:17:31.880824 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=2.188937
I20260812 06:17:31.897920 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.017s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4557,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.898373 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36): perf score=1.000000
I20260812 06:17:32.049808 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.151s	user 0.100s	sys 0.040s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20303032,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":673,"lbm_read_time_us":11041,"lbm_reads_lt_1ms":450,"lbm_write_time_us":21713,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"thread_start_us":298,"threads_started":5,"update_count":1950}
I20260812 06:17:32.050374 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=14.095187
I20260812 06:17:32.107075 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.056s	user 0.026s	sys 0.022s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23705,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.107653 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36): perf score=1.000000
I20260812 06:17:32.267804 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.160s	user 0.096s	sys 0.057s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":262,"lbm_read_time_us":10556,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26253,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2000}
I20260812 06:17:32.268283 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=14.095187
I20260812 06:17:32.314533 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.046s	user 0.021s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18523,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.315122 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=2.188937
I20260812 06:17:32.326745 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3989,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.327353 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36): perf score=1.000000
I20260812 06:17:32.521759 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.194s	user 0.126s	sys 0.054s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":127,"lbm_read_time_us":13703,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28573,"lbm_writes_lt_1ms":543,"mutex_wait_us":16,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:17:32.522233 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=14.095187
I20260812 06:17:32.569047 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.047s	user 0.027s	sys 0.012s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":17771,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.569633 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=2.188937
I20260812 06:17:32.580610 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3982,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.581172 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36): perf score=1.000000
I20260812 06:17:32.748571 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.167s	user 0.109s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815680,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":578,"lbm_read_time_us":10274,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29041,"lbm_writes_lt_1ms":543,"mutex_wait_us":284,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2500}
I20260812 06:17:32.749075 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=14.095187
I20260812 06:17:32.791796 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.043s	user 0.031s	sys 0.007s Metrics: {"bytes_written":16409907,"delete_count":0,"lbm_write_time_us":16720,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.792321 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=2.188937
I20260812 06:17:32.802830 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3947,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.803419 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36): perf score=1.000000
I20260812 06:17:32.954142 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.150s	user 0.132s	sys 0.016s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":183,"lbm_read_time_us":9977,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29796,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2500}
I20260812 06:17:32.954646 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=11.118625
I20260812 06:17:32.991743 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.037s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15350,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:32.992388 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=2.188937
I20260812 06:17:33.020565 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.028s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5364,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:33.021093 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=2.188937
I20260812 06:17:33.031448 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3639,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.032001 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36): perf score=1.000000
I20260812 06:17:33.183136 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.151s	user 0.104s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":2401,"lbm_read_time_us":10149,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29075,"lbm_writes_lt_1ms":543,"mutex_wait_us":2126,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2500}
I20260812 06:17:33.183806 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=11.118625
I20260812 06:17:33.226631 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.043s	user 0.030s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17493,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:33.227223 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=2.188937
I20260812 06:17:33.237445 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3557,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:33.238161 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushMRSOp(efd534f0368d4990879dbfecb9faaf36): perf score=1.000000
I20260812 06:17:33.266675 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushMRSOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.028s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":88,"dirs.run_cpu_time_us":212,"dirs.run_wall_time_us":1890,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1437,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:33.267417 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling LogGCOp(efd534f0368d4990879dbfecb9faaf36): free 129320496 bytes of WAL
I20260812 06:17:33.267741 21950 log_reader.cc:385] T efd534f0368d4990879dbfecb9faaf36: removed 13 log segments from log reader
I20260812 06:17:33.267794 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000003 (ops 12-16)
I20260812 06:17:33.267836 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000004 (ops 17-21)
I20260812 06:17:33.267869 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000005 (ops 22-26)
I20260812 06:17:33.267901 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000006 (ops 27-31)
I20260812 06:17:33.267932 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000007 (ops 32-36)
I20260812 06:17:33.267961 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000008 (ops 37-40)
I20260812 06:17:33.267992 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000009 (ops 41-45)
I20260812 06:17:33.268023 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000010 (ops 46-50)
I20260812 06:17:33.268051 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000011 (ops 51-54)
I20260812 06:17:33.268081 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000012 (ops 55-59)
I20260812 06:17:33.268111 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000013 (ops 60-64)
I20260812 06:17:33.268141 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000014 (ops 65-69)
I20260812 06:17:33.268169 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000015 (ops 70-74)
I20260812 06:17:33.293915 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: LogGCOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.026s	user 0.004s	sys 0.020s Metrics: {}
I20260812 06:17:33.294387 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=3.181125
I20260812 06:17:33.312532 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.018s	user 0.016s	sys 0.001s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7097,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:33.312973 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling UndoDeltaBlockGCOp(efd534f0368d4990879dbfecb9faaf36): 482 bytes on disk
I20260812 06:17:33.313386 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: UndoDeltaBlockGCOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:17:33.313841 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=2.188937
I20260812 06:17:33.323280 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3308,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:33.323781 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36): perf score=1.000000
I20260812 06:17:33.512100 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.188s	user 0.148s	sys 0.037s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":915,"lbm_read_time_us":13857,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37324,"lbm_writes_lt_1ms":643,"mutex_wait_us":60,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":21376,"thread_start_us":89,"threads_started":1,"update_count":3000}
I20260812 06:17:33.512780 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=14.095187
I20260812 06:17:33.562656 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.050s	user 0.030s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22182,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.563186 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=2.188937
I20260812 06:17:33.578315 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4830,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.578763 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36): perf score=1.000000
I20260812 06:17:33.735468 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.157s	user 0.117s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":207,"lbm_read_time_us":9401,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27759,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":42240,"update_count":2500}
I20260812 06:17:33.736114 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=14.095187
I20260812 06:17:33.783361 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.047s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20910,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.783941 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36): perf score=1.000000
I20260812 06:17:33.936654 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.153s	user 0.091s	sys 0.054s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713155,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":296,"lbm_read_time_us":10649,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23313,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2000}
I20260812 06:17:33.937191 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=11.118625
I20260812 06:17:33.970925 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.034s	user 0.017s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14150,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:33.971578 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=2.188937
I20260812 06:17:33.985208 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.013s	user 0.002s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4688,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:33.985726 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36): perf score=1.000000
I20260812 06:17:34.114701 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.129s	user 0.100s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":154,"lbm_read_time_us":7936,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23172,"lbm_writes_lt_1ms":443,"mutex_wait_us":81,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.115198 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=10.126437
I20260812 06:17:34.150715 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.035s	user 0.026s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15277,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:34.151257 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=2.188937
I20260812 06:17:34.170794 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.019s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5379,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.171317 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36): perf score=1.000000
I20260812 06:17:34.300854 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.129s	user 0.090s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":162,"lbm_read_time_us":9562,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23408,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:17:34.301399 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=10.126437
I20260812 06:17:34.341194 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.040s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14839,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:34.341732 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=2.188937
I20260812 06:17:34.351881 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3693,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.352459 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36): perf score=1.000000
I20260812 06:17:34.471167 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.118s	user 0.086s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1201,"lbm_read_time_us":8788,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21189,"lbm_writes_lt_1ms":443,"mutex_wait_us":390,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21760,"update_count":2000}
I20260812 06:17:34.471783 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=10.126437
I20260812 06:17:34.524771 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.053s	user 0.024s	sys 0.026s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18631,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:34.525343 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=2.188937
I20260812 06:17:34.535904 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3916,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.536367 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36): perf score=1.000000
I20260812 06:17:34.684214 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.148s	user 0.101s	sys 0.046s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1391,"lbm_read_time_us":10843,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23024,"lbm_writes_lt_1ms":443,"mutex_wait_us":425,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.684896 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=10.126437
I20260812 06:17:34.723784 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.039s	user 0.009s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14962,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:34.724246 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=2.188937
I20260812 06:17:34.734815 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3962,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.735395 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushMRSOp(efd534f0368d4990879dbfecb9faaf36): perf score=1.000000
I20260812 06:17:34.765251 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushMRSOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.030s	user 0.022s	sys 0.006s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":40,"dirs.run_cpu_time_us":218,"dirs.run_wall_time_us":1370,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1660,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:34.765928 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling LogGCOp(efd534f0368d4990879dbfecb9faaf36): free 124710324 bytes of WAL
I20260812 06:17:34.766171 21950 log_reader.cc:385] T efd534f0368d4990879dbfecb9faaf36: removed 12 log segments from log reader
I20260812 06:17:34.766218 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000016 (ops 75-79)
I20260812 06:17:34.766247 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000017 (ops 80-84)
I20260812 06:17:34.766276 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000018 (ops 85-89)
I20260812 06:17:34.766310 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000019 (ops 90-94)
I20260812 06:17:34.766343 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000020 (ops 95-99)
I20260812 06:17:34.766376 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000021 (ops 100-104)
I20260812 06:17:34.766408 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000022 (ops 105-109)
I20260812 06:17:34.766438 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000023 (ops 110-114)
I20260812 06:17:34.766469 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000024 (ops 115-119)
I20260812 06:17:34.766499 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000025 (ops 120-124)
I20260812 06:17:34.766530 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000026 (ops 125-129)
I20260812 06:17:34.766561 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000027 (ops 130-134)
I20260812 06:17:34.791556 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: LogGCOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.025s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:17:34.792186 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling UndoDeltaBlockGCOp(efd534f0368d4990879dbfecb9faaf36): 483 bytes on disk
I20260812 06:17:34.792757 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: UndoDeltaBlockGCOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:17:34.793362 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=3.181125
I20260812 06:17:34.807763 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5681,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:34.808275 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=2.188937
I20260812 06:17:34.826053 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.018s	user 0.005s	sys 0.010s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3653,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:34.826617 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36): perf score=1.000000
I20260812 06:17:35.013437 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.187s	user 0.130s	sys 0.056s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918323,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":829,"lbm_read_time_us":13726,"lbm_reads_lt_1ms":674,"lbm_write_time_us":29216,"lbm_writes_lt_1ms":643,"mutex_wait_us":278,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4096,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:17:35.015941 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=14.095187
I20260812 06:17:35.065474 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.049s	user 0.023s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16710,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:17:35.066107 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=2.188937
I20260812 06:17:35.080893 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5244,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.081449 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36): perf score=1.000000
I20260812 06:17:35.257750 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.176s	user 0.101s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":160,"lbm_read_time_us":11098,"lbm_reads_lt_1ms":568,"lbm_write_time_us":29858,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:35.258288 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=14.095187
I20260812 06:17:35.305079 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.047s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19001,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.305727 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=2.188937
I20260812 06:17:35.322273 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.016s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6422,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.330632 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36): perf score=1.000000
I20260812 06:17:35.492588 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.162s	user 0.118s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":276,"lbm_read_time_us":10884,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26353,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2500}
I20260812 06:17:35.493069 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=14.095187
I20260812 06:17:35.535980 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.043s	user 0.023s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18803,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.536502 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=2.188937
I20260812 06:17:35.549214 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4542,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.549705 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36): perf score=1.000000
I20260812 06:17:35.709496 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.160s	user 0.121s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":296,"lbm_read_time_us":11075,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28055,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2500}
I20260812 06:17:35.710114 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=14.095187
I20260812 06:17:35.755424 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.045s	user 0.024s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16699,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.756052 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=2.188937
I20260812 06:17:35.767254 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4033,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.767835 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36): perf score=1.000000
I20260812 06:17:35.928293 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.160s	user 0.118s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":160,"lbm_read_time_us":11853,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29268,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":84224,"update_count":2500}
I20260812 06:17:35.929220 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=14.095187
I20260812 06:17:35.978868 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.049s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20433,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.979489 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=2.188937
I20260812 06:17:35.990758 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3856,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.991259 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36): perf score=1.000000
I20260812 06:17:36.138710 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.147s	user 0.139s	sys 0.008s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":199,"lbm_read_time_us":11068,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28202,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:17:36.139295 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=11.118625
I20260812 06:17:36.171214 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.032s	user 0.016s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13483,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:36.171852 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=2.188937
I20260812 06:17:36.185701 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5091,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:36.186471 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushMRSOp(efd534f0368d4990879dbfecb9faaf36): perf score=1.000000
I20260812 06:17:36.213832 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushMRSOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.027s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":242,"dirs.run_wall_time_us":1332,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1533,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:36.214653 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling LogGCOp(efd534f0368d4990879dbfecb9faaf36): free 136728511 bytes of WAL
I20260812 06:17:36.214967 21950 log_reader.cc:385] T efd534f0368d4990879dbfecb9faaf36: removed 13 log segments from log reader
I20260812 06:17:36.215023 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000028 (ops 135-139)
I20260812 06:17:36.215065 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000029 (ops 140-144)
I20260812 06:17:36.215097 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000030 (ops 145-149)
I20260812 06:17:36.215121 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000031 (ops 150-154)
I20260812 06:17:36.215152 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000032 (ops 155-159)
I20260812 06:17:36.215176 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000033 (ops 160-164)
I20260812 06:17:36.215205 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000034 (ops 165-169)
I20260812 06:17:36.215235 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000035 (ops 170-174)
I20260812 06:17:36.215265 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000036 (ops 175-179)
I20260812 06:17:36.215296 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000037 (ops 180-184)
I20260812 06:17:36.215327 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000038 (ops 185-189)
I20260812 06:17:36.215356 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000039 (ops 190-194)
I20260812 06:17:36.215385 21950 log.cc:1079] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: Deleting log segment in path: /tmp/dist-test-taskL8WVzt/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446214553-21461-0/minicluster-data/ts-0-root/wals/efd534f0368d4990879dbfecb9faaf36/wal-000000040 (ops 195-199)
I20260812 06:17:36.242466 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: LogGCOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:36.243093 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=5.165500
I20260812 06:17:36.247666 21461 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.678s	user 1.718s	sys 0.124s
I20260812 06:17:36.258635 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.015s	user 0.007s	sys 0.007s Metrics: {"bytes_written":6728210,"delete_count":0,"lbm_write_time_us":6775,"lbm_writes_lt_1ms":167,"reinsert_count":0,"update_count":820}
I20260812 06:17:36.259084 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling UndoDeltaBlockGCOp(efd534f0368d4990879dbfecb9faaf36): 492 bytes on disk
I20260812 06:17:36.259656 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: UndoDeltaBlockGCOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:17:36.260229 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36): perf score=1.000000
I20260812 06:17:36.267699 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: FlushDeltaMemStoresOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.007s	user 0.006s	sys 0.001s Metrics: {"bytes_written":1477052,"delete_count":0,"lbm_write_time_us":2298,"lbm_writes_lt_1ms":39,"reinsert_count":0,"update_count":180}
I20260812 06:17:36.268114 22056 maintenance_manager.cc:419] P 2ac79677bc24498fb363fb82186b5d90: Scheduling MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36): perf score=1.000000
I20260812 06:17:36.312800 21461 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.065s	user 0.002s	sys 0.000s
I20260812 06:17:36.313369 21461 tablet_server.cc:179] TabletServer@127.20.245.65:0 shutting down...
I20260812 06:17:36.414978 21950 maintenance_manager.cc:643] P 2ac79677bc24498fb363fb82186b5d90: MajorDeltaCompactionOp(efd534f0368d4990879dbfecb9faaf36) complete. Timing: real 0.147s	user 0.104s	sys 0.042s Metrics: {"cfile_cache_hit":402,"cfile_cache_hit_bytes":16409878,"cfile_cache_miss":232,"cfile_cache_miss_bytes":12508386,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":767,"lbm_read_time_us":6779,"lbm_reads_lt_1ms":268,"lbm_write_time_us":29929,"lbm_writes_lt_1ms":643,"mutex_wait_us":366,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":68992,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:17:36.416141 21461 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:36.416445 21461 tablet_replica.cc:333] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90: stopping tablet replica
I20260812 06:17:36.416579 21461 raft_consensus.cc:2243] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:36.416744 21461 raft_consensus.cc:2272] T efd534f0368d4990879dbfecb9faaf36 P 2ac79677bc24498fb363fb82186b5d90 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:36.431038 21461 tablet_server.cc:196] TabletServer@127.20.245.65:0 shutdown complete.
I20260812 06:17:36.465444 21461 master.cc:562] Master@127.20.245.126:45457 shutting down...
I20260812 06:17:36.468598 21461 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:36.468780 21461 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:36.468833 21461 tablet_replica.cc:333] T 00000000000000000000000000000000 P 583c7bb06d874c60aaa7d1285a110d32: stopping tablet replica
I20260812 06:17:36.481143 21461 master.cc:584] Master@127.20.245.126:45457 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5187 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10331 ms total)

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